01JPK23B2AH5VBM7FXTSB5B87W: test-up-2region-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: 01JPK23YZ4K2ZFPSRKE1CEN53R

Tags:

Artefacts:

Output:

SEQ GLOBAL TIME DETAILS
12025-03-17T22:17:21.471Zjob dependencies complete; ready to run (waiting for 14 m 1 s)
22025-03-17T22:18:23.977Zjob assigned to worker 01JPK2XYXNKNQHJ28D83W62KZ9 [factory aws, i-0206348b4a2fc0573] (queued for 1 m 2 s)
32025-03-17T22:18:32.711Zdownloading input: /input/build/work/bins/crucible-downstairs.gz
42025-03-17T22:18:33.964Zdownloaded input: /input/build/work/bins/crucible-downstairs.gz
52025-03-17T22:18:33.964Zdownloading input: /input/build/work/bins/crucible-hammer.gz
62025-03-17T22:18:35.550Zdownloaded input: /input/build/work/bins/crucible-hammer.gz
72025-03-17T22:18:35.550Zdownloading input: /input/build/work/bins/crutest.gz
82025-03-17T22:18:36.946Zdownloaded input: /input/build/work/bins/crutest.gz
92025-03-17T22:18:36.946Zdownloading input: /input/build/work/bins/dsc.gz
102025-03-17T22:18:37.683Zdownloaded input: /input/build/work/bins/dsc.gz
112025-03-17T22:18:37.690Zdownloading input: /input/build/work/scripts/perf-downstairs-tick.d
122025-03-17T22:18:37.711Zdownloaded input: /input/build/work/scripts/perf-downstairs-tick.d
132025-03-17T22:18:37.711Zdownloading input: /input/build/work/scripts/test_ds.sh
142025-03-17T22:18:37.733Zdownloaded input: /input/build/work/scripts/test_ds.sh
152025-03-17T22:18:37.733Zdownloading input: /input/build/work/scripts/test_live_repair.sh
162025-03-17T22:18:37.751Zdownloaded input: /input/build/work/scripts/test_live_repair.sh
172025-03-17T22:18:37.751Zdownloading input: /input/build/work/scripts/test_repair.sh
182025-03-17T22:18:37.773Zdownloaded input: /input/build/work/scripts/test_repair.sh
192025-03-17T22:18:37.773Zdownloading input: /input/build/work/scripts/test_replay.sh
202025-03-17T22:18:37.793Zdownloaded input: /input/build/work/scripts/test_replay.sh
212025-03-17T22:18:37.793Zdownloading input: /input/build/work/scripts/test_up.sh
222025-03-17T22:18:37.815Zdownloaded input: /input/build/work/scripts/test_up.sh
232025-03-17T22:18:37.815Zdownloading input: /input/build/work/scripts/upstairs_info.d
242025-03-17T22:18:37.837Zdownloaded input: /input/build/work/scripts/upstairs_info.d
252025-03-17T22:18:37.860Zdownloading input: /input/build/tmp/cargo-test-out.log
262025-03-17T22:18:38.502Zdownloaded input: /input/build/tmp/cargo-test-out.log
 
272025-03-17T22:18:38.503Zstarting task 0: "setup"
282025-03-17T22:18:38.509Z++ uname -s
292025-03-17T22:18:38.513Z+ kern=SunOS
302025-03-17T22:18:38.513Z+ build_user=build
312025-03-17T22:18:38.513Z+ build_uid=12345
322025-03-17T22:18:38.513Z+ work_dir=/work
332025-03-17T22:18:38.513Z+ input_dir=/input
342025-03-17T22:18:38.513Z+ [[ 0 == 12345 ]]
352025-03-17T22:18:38.513Z+ case "$kern" in
362025-03-17T22:18:38.514Z+ groupadd -g 12345 build
372025-03-17T22:18:38.517Z+ useradd -u 12345 -g build -d /home/build -s /bin/bash -c build -P 'Primary Administrator' build
382025-03-17T22:18:40.522Z+ zfs create -o mountpoint=/work rpool/work
392025-03-17T22:18:40.882Z++ awk '$2 == "/home" { print $3 }' /etc/mnttab
402025-03-17T22:18:40.885Z+ home_fs=zfs
412025-03-17T22:18:40.885Z+ [[ zfs == autofs ]]
422025-03-17T22:18:40.885Z+ mkdir -p /home/build
432025-03-17T22:18:40.888Z+ chown build:build /home/build /work
442025-03-17T22:18:42.889Z+ chmod 0700 /home/build /work
452025-03-17T22:18:42.892Zprocess exited: duration 4390 ms, exit code 0
 
462025-03-17T22:18:42.898Zstarting task 1: "authentication"
472025-03-17T22:18:42.916Zprocess exited: duration 18 ms, exit code 0
 
482025-03-17T22:18:42.925Zstarting task 2: "build"
492025-03-17T22:18:42.928Z+ banner cores
502025-03-17T22:18:42.931Z
512025-03-17T22:18:42.931Z #### #### ##### ###### ####
522025-03-17T22:18:42.931Z # # # # # # # #
532025-03-17T22:18:42.931Z # # # # # ##### ####
542025-03-17T22:18:42.931Z # # # ##### # #
552025-03-17T22:18:42.931Z # # # # # # # # #
562025-03-17T22:18:42.932Z #### #### # # ###### ####
572025-03-17T22:18:42.932Z
582025-03-17T22:18:42.932Z+ 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:18:42.939Z+ banner unpack
602025-03-17T22:18:42.942Z
612025-03-17T22:18:42.942Z # # # # ##### ## #### # #
622025-03-17T22:18:42.942Z # # ## # # # # # # # # #
632025-03-17T22:18:42.942Z # # # # # # # # # # ####
642025-03-17T22:18:42.942Z # # # # # ##### ###### # # #
652025-03-17T22:18:42.942Z # # # ## # # # # # # #
662025-03-17T22:18:42.942Z #### # # # # # #### # #
672025-03-17T22:18:42.942Z
682025-03-17T22:18:42.942Z+ mkdir -p /var/tmp/bins
692025-03-17T22:18:42.945Z+ for t in "$input/bins/"*.gz
702025-03-17T22:18:42.945Z++ basename /input/build/work/bins/crucible-downstairs.gz
712025-03-17T22:18:42.945Z+ b=crucible-downstairs.gz
722025-03-17T22:18:42.945Z+ b=crucible-downstairs
732025-03-17T22:18:42.945Z+ gunzip
742025-03-17T22:18:45.365Z+ chmod +x /var/tmp/bins/crucible-downstairs
752025-03-17T22:18:45.368Z+ for t in "$input/bins/"*.gz
762025-03-17T22:18:45.368Z++ basename /input/build/work/bins/crucible-hammer.gz
772025-03-17T22:18:45.371Z+ b=crucible-hammer.gz
782025-03-17T22:18:45.371Z+ b=crucible-hammer
792025-03-17T22:18:45.372Z+ gunzip
802025-03-17T22:18:47.548Z+ chmod +x /var/tmp/bins/crucible-hammer
812025-03-17T22:18:47.552Z+ for t in "$input/bins/"*.gz
822025-03-17T22:18:47.552Z++ basename /input/build/work/bins/crutest.gz
832025-03-17T22:18:47.555Z+ b=crutest.gz
842025-03-17T22:18:47.555Z+ b=crutest
852025-03-17T22:18:47.555Z+ gunzip
862025-03-17T22:18:49.977Z+ chmod +x /var/tmp/bins/crutest
872025-03-17T22:18:49.981Z+ for t in "$input/bins/"*.gz
882025-03-17T22:18:49.981Z++ basename /input/build/work/bins/dsc.gz
892025-03-17T22:18:49.984Z+ b=dsc.gz
902025-03-17T22:18:49.984Z+ b=dsc
912025-03-17T22:18:49.984Z+ gunzip
922025-03-17T22:18:51.325Z+ chmod +x /var/tmp/bins/dsc
932025-03-17T22:18:51.328Z+ export BINDIR=/var/tmp/bins
942025-03-17T22:18:51.328Z+ BINDIR=/var/tmp/bins
952025-03-17T22:18:51.328Z+ jobpid=1147
962025-03-17T22:18:51.328Z+ echo 'Setup debug logging'
972025-03-17T22:18:51.328Z+ mkdir /tmp/debug
982025-03-17T22:18:51.328ZSetup debug logging
992025-03-17T22:18:51.331Z+ sleep 3600
1002025-03-17T22:18:51.331Z+ psrinfo -v
1012025-03-17T22:18:51.334Z+ df -h
1022025-03-17T22:18:51.341Z+ prstat -d d -mLc 1
1032025-03-17T22:18:51.344Z+ iostat -T d -xn 1
1042025-03-17T22:18:51.344Z+ mpstat -T d 1
1052025-03-17T22:18:51.344Z+ vmstat -T d -p 1
1062025-03-17T22:18:51.344Z+ pfexec dtrace -Z -s /input/build/work/scripts/perf-downstairs-tick.d
1072025-03-17T22:18:51.347Z+ banner test_up_2r_encrypted
1082025-03-17T22:18:51.347Z+ pfexec dtrace -Z -s /input/build/work/scripts/upstairs_info.d
1092025-03-17T22:18:51.347Z #####
1102025-03-17T22:18:51.347Z ##### ###### #### ##### # # ##### # # #####
1112025-03-17T22:18:51.347Z # # # # # # # # # # #
1122025-03-17T22:18:51.347Z # ##### #### # # # # # ##### # #
1132025-03-17T22:18:51.347Z # # # # # # ##### # #####
1142025-03-17T22:18:51.347Z # # # # # # # # # # #
1152025-03-17T22:18:51.347Z # ###### #### # ####### #### # ####### ####### # #
1162025-03-17T22:18:51.347Z
1172025-03-17T22:18:51.347Z+ ptime -m bash /input/build/work/scripts/test_up.sh -r 2 -N encrypted
1182025-03-17T22:18:51.358Z/input/build/work
1192025-03-17T22:18:51.370ZUsing 2 region sets
1202025-03-17T22:18:51.370ZTurn off color for downstairs dump
1212025-03-17T22:18:51.387ZUpstairs using key: dTo8OYwJ4nmwk+WBHlLjCGc4PhTEPwEIOae/e9F5cFU=
1222025-03-17T22:18:51.390Zdsc output goes to /tmp/test_up-build/dsc-out.txt
1232025-03-17T22:18:51.390ZCreating 6 downstairs regions
1242025-03-17T22:18:51.743ZStarting 6 downstairs
1252025-03-17T22:18:51.746Zdsc started at PID: 1195
1262025-03-17T22:18:57.082ZDisable automatic restart on all downstairs
1272025-03-17T22:18:57.134Z
1282025-03-17T22:18:57.135ZBegin tests, output goes to /tmp/test_up-build/test_up_out.txt
1292025-03-17T22:18:57.138ZRunning test: span
1302025-03-17T22:19:01.307ZCompleted test: span
1312025-03-17T22:19:06.314ZRunning test: big
1322025-03-17T22:19:10.904ZCompleted test: big
1332025-03-17T22:19:15.910ZRunning test: dep
1342025-03-17T22:19:49.962ZCompleted test: dep
1352025-03-17T22:19:54.969ZRunning test: balloon
1362025-03-17T22:24:13.686ZCompleted test: balloon
1372025-03-17T22:24:19.135ZRunning test: deactivate
1382025-03-17T22:25:13.648ZCompleted test: deactivate
1392025-03-17T22:25:18.367ZRunning hammer
1402025-03-17T22:25:31.100ZRun repair tests
1412025-03-17T22:25:31.105Z/var/tmp/bins/crutest fill -g 31 -q --key dTo8OYwJ4nmwk+WBHlLjCGc4PhTEPwEIOae/e9F5cFU= --dsc 127.0.0.1:9998 --verify-out /var/tmp/test_up-build/verify_file
1422025-03-17T22:25:31.161Z{"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:25:30.128312524Z","hostname":"w-01JPK2XYXNKNQHJ28D83W62KZ9","pid":1238,"task":"crutest"}
1432025-03-17T22:25:31.164Z{"msg":"dsc has 6 regions. This means 2 sub_volumes","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:25:30.128815125Z","hostname":"w-01JPK2XYXNKNQHJ28D83W62KZ9","pid":1238,"task":"crutest"}
1442025-03-17T22:25:31.164Z{"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:25:30.130556191Z","hostname":"w-01JPK2XYXNKNQHJ28D83W62KZ9","pid":1238,"task":"crutest"}
1452025-03-17T22:25:31.164Z{"msg":"Upstairs starts","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:25:30.130732481Z","hostname":"w-01JPK2XYXNKNQHJ28D83W62KZ9","pid":1238}
1462025-03-17T22:25:31.165Z{"msg":"Crucible Version: BuildInfo {\n version: \"0.0.1\",\n git_sha: \"acc6b11fa639390710fd9a0449e05c901b048ed2\",\n git_commit_timestamp: \"2025-03-17T22:02:02.000000000Z\",\n git_branch: \"renovate/itertools-0.x\",\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:25:30.130777411Z","hostname":"w-01JPK2XYXNKNQHJ28D83W62KZ9","pid":1238}
1472025-03-17T22:25:31.165Z{"msg":"Upstairs <-> Downstairs Message Version: 13","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:25:30.130800582Z","hostname":"w-01JPK2XYXNKNQHJ28D83W62KZ9","pid":1238}
1482025-03-17T22:25:31.165Z{"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-03-17T22:25:30.130816371Z","hostname":"w-01JPK2XYXNKNQHJ28D83W62KZ9","pid":1238}
1492025-03-17T22:25:31.165Z{"msg":"Crucible 142c1be5-c94c-4a5e-ac2b-863be227ff50 has session id: ee654b9d-111f-401c-aff0-1f8d71aa44c2","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:25:30.131457173Z","hostname":"w-01JPK2XYXNKNQHJ28D83W62KZ9","pid":1238,"session_id":"ee654b9d-111f-401c-aff0-1f8d71aa44c2"}
1502025-03-17T22:25:31.165Z{"msg":"Upstairs opts: Upstairs UUID: 142c1be5-c94c-4a5e-ac2b-863be227ff50, 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-03-17T22:25:30.131502184Z","hostname":"w-01JPK2XYXNKNQHJ28D83W62KZ9","pid":1238,"session_id":"ee654b9d-111f-401c-aff0-1f8d71aa44c2"}
1512025-03-17T22:25:31.165Z{"msg":"Crucible stats registered with UUID: 142c1be5-c94c-4a5e-ac2b-863be227ff50","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:25:30.131523564Z","hostname":"w-01JPK2XYXNKNQHJ28D83W62KZ9","pid":1238,"session_id":"ee654b9d-111f-401c-aff0-1f8d71aa44c2"}
1522025-03-17T22:25:31.165Z{"msg":"could not find Downstairs address for Nexus","v":0,"name":"crucible","level":40,"time":"2025-03-17T22:25:30.131545374Z","hostname":"w-01JPK2XYXNKNQHJ28D83W62KZ9","pid":1238,"session_id":"ee654b9d-111f-401c-aff0-1f8d71aa44c2"}
1532025-03-17T22:25:31.170Z{"msg":"SV 1 has targets: [127.0.0.1:8840, 127.0.0.1:8850, 127.0.0.1:8860]","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:25:30.13354217Z","hostname":"w-01JPK2XYXNKNQHJ28D83W62KZ9","pid":1238,"task":"crutest"}
1542025-03-17T22:25:31.170Z{"msg":"Upstairs starts","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:25:30.13362406Z","hostname":"w-01JPK2XYXNKNQHJ28D83W62KZ9","pid":1238}
1552025-03-17T22:25:31.170Z{"msg":"Crucible Version: BuildInfo {\n version: \"0.0.1\",\n git_sha: \"acc6b11fa639390710fd9a0449e05c901b048ed2\",\n git_commit_timestamp: \"2025-03-17T22:02:02.000000000Z\",\n git_branch: \"renovate/itertools-0.x\",\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:25:30.13365895Z","hostname":"w-01JPK2XYXNKNQHJ28D83W62KZ9","pid":1238}
1562025-03-17T22:25:31.170Z{"msg":"Upstairs <-> Downstairs Message Version: 13","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:25:30.13368015Z","hostname":"w-01JPK2XYXNKNQHJ28D83W62KZ9","pid":1238}
1572025-03-17T22:25:31.170Z{"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-03-17T22:25:30.13369455Z","hostname":"w-01JPK2XYXNKNQHJ28D83W62KZ9","pid":1238}
1582025-03-17T22:25:31.171Z{"msg":"Crucible 142c1be5-c94c-4a5e-ac2b-863be227ff50 has session id: 61deafc3-71a2-412b-8ec7-79345954f681","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:25:30.134125281Z","hostname":"w-01JPK2XYXNKNQHJ28D83W62KZ9","pid":1238,"session_id":"61deafc3-71a2-412b-8ec7-79345954f681"}
1592025-03-17T22:25:31.171Z{"msg":"Upstairs opts: Upstairs UUID: 142c1be5-c94c-4a5e-ac2b-863be227ff50, Targets: [127.0.0.1:8840, 127.0.0.1:8850, 127.0.0.1:8860], 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-03-17T22:25:30.134167372Z","hostname":"w-01JPK2XYXNKNQHJ28D83W62KZ9","pid":1238,"session_id":"61deafc3-71a2-412b-8ec7-79345954f681"}
1602025-03-17T22:25:31.171Z{"msg":"Crucible stats registered with UUID: 142c1be5-c94c-4a5e-ac2b-863be227ff50","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:25:30.134184362Z","hostname":"w-01JPK2XYXNKNQHJ28D83W62KZ9","pid":1238,"session_id":"61deafc3-71a2-412b-8ec7-79345954f681"}
1612025-03-17T22:25:31.171Z{"msg":"could not find Downstairs address for Nexus","v":0,"name":"crucible","level":40,"time":"2025-03-17T22:25:30.134197572Z","hostname":"w-01JPK2XYXNKNQHJ28D83W62KZ9","pid":1238,"session_id":"61deafc3-71a2-412b-8ec7-79345954f681"}
1622025-03-17T22:25:31.171Z{"msg":"Downstairs in volume = 6","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:25:30.134790374Z","hostname":"w-01JPK2XYXNKNQHJ28D83W62KZ9","pid":1238,"task":"crutest"}
1632025-03-17T22:25:31.171Z{"msg":"The guest has requested activation with gen:31","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:25:30.134811594Z","hostname":"w-01JPK2XYXNKNQHJ28D83W62KZ9","pid":1238}
1642025-03-17T22:25:31.171Z{"msg":"142c1be5-c94c-4a5e-ac2b-863be227ff50 active request set","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:25:30.134876104Z","hostname":"w-01JPK2XYXNKNQHJ28D83W62KZ9","pid":1238,"session_id":"ee654b9d-111f-401c-aff0-1f8d71aa44c2"}
1652025-03-17T22:25:31.171Z{"msg":"sending connect oneshot to client","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:25:30.134901094Z","hostname":"w-01JPK2XYXNKNQHJ28D83W62KZ9","pid":1238,"client":"0","":"downstairs","session_id":"ee654b9d-111f-401c-aff0-1f8d71aa44c2"}
1662025-03-17T22:25:31.171Z{"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:25:30.134962184Z","hostname":"w-01JPK2XYXNKNQHJ28D83W62KZ9","pid":1238,"client":"0","":"downstairs","session_id":"ee654b9d-111f-401c-aff0-1f8d71aa44c2"}
1672025-03-17T22:25:31.171Z{"msg":"sending connect oneshot to client","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:25:30.135009024Z","hostname":"w-01JPK2XYXNKNQHJ28D83W62KZ9","pid":1238,"client":"1","":"downstairs","session_id":"ee654b9d-111f-401c-aff0-1f8d71aa44c2"}
1682025-03-17T22:25:31.171Z{"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:25:30.135060354Z","hostname":"w-01JPK2XYXNKNQHJ28D83W62KZ9","pid":1238,"client":"1","":"downstairs","session_id":"ee654b9d-111f-401c-aff0-1f8d71aa44c2"}
1692025-03-17T22:25:31.171Z{"msg":"sending connect oneshot to client","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:25:30.135111094Z","hostname":"w-01JPK2XYXNKNQHJ28D83W62KZ9","pid":1238,"client":"2","":"downstairs","session_id":"ee654b9d-111f-401c-aff0-1f8d71aa44c2"}
1702025-03-17T22:25:31.171Z{"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:25:30.135141595Z","hostname":"w-01JPK2XYXNKNQHJ28D83W62KZ9","pid":1238,"client":"2","":"downstairs","session_id":"ee654b9d-111f-401c-aff0-1f8d71aa44c2"}
1712025-03-17T22:25:31.171Z{"msg":"connecting to 127.0.0.1:8830","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:25:30.135167384Z","hostname":"w-01JPK2XYXNKNQHJ28D83W62KZ9","pid":1238,"":"io task","client":"2","":"downstairs","session_id":"ee654b9d-111f-401c-aff0-1f8d71aa44c2"}
1722025-03-17T22:25:31.171Z{"msg":"connecting to 127.0.0.1:8810","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:25:30.135189385Z","hostname":"w-01JPK2XYXNKNQHJ28D83W62KZ9","pid":1238,"":"io task","client":"0","":"downstairs","session_id":"ee654b9d-111f-401c-aff0-1f8d71aa44c2"}
1732025-03-17T22:25:31.171Z{"msg":"connecting to 127.0.0.1:8820","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:25:30.135222245Z","hostname":"w-01JPK2XYXNKNQHJ28D83W62KZ9","pid":1238,"":"io task","client":"1","":"downstairs","session_id":"ee654b9d-111f-401c-aff0-1f8d71aa44c2"}
1742025-03-17T22:25:31.171Z{"msg":"ds_connection connected from Ok(127.0.0.1:64097)","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:25:30.135246065Z","hostname":"w-01JPK2XYXNKNQHJ28D83W62KZ9","pid":1238,"":"io task","client":"0","":"downstairs","session_id":"ee654b9d-111f-401c-aff0-1f8d71aa44c2"}
1752025-03-17T22:25:31.171Z{"msg":"ds_connection connected from Ok(127.0.0.1:64720)","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:25:30.135278295Z","hostname":"w-01JPK2XYXNKNQHJ28D83W62KZ9","pid":1238,"":"io task","client":"2","":"downstairs","session_id":"ee654b9d-111f-401c-aff0-1f8d71aa44c2"}
1762025-03-17T22:25:31.171Z{"msg":"ds_connection connected from Ok(127.0.0.1:34318)","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:25:30.135303195Z","hostname":"w-01JPK2XYXNKNQHJ28D83W62KZ9","pid":1238,"":"io task","client":"1","":"downstairs","session_id":"ee654b9d-111f-401c-aff0-1f8d71aa44c2"}
1772025-03-17T22:25:31.171Z{"msg":"version negotiation from state Connecting { state: WaitForPromote, mode: New }","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:25:30.135850857Z","hostname":"w-01JPK2XYXNKNQHJ28D83W62KZ9","pid":1238,"client":"2","":"downstairs","session_id":"ee654b9d-111f-401c-aff0-1f8d71aa44c2"}
1782025-03-17T22:25:31.171Z{"msg":"version negotiation from state Connecting { state: WaitForPromote, mode: New }","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:25:30.135891217Z","hostname":"w-01JPK2XYXNKNQHJ28D83W62KZ9","pid":1238,"client":"1","":"downstairs","session_id":"ee654b9d-111f-401c-aff0-1f8d71aa44c2"}
1792025-03-17T22:25:31.172Z{"msg":"version negotiation from state Connecting { state: WaitForPromote, mode: New }","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:25:30.135949657Z","hostname":"w-01JPK2XYXNKNQHJ28D83W62KZ9","pid":1238,"client":"0","":"downstairs","session_id":"ee654b9d-111f-401c-aff0-1f8d71aa44c2"}
1802025-03-17T22:25:31.178Z{"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:25:30.136535659Z","hostname":"w-01JPK2XYXNKNQHJ28D83W62KZ9","pid":1238,"client":"1","":"downstairs","session_id":"ee654b9d-111f-401c-aff0-1f8d71aa44c2"}
1812025-03-17T22:25:31.178Z{"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:25:30.136582259Z","hostname":"w-01JPK2XYXNKNQHJ28D83W62KZ9","pid":1238,"client":"2","":"downstairs","session_id":"ee654b9d-111f-401c-aff0-1f8d71aa44c2"}
1822025-03-17T22:25:31.178Z{"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:25:30.136653009Z","hostname":"w-01JPK2XYXNKNQHJ28D83W62KZ9","pid":1238,"client":"0","":"downstairs","session_id":"ee654b9d-111f-401c-aff0-1f8d71aa44c2"}
1832025-03-17T22:25:31.178Z{"msg":"Waiting for more clients to be ready","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:25:30.13700973Z","hostname":"w-01JPK2XYXNKNQHJ28D83W62KZ9","pid":1238,"session_id":"ee654b9d-111f-401c-aff0-1f8d71aa44c2"}
1842025-03-17T22:25:31.178Z{"msg":"Waiting for more clients to be ready","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:25:30.13704602Z","hostname":"w-01JPK2XYXNKNQHJ28D83W62KZ9","pid":1238,"session_id":"ee654b9d-111f-401c-aff0-1f8d71aa44c2"}
1852025-03-17T22:25:31.179Z{"msg":"[0]R flush_numbers: [3998, 3998, 3998, 3998, 3998]","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:25:30.13706029Z","hostname":"w-01JPK2XYXNKNQHJ28D83W62KZ9","pid":1238,"":"downstairs","":"downstairs","session_id":"ee654b9d-111f-401c-aff0-1f8d71aa44c2"}
1862025-03-17T22:25:31.179Z{"msg":"[0]R generation: [25, 25, 25, 25, 25]","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:25:30.13708186Z","hostname":"w-01JPK2XYXNKNQHJ28D83W62KZ9","pid":1238,"":"downstairs","":"downstairs","session_id":"ee654b9d-111f-401c-aff0-1f8d71aa44c2"}
1872025-03-17T22:25:31.179Z{"msg":"[0]R dirty: [false, false, false, false, false]","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:25:30.13709566Z","hostname":"w-01JPK2XYXNKNQHJ28D83W62KZ9","pid":1238,"":"downstairs","":"downstairs","session_id":"ee654b9d-111f-401c-aff0-1f8d71aa44c2"}
1882025-03-17T22:25:31.179Z{"msg":"[1]R flush_numbers: [3998, 3998, 3998, 3998, 3998]","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:25:30.13711549Z","hostname":"w-01JPK2XYXNKNQHJ28D83W62KZ9","pid":1238,"":"downstairs","":"downstairs","session_id":"ee654b9d-111f-401c-aff0-1f8d71aa44c2"}
1892025-03-17T22:25:31.179Z{"msg":"[1]R generation: [25, 25, 25, 25, 25]","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:25:30.137128681Z","hostname":"w-01JPK2XYXNKNQHJ28D83W62KZ9","pid":1238,"":"downstairs","":"downstairs","session_id":"ee654b9d-111f-401c-aff0-1f8d71aa44c2"}
1902025-03-17T22:25:31.179Z{"msg":"[1]R dirty: [false, false, false, false, false]","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:25:30.13714163Z","hostname":"w-01JPK2XYXNKNQHJ28D83W62KZ9","pid":1238,"":"downstairs","":"downstairs","session_id":"ee654b9d-111f-401c-aff0-1f8d71aa44c2"}
1912025-03-17T22:25:31.179Z{"msg":"[2]R flush_numbers: [3998, 3998, 3998, 3998, 3998]","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:25:30.137161481Z","hostname":"w-01JPK2XYXNKNQHJ28D83W62KZ9","pid":1238,"":"downstairs","":"downstairs","session_id":"ee654b9d-111f-401c-aff0-1f8d71aa44c2"}
1922025-03-17T22:25:31.179Z{"msg":"[2]R generation: [25, 25, 25, 25, 25]","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:25:30.13717455Z","hostname":"w-01JPK2XYXNKNQHJ28D83W62KZ9","pid":1238,"":"downstairs","":"downstairs","session_id":"ee654b9d-111f-401c-aff0-1f8d71aa44c2"}
1932025-03-17T22:25:31.179Z{"msg":"[2]R dirty: [false, false, false, false, false]","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:25:30.137200181Z","hostname":"w-01JPK2XYXNKNQHJ28D83W62KZ9","pid":1238,"":"downstairs","":"downstairs","session_id":"ee654b9d-111f-401c-aff0-1f8d71aa44c2"}
1942025-03-17T22:25:31.179Z{"msg":"Max found gen is 26","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:25:30.137230021Z","hostname":"w-01JPK2XYXNKNQHJ28D83W62KZ9","pid":1238,"":"downstairs","":"downstairs","session_id":"ee654b9d-111f-401c-aff0-1f8d71aa44c2"}
1952025-03-17T22:25:31.179Z{"msg":"Generation requested: 31 >= found:26","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:25:30.137244951Z","hostname":"w-01JPK2XYXNKNQHJ28D83W62KZ9","pid":1238,"":"downstairs","":"downstairs","session_id":"ee654b9d-111f-401c-aff0-1f8d71aa44c2"}
1962025-03-17T22:25:31.179Z{"msg":"Next flush: 3999","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:25:30.137268681Z","hostname":"w-01JPK2XYXNKNQHJ28D83W62KZ9","pid":1238,"":"downstairs","":"downstairs","session_id":"ee654b9d-111f-401c-aff0-1f8d71aa44c2"}
1972025-03-17T22:25:31.179Z{"msg":"All extents match","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:25:30.137298691Z","hostname":"w-01JPK2XYXNKNQHJ28D83W62KZ9","pid":1238,"":"downstairs","":"downstairs","session_id":"ee654b9d-111f-401c-aff0-1f8d71aa44c2"}
1982025-03-17T22:25:31.179Z{"msg":"No downstairs reconciliation required","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:25:30.137333211Z","hostname":"w-01JPK2XYXNKNQHJ28D83W62KZ9","pid":1238,"session_id":"ee654b9d-111f-401c-aff0-1f8d71aa44c2"}
1992025-03-17T22:25:31.179Z{"msg":"Transition from WaitQuorum to Active","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:25:30.137372061Z","hostname":"w-01JPK2XYXNKNQHJ28D83W62KZ9","pid":1238,"client":"0","":"downstairs","session_id":"ee654b9d-111f-401c-aff0-1f8d71aa44c2"}
2002025-03-17T22:25:31.179Z{"msg":"Transition from WaitQuorum to Active","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:25:30.137401391Z","hostname":"w-01JPK2XYXNKNQHJ28D83W62KZ9","pid":1238,"client":"1","":"downstairs","session_id":"ee654b9d-111f-401c-aff0-1f8d71aa44c2"}
2012025-03-17T22:25:31.179Z{"msg":"Transition from WaitQuorum to Active","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:25:30.137423631Z","hostname":"w-01JPK2XYXNKNQHJ28D83W62KZ9","pid":1238,"client":"2","":"downstairs","session_id":"ee654b9d-111f-401c-aff0-1f8d71aa44c2"}
2022025-03-17T22:25:31.179Z{"msg":"All required reconciliation work is completed","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:25:30.137444971Z","hostname":"w-01JPK2XYXNKNQHJ28D83W62KZ9","pid":1238,"session_id":"ee654b9d-111f-401c-aff0-1f8d71aa44c2"}
2032025-03-17T22:25:31.179Z{"msg":"Set Downstairs and Upstairs active after reconciliation","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:25:30.137486071Z","hostname":"w-01JPK2XYXNKNQHJ28D83W62KZ9","pid":1238,"session_id":"ee654b9d-111f-401c-aff0-1f8d71aa44c2"}
2042025-03-17T22:25:31.179Z{"msg":"142c1be5-c94c-4a5e-ac2b-863be227ff50 is now active with session: ee654b9d-111f-401c-aff0-1f8d71aa44c2","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:25:30.137509411Z","hostname":"w-01JPK2XYXNKNQHJ28D83W62KZ9","pid":1238,"session_id":"ee654b9d-111f-401c-aff0-1f8d71aa44c2"}
2052025-03-17T22:25:31.179Z{"msg":"Set Active after no reconciliation","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:25:30.137530202Z","hostname":"w-01JPK2XYXNKNQHJ28D83W62KZ9","pid":1238,"session_id":"ee654b9d-111f-401c-aff0-1f8d71aa44c2"}
2062025-03-17T22:25:31.179Z{"msg":"The guest has finished waiting for activation with:31","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:25:30.137655692Z","hostname":"w-01JPK2XYXNKNQHJ28D83W62KZ9","pid":1238}
2072025-03-17T22:25:31.179Z{"msg":"Activated sub_volume 142c1be5-c94c-4a5e-ac2b-863be227ff50","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:25:30.137689932Z","hostname":"w-01JPK2XYXNKNQHJ28D83W62KZ9","pid":1238}
2082025-03-17T22:25:31.179Z{"msg":"The guest has requested activation with gen:31","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:25:30.137702812Z","hostname":"w-01JPK2XYXNKNQHJ28D83W62KZ9","pid":1238}
2092025-03-17T22:25:31.180Z{"msg":"142c1be5-c94c-4a5e-ac2b-863be227ff50 active request set","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:25:30.137714532Z","hostname":"w-01JPK2XYXNKNQHJ28D83W62KZ9","pid":1238,"session_id":"61deafc3-71a2-412b-8ec7-79345954f681"}
2102025-03-17T22:25:31.180Z{"msg":"sending connect oneshot to client","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:25:30.137727232Z","hostname":"w-01JPK2XYXNKNQHJ28D83W62KZ9","pid":1238,"client":"0","":"downstairs","session_id":"61deafc3-71a2-412b-8ec7-79345954f681"}
2112025-03-17T22:25:31.180Z{"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:25:30.137743222Z","hostname":"w-01JPK2XYXNKNQHJ28D83W62KZ9","pid":1238,"client":"0","":"downstairs","session_id":"61deafc3-71a2-412b-8ec7-79345954f681"}
2122025-03-17T22:25:31.180Z{"msg":"sending connect oneshot to client","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:25:30.137767022Z","hostname":"w-01JPK2XYXNKNQHJ28D83W62KZ9","pid":1238,"client":"1","":"downstairs","session_id":"61deafc3-71a2-412b-8ec7-79345954f681"}
2132025-03-17T22:25:31.180Z{"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:25:30.137791822Z","hostname":"w-01JPK2XYXNKNQHJ28D83W62KZ9","pid":1238,"client":"1","":"downstairs","session_id":"61deafc3-71a2-412b-8ec7-79345954f681"}
2142025-03-17T22:25:31.180Z{"msg":"sending connect oneshot to client","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:25:30.137815192Z","hostname":"w-01JPK2XYXNKNQHJ28D83W62KZ9","pid":1238,"client":"2","":"downstairs","session_id":"61deafc3-71a2-412b-8ec7-79345954f681"}
2152025-03-17T22:25:31.180Z{"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:25:30.137864513Z","hostname":"w-01JPK2XYXNKNQHJ28D83W62KZ9","pid":1238,"client":"2","":"downstairs","session_id":"61deafc3-71a2-412b-8ec7-79345954f681"}
2162025-03-17T22:25:31.180Z{"msg":"connecting to 127.0.0.1:8860","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:25:30.137956013Z","hostname":"w-01JPK2XYXNKNQHJ28D83W62KZ9","pid":1238,"":"io task","client":"2","":"downstairs","session_id":"61deafc3-71a2-412b-8ec7-79345954f681"}
2172025-03-17T22:25:31.180Z{"msg":"connecting to 127.0.0.1:8840","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:25:30.138024963Z","hostname":"w-01JPK2XYXNKNQHJ28D83W62KZ9","pid":1238,"":"io task","client":"0","":"downstairs","session_id":"61deafc3-71a2-412b-8ec7-79345954f681"}
2182025-03-17T22:25:31.180Z{"msg":"connecting to 127.0.0.1:8850","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:25:30.138054953Z","hostname":"w-01JPK2XYXNKNQHJ28D83W62KZ9","pid":1238,"":"io task","client":"1","":"downstairs","session_id":"61deafc3-71a2-412b-8ec7-79345954f681"}
2192025-03-17T22:25:31.180Z{"msg":"ds_connection connected from Ok(127.0.0.1:38541)","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:25:30.138075873Z","hostname":"w-01JPK2XYXNKNQHJ28D83W62KZ9","pid":1238,"":"io task","client":"2","":"downstairs","session_id":"61deafc3-71a2-412b-8ec7-79345954f681"}
2202025-03-17T22:25:31.180Z{"msg":"ds_connection connected from Ok(127.0.0.1:64686)","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:25:30.138105743Z","hostname":"w-01JPK2XYXNKNQHJ28D83W62KZ9","pid":1238,"":"io task","client":"0","":"downstairs","session_id":"61deafc3-71a2-412b-8ec7-79345954f681"}
2212025-03-17T22:25:31.180Z{"msg":"ds_connection connected from Ok(127.0.0.1:55030)","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:25:30.138131153Z","hostname":"w-01JPK2XYXNKNQHJ28D83W62KZ9","pid":1238,"":"io task","client":"1","":"downstairs","session_id":"61deafc3-71a2-412b-8ec7-79345954f681"}
2222025-03-17T22:25:31.180Z{"msg":"version negotiation from state Connecting { state: WaitForPromote, mode: New }","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:25:30.138168693Z","hostname":"w-01JPK2XYXNKNQHJ28D83W62KZ9","pid":1238,"client":"0","":"downstairs","session_id":"61deafc3-71a2-412b-8ec7-79345954f681"}
2232025-03-17T22:25:31.180Z{"msg":"version negotiation from state Connecting { state: WaitForPromote, mode: New }","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:25:30.138192534Z","hostname":"w-01JPK2XYXNKNQHJ28D83W62KZ9","pid":1238,"client":"1","":"downstairs","session_id":"61deafc3-71a2-412b-8ec7-79345954f681"}
2242025-03-17T22:25:31.180Z{"msg":"version negotiation from state Connecting { state: WaitForPromote, mode: New }","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:25:30.138207334Z","hostname":"w-01JPK2XYXNKNQHJ28D83W62KZ9","pid":1238,"client":"2","":"downstairs","session_id":"61deafc3-71a2-412b-8ec7-79345954f681"}
2252025-03-17T22:25:31.180Z{"msg":"downstairs client at Some(127.0.0.1:8840) has region UUID 12345678-0000-0000-0000-000000008840","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:25:30.138506445Z","hostname":"w-01JPK2XYXNKNQHJ28D83W62KZ9","pid":1238,"client":"0","":"downstairs","session_id":"61deafc3-71a2-412b-8ec7-79345954f681"}
2262025-03-17T22:25:31.180Z{"msg":"downstairs client at Some(127.0.0.1:8850) has region UUID 12345678-0000-0000-0000-000000008850","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:25:30.138611225Z","hostname":"w-01JPK2XYXNKNQHJ28D83W62KZ9","pid":1238,"client":"1","":"downstairs","session_id":"61deafc3-71a2-412b-8ec7-79345954f681"}
2272025-03-17T22:25:31.180Z{"msg":"downstairs client at Some(127.0.0.1:8860) has region UUID 12345678-0000-0000-0000-000000008860","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:25:30.138640475Z","hostname":"w-01JPK2XYXNKNQHJ28D83W62KZ9","pid":1238,"client":"2","":"downstairs","session_id":"61deafc3-71a2-412b-8ec7-79345954f681"}
2282025-03-17T22:25:31.180Z{"msg":"Waiting for more clients to be ready","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:25:30.138845686Z","hostname":"w-01JPK2XYXNKNQHJ28D83W62KZ9","pid":1238,"session_id":"61deafc3-71a2-412b-8ec7-79345954f681"}
2292025-03-17T22:25:31.180Z{"msg":"Waiting for more clients to be ready","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:25:30.139008256Z","hostname":"w-01JPK2XYXNKNQHJ28D83W62KZ9","pid":1238,"session_id":"61deafc3-71a2-412b-8ec7-79345954f681"}
2302025-03-17T22:25:31.180Z{"msg":"[0]R flush_numbers: [5320, 5316, 5317, 5318, 5315]","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:25:30.139071076Z","hostname":"w-01JPK2XYXNKNQHJ28D83W62KZ9","pid":1238,"":"downstairs","":"downstairs","session_id":"61deafc3-71a2-412b-8ec7-79345954f681"}
2312025-03-17T22:25:31.180Z{"msg":"[0]R generation: [14, 14, 14, 14, 13]","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:25:30.139117046Z","hostname":"w-01JPK2XYXNKNQHJ28D83W62KZ9","pid":1238,"":"downstairs","":"downstairs","session_id":"61deafc3-71a2-412b-8ec7-79345954f681"}
2322025-03-17T22:25:31.180Z{"msg":"[0]R dirty: [false, false, false, false, false]","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:25:30.139190447Z","hostname":"w-01JPK2XYXNKNQHJ28D83W62KZ9","pid":1238,"":"downstairs","":"downstairs","session_id":"61deafc3-71a2-412b-8ec7-79345954f681"}
2332025-03-17T22:25:31.180Z{"msg":"[1]R flush_numbers: [5320, 5316, 5317, 5318, 5315]","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:25:30.139231177Z","hostname":"w-01JPK2XYXNKNQHJ28D83W62KZ9","pid":1238,""Wait for a query_work_queue command to finish before sending IO
2342025-03-17T22:25:31.181Z:"downstairs","":"downstairs","session_id":"61deafc3-71a2-412b-8ec7-79345954f681"}
2352025-03-17T22:25:31.181Z{"msg":"[1]R generation: [14, 14, 14, 14, 13]","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:25:30.139257197Z","hostname":"w-01JPK2XYXNKNQHJ28D83W62KZ9","pid":1238,"":"downstairs","":"downstairs","session_id":"61deafc3-71a2-412b-8ec7-79345954f681"}
2362025-03-17T22:25:31.181Z{"msg":"[1]R dirty: [false, false, false, false, false]","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:25:30.139288297Z","hostname":"w-01JPK2XYXNKNQHJ28D83W62KZ9","pid":1238,"":"downstairs","":"downstairs","session_id":"61deafc3-71a2-412b-8ec7-79345954f681"}
2372025-03-17T22:25:31.181Z{"msg":"[2]R flush_numbers: [5320, 5316, 5317, 5318, 5315]","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:25:30.139303347Z","hostname":"w-01JPK2XYXNKNQHJ28D83W62KZ9","pid":1238,"":"downstairs","":"downstairs","session_id":"61deafc3-71a2-412b-8ec7-79345954f681"}
2382025-03-17T22:25:31.181Z{"msg":"[2]R generation: [14, 14, 14, 14, 13]","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:25:30.139323647Z","hostname":"w-01JPK2XYXNKNQHJ28D83W62KZ9","pid":1238,"":"downstairs","":"downstairs","session_id":"61deafc3-71a2-412b-8ec7-79345954f681"}
2392025-03-17T22:25:31.181Z{"msg":"[2]R dirty: [false, false, false, false, false]","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:25:30.139338297Z","hostname":"w-01JPK2XYXNKNQHJ28D83W62KZ9","pid":1238,"":"downstairs","":"downstairs","session_id":"61deafc3-71a2-412b-8ec7-79345954f681"}
2402025-03-17T22:25:31.181Z{"msg":"Max found gen is 15","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:25:30.139368307Z","hostname":"w-01JPK2XYXNKNQHJ28D83W62KZ9","pid":1238,"":"downstairs","":"downstairs","session_id":"61deafc3-71a2-412b-8ec7-79345954f681"}
2412025-03-17T22:25:31.181Z{"msg":"Generation requested: 31 >= found:15","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:25:30.139407227Z","hostname":"w-01JPK2XYXNKNQHJ28D83W62KZ9","pid":1238,"":"downstairs","":"downstairs","session_id":"61deafc3-71a2-412b-8ec7-79345954f681"}
2422025-03-17T22:25:31.181Z{"msg":"Next flush: 5321","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:25:30.139420987Z","hostname":"w-01JPK2XYXNKNQHJ28D83W62KZ9","pid":1238,"":"downstairs","":"downstairs","session_id":"61deafc3-71a2-412b-8ec7-79345954f681"}
2432025-03-17T22:25:31.181Z{"msg":"All extents match","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:25:30.139433957Z","hostname":"w-01JPK2XYXNKNQHJ28D83W62KZ9","pid":1238,"":"downstairs","":"downstairs","session_id":"61deafc3-71a2-412b-8ec7-79345954f681"}
2442025-03-17T22:25:31.181Z{"msg":"No downstairs reconciliation required","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:25:30.139460527Z","hostname":"w-01JPK2XYXNKNQHJ28D83W62KZ9","pid":1238,"session_id":"61deafc3-71a2-412b-8ec7-79345954f681"}
2452025-03-17T22:25:31.181Z{"msg":"Transition from WaitQuorum to Active","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:25:30.139488537Z","hostname":"w-01JPK2XYXNKNQHJ28D83W62KZ9","pid":1238,"client":"0","":"downstairs","session_id":"61deafc3-71a2-412b-8ec7-79345954f681"}
2462025-03-17T22:25:31.181Z{"msg":"Transition from WaitQuorum to Active","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:25:30.139507897Z","hostname":"w-01JPK2XYXNKNQHJ28D83W62KZ9","pid":1238,"client":"1","":"downstairs","session_id":"61deafc3-71a2-412b-8ec7-79345954f681"}
2472025-03-17T22:25:31.181Z{"msg":"Transition from WaitQuorum to Active","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:25:30.139536528Z","hostname":"w-01JPK2XYXNKNQHJ28D83W62KZ9","pid":1238,"client":"2","":"downstairs","session_id":"61deafc3-71a2-412b-8ec7-79345954f681"}
2482025-03-17T22:25:31.181Z{"msg":"All required reconciliation work is completed","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:25:30.139555538Z","hostname":"w-01JPK2XYXNKNQHJ28D83W62KZ9","pid":1238,"session_id":"61deafc3-71a2-412b-8ec7-79345954f681"}
2492025-03-17T22:25:31.181Z{"msg":"Set Downstairs and Upstairs active after reconciliation","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:25:30.139582028Z","hostname":"w-01JPK2XYXNKNQHJ28D83W62KZ9","pid":1238,"session_id":"61deafc3-71a2-412b-8ec7-79345954f681"}
2502025-03-17T22:25:31.181Z{"msg":"142c1be5-c94c-4a5e-ac2b-863be227ff50 is now active with session: 61deafc3-71a2-412b-8ec7-79345954f681","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:25:30.139599038Z","hostname":"w-01JPK2XYXNKNQHJ28D83W62KZ9","pid":1238,"session_id":"61deafc3-71a2-412b-8ec7-79345954f681"}
2512025-03-17T22:25:31.181Z{"msg":"Set Active after no reconciliation","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:25:30.139626728Z","hostname":"w-01JPK2XYXNKNQHJ28D83W62KZ9","pid":1238,"session_id":"61deafc3-71a2-412b-8ec7-79345954f681"}
2522025-03-17T22:25:31.181Z{"msg":"The guest has finished waiting for activation with:31","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:25:30.139642648Z","hostname":"w-01JPK2XYXNKNQHJ28D83W62KZ9","pid":1238}
2532025-03-17T22:25:31.181Z{"msg":"Activated sub_volume 142c1be5-c94c-4a5e-ac2b-863be227ff50","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:25:30.139668888Z","hostname":"w-01JPK2XYXNKNQHJ28D83W62KZ9","pid":1238}
2542025-03-17T22:25:31.181ZDisk: sv:2 bs:4096 ts:409600 tb:100 max_io:100 or 409600
2552025-03-17T22:25:31.181ZFill test
2562025-03-17T22:25:31.218ZRead and Verify all blocks (0..100 range:false)
2572025-03-17T22:25:31.297ZWrote out file "/var/tmp/test_up-build/verify_file"
2582025-03-17T22:25:31.297ZCLIENT: Tests done. All submitted work has been ACK'd
2592025-03-17T22:25:31.301Z----------------------------------------------------------------
2602025-03-17T22:25:31.301Z Crucible gen:31 GIO:true work queues: Upstairs:0 downstairs:1
2612025-03-17T22:25:31.301ZStates: Active Active Active
2622025-03-17T22:25:31.301ZJOBID ACK TYPE BKS/EXT DS:0 DS:1 DS:2 REPLAY
2632025-03-17T22:25:31.301Z 1002 Acked Read 50 Done Done Done false
2642025-03-17T22:25:31.301Z STATES DS:0 DS:1 DS:2 TOTAL
2652025-03-17T22:25:31.301Z Sent 0 0 0 0
2662025-03-17T22:25:31.301Z Done 1 1 1 3
2672025-03-17T22:25:31.301Z Skipped 0 0 0 0
2682025-03-17T22:25:31.301Z Error 0 0 0 0
2692025-03-17T22:25:31.301ZLast Flush: Some(JobId(1001)) Some(JobId(1001)) Some(JobId(1001))
2702025-03-17T22:25:31.301ZDownstairs last five completed: 1001 1000
2712025-03-17T22:25:31.301ZUpstairs last five completed: 1002 1001 1000
2722025-03-17T22:25:31.301Z----------------------------------------------------------------
2732025-03-17T22:25:31.301Z Crucible gen:31 GIO:true work queues: Upstairs:0 downstairs:1
2742025-03-17T22:25:31.301ZStates: Active Active Active
2752025-03-17T22:25:31.301ZJOBID ACK TYPE BKS/EXT DS:0 DS:1 DS:2 REPLAY
2762025-03-17T22:25:31.301Z 1002 Acked Read 50 Done Done Done false
2772025-03-17T22:25:31.301Z STATES DS:0 DS:1 DS:2 TOTAL
2782025-03-17T22:25:31.302Z Sent 0 0 0 0
2792025-03-17T22:25:31.302Z Done 1 1 1 3
2802025-03-17T22:25:31.302Z Skipped 0 0 0 0
2812025-03-17T22:25:31.302Z Error 0 0 0 0
2822025-03-17T22:25:31.302ZLast Flush: Some(JobId(1001)) Some(JobId(1001)) Some(JobId(1001))
2832025-03-17T22:25:31.302ZDownstairs last five completed: 1001 1000
2842025-03-17T22:25:31.302ZUpstairs last five completed: 1002 1001 1000
2852025-03-17T22:25:31.302ZCLIENT: Up:0 ds:2 act:6
2862025-03-17T22:25:35.300Z----------------------------------------------------------------
2872025-03-17T22:25:35.300Z Crucible gen:31 GIO:true work queues: Upstairs:0 downstairs:0
2882025-03-17T22:25:35.300ZDownstairs last five completed: 1003 1002 1001 1000
2892025-03-17T22:25:35.300ZUpstairs last five completed: 1003 1002 1001 1000
2902025-03-17T22:25:35.304Z----------------------------------------------------------------
2912025-03-17T22:25:35.304Z Crucible gen:31 GIO:true work queues: Upstairs:0 downstairs:0
2922025-03-17T22:25:35.304ZDownstairs last five completed: 1003 1002 1001 1000
2932025-03-17T22:25:35.304ZUpstairs last five completed: 1003 1002 1001 1000
2942025-03-17T22:25:35.304ZCLIENT: Up:0 ds:0 act:6
2952025-03-17T22:25:35.304ZCLIENT: All crucible jobs finished, exiting program
2962025-03-17T22:25:35.304Z{"msg":"Guest handle has been dropped","v":0,"name":"crucible","level":40,"time":"2025-03-17T22:25:34.266355092Z","hostname":"w-01JPK2XYXNKNQHJ28D83W62KZ9","pid":1238}
2972025-03-17T22:25:35.310ZRepair setup passed
2982025-03-17T22:25:35.313ZCopy the region for /var/tmp/test_up-build/8830
2992025-03-17T22:25:35.316Zcp -r /var/tmp/test_up-build/8830 /var/tmp/test_up-build/previous
3002025-03-17T22:25:35.320Z/var/tmp/bins/crutest fill -g 32 -q --key dTo8OYwJ4nmwk+WBHlLjCGc4PhTEPwEIOae/e9F5cFU= --dsc 127.0.0.1:9998 --verify-out /var/tmp/test_up-build/verify_file --verify-in /var/tmp/test_up-build/verify_file
3012025-03-17T22:25:35.373Z{"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:25:34.341216316Z","hostname":"w-01JPK2XYXNKNQHJ28D83W62KZ9","pid":1244,"task":"crutest"}
3022025-03-17T22:25:35.377Z{"msg":"dsc has 6 regions. This means 2 sub_volumes","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:25:34.341717438Z","hostname":"w-01JPK2XYXNKNQHJ28D83W62KZ9","pid":1244,"task":"crutest"}
3032025-03-17T22:25:35.377Z{"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:25:34.343368952Z","hostname":"w-01JPK2XYXNKNQHJ28D83W62KZ9","pid":1244,"task":"crutest"}
3042025-03-17T22:25:35.377Z{"msg":"Upstairs starts","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:25:34.343551073Z","hostname":"w-01JPK2XYXNKNQHJ28D83W62KZ9","pid":1244}
3052025-03-17T22:25:35.377Z{"msg":"Crucible Version: BuildInfo {\n version: \"0.0.1\",\n git_sha: \"acc6b11fa639390710fd9a0449e05c901b048ed2\",\n git_commit_timestamp: \"2025-03-17T22:02:02.000000000Z\",\n git_branch: \"renovate/itertools-0.x\",\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:25:34.343602833Z","hostname":"w-01JPK2XYXNKNQHJ28D83W62KZ9","pid":1244}
3062025-03-17T22:25:35.378Z{"msg":"Upstairs <-> Downstairs Message Version: 13","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:25:34.343632203Z","hostname":"w-01JPK2XYXNKNQHJ28D83W62KZ9","pid":1244}
3072025-03-17T22:25:35.378Z{"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-03-17T22:25:34.343652683Z","hostname":"w-01JPK2XYXNKNQHJ28D83W62KZ9","pid":1244}
3082025-03-17T22:25:35.378Z{"msg":"Crucible ae1a52fa-2b67-497c-969c-bb85ce98d076 has session id: 3925800d-b030-4b57-9470-9a36f9d1941e","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:25:34.344229505Z","hostname":"w-01JPK2XYXNKNQHJ28D83W62KZ9","pid":1244,"session_id":"3925800d-b030-4b57-9470-9a36f9d1941e"}
3092025-03-17T22:25:35.378Z{"msg":"Upstairs opts: Upstairs UUID: ae1a52fa-2b67-497c-969c-bb85ce98d076, 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-03-17T22:25:34.344285825Z","hostname":"w-01JPK2XYXNKNQHJ28D83W62KZ9","pid":1244,"session_id":"3925800d-b030-4b57-9470-9a36f9d1941e"}
3102025-03-17T22:25:35.378Z{"msg":"Crucible stats registered with UUID: ae1a52fa-2b67-497c-969c-bb85ce98d076","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:25:34.344307915Z","hostname":"w-01JPK2XYXNKNQHJ28D83W62KZ9","pid":1244,"session_id":"3925800d-b030-4b57-9470-9a36f9d1941e"}
3112025-03-17T22:25:35.378Z{"msg":"could not find Downstairs address for Nexus","v":0,"name":"crucible","level":40,"time":"2025-03-17T22:25:34.344346606Z","hostname":"w-01JPK2XYXNKNQHJ28D83W62KZ9","pid":1244,"session_id":"3925800d-b030-4b57-9470-9a36f9d1941e"}
3122025-03-17T22:25:35.381Z{"msg":"SV 1 has targets: [127.0.0.1:8840, 127.0.0.1:8850, 127.0.0.1:8860]","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:25:34.346255801Z","hostname":"w-01JPK2XYXNKNQHJ28D83W62KZ9","pid":1244,"task":"crutest"}
3132025-03-17T22:25:35.381Z{"msg":"Upstairs starts","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:25:34.346369272Z","hostname":"w-01JPK2XYXNKNQHJ28D83W62KZ9","pid":1244}
3142025-03-17T22:25:35.381Z{"msg":"Crucible Version: BuildInfo {\n version: \"0.0.1\",\n git_sha: \"acc6b11fa639390710fd9a0449e05c901b048ed2\",\n git_commit_timestamp: \"2025-03-17T22:02:02.000000000Z\",\n git_branch: \"renovate/itertools-0.x\",\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:25:34.346404212Z","hostname":"w-01JPK2XYXNKNQHJ28D83W62KZ9","pid":1244}
3152025-03-17T22:25:35.381Z{"msg":"Upstairs <-> Downstairs Message Version: 13","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:25:34.346416952Z","hostname":"w-01JPK2XYXNKNQHJ28D83W62KZ9","pid":1244}
3162025-03-17T22:25:35.381Z{"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-03-17T22:25:34.346431052Z","hostname":"w-01JPK2XYXNKNQHJ28D83W62KZ9","pid":1244}
3172025-03-17T22:25:35.381Z{"msg":"Crucible ae1a52fa-2b67-497c-969c-bb85ce98d076 has session id: 9b5ea180-40d0-458d-b9f6-f0b4fca0bc94","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:25:34.346797883Z","hostname":"w-01JPK2XYXNKNQHJ28D83W62KZ9","pid":1244,"session_id":"9b5ea180-40d0-458d-b9f6-f0b4fca0bc94"}
3182025-03-17T22:25:35.381Z{"msg":"Upstairs opts: Upstairs UUID: ae1a52fa-2b67-497c-969c-bb85ce98d076, Targets: [127.0.0.1:8840, 127.0.0.1:8850, 127.0.0.1:8860], 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-03-17T22:25:34.346843823Z","hostname":"w-01JPK2XYXNKNQHJ28D83W62KZ9","pid":1244,"session_id":"9b5ea180-40d0-458d-b9f6-f0b4fca0bc94"}
3192025-03-17T22:25:35.382Z{"msg":"Crucible stats registered with UUID: ae1a52fa-2b67-497c-969c-bb85ce98d076","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:25:34.346867853Z","hostname":"w-01JPK2XYXNKNQHJ28D83W62KZ9","pid":1244,"session_id":"9b5ea180-40d0-458d-b9f6-f0b4fca0bc94"}
3202025-03-17T22:25:35.382Z{"msg":"could not find Downstairs address for Nexus","v":0,"name":"crucible","level":40,"time":"2025-03-17T22:25:34.346905703Z","hostname":"w-01JPK2XYXNKNQHJ28D83W62KZ9","pid":1244,"session_id":"9b5ea180-40d0-458d-b9f6-f0b4fca0bc94"}
3212025-03-17T22:25:35.382Z{"msg":"Downstairs in volume = 6","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:25:34.347542595Z","hostname":"w-01JPK2XYXNKNQHJ28D83W62KZ9","pid":1244,"task":"crutest"}
3222025-03-17T22:25:35.382Z{"msg":"The guest has requested activation with gen:32","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:25:34.347582295Z","hostname":"w-01JPK2XYXNKNQHJ28D83W62KZ9","pid":1244}
3232025-03-17T22:25:35.382Z{"msg":"ae1a52fa-2b67-497c-969c-bb85ce98d076 active request set","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:25:34.347617775Z","hostname":"w-01JPK2XYXNKNQHJ28D83W62KZ9","pid":1244,"session_id":"3925800d-b030-4b57-9470-9a36f9d1941e"}
3242025-03-17T22:25:35.382Z{"msg":"sending connect oneshot to client","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:25:34.347643555Z","hostname":"w-01JPK2XYXNKNQHJ28D83W62KZ9","pid":1244,"client":"0","":"downstairs","session_id":"3925800d-b030-4b57-9470-9a36f9d1941e"}
3252025-03-17T22:25:35.382Z{"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:25:34.347693776Z","hostname":"w-01JPK2XYXNKNQHJ28D83W62KZ9","pid":1244,"client":"0","":"downstairs","session_id":"3925800d-b030-4b57-9470-9a36f9d1941e"}
3262025-03-17T22:25:35.382Z{"msg":"sending connect oneshot to client","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:25:34.347721805Z","hostname":"w-01JPK2XYXNKNQHJ28D83W62KZ9","pid":1244,"client":"1","":"downstairs","session_id":"3925800d-b030-4b57-9470-9a36f9d1941e"}
3272025-03-17T22:25:35.382Z{"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:25:34.347767346Z","hostname":"w-01JPK2XYXNKNQHJ28D83W62KZ9","pid":1244,"client":"1","":"downstairs","session_id":"3925800d-b030-4b57-9470-9a36f9d1941e"}
3282025-03-17T22:25:35.382Z{"msg":"sending connect oneshot to client","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:25:34.347792806Z","hostname":"w-01JPK2XYXNKNQHJ28D83W62KZ9","pid":1244,"client":"2","":"downstairs","session_id":"3925800d-b030-4b57-9470-9a36f9d1941e"}
3292025-03-17T22:25:35.382Z{"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:25:34.347829686Z","hostname":"w-01JPK2XYXNKNQHJ28D83W62KZ9","pid":1244,"client":"2","":"downstairs","session_id":"3925800d-b030-4b57-9470-9a36f9d1941e"}
3302025-03-17T22:25:35.382Z{"msg":"connecting to 127.0.0.1:8830","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:25:34.347869106Z","hostname":"w-01JPK2XYXNKNQHJ28D83W62KZ9","pid":1244,"":"io task","client":"2","":"downstairs","session_id":"3925800d-b030-4b57-9470-9a36f9d1941e"}
3312025-03-17T22:25:35.382Z{"msg":"connecting to 127.0.0.1:8810","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:25:34.347894016Z","hostname":"w-01JPK2XYXNKNQHJ28D83W62KZ9","pid":1244,"":"io task","client":"0","":"downstairs","session_id":"3925800d-b030-4b57-9470-9a36f9d1941e"}
3322025-03-17T22:25:35.382Z{"msg":"connecting to 127.0.0.1:8820","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:25:34.347928596Z","hostname":"w-01JPK2XYXNKNQHJ28D83W62KZ9","pid":1244,"":"io task","client":"1","":"downstairs","session_id":"3925800d-b030-4b57-9470-9a36f9d1941e"}
3332025-03-17T22:25:35.382Z{"msg":"ds_connection connected from Ok(127.0.0.1:61275)","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:25:34.347963016Z","hostname":"w-01JPK2XYXNKNQHJ28D83W62KZ9","pid":1244,"":"io task","client":"0","":"downstairs","session_id":"3925800d-b030-4b57-9470-9a36f9d1941e"}
3342025-03-17T22:25:35.382Z{"msg":"ds_connection connected from Ok(127.0.0.1:36029)","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:25:34.347995386Z","hostname":"w-01JPK2XYXNKNQHJ28D83W62KZ9","pid":1244,"":"io task","client":"2","":"downstairs","session_id":"3925800d-b030-4b57-9470-9a36f9d1941e"}
3352025-03-17T22:25:35.382Z{"msg":"ds_connection connected from Ok(127.0.0.1:41343)","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:25:34.348018386Z","hostname":"w-01JPK2XYXNKNQHJ28D83W62KZ9","pid":1244,"":"io task","client":"1","":"downstairs","session_id":"3925800d-b030-4b57-9470-9a36f9d1941e"}
3362025-03-17T22:25:35.382Z{"msg":"version negotiation from state Connecting { state: WaitForPromote, mode: New }","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:25:34.348736739Z","hostname":"w-01JPK2XYXNKNQHJ28D83W62KZ9","pid":1244,"client":"0","":"downstairs","session_id":"3925800d-b030-4b57-9470-9a36f9d1941e"}
3372025-03-17T22:25:35.382Z{"msg":"version negotiation from state Connecting { state: WaitForPromote, mode: New }","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:25:34.348778069Z","hostname":"w-01JPK2XYXNKNQHJ28D83W62KZ9","pid":1244,"client":"2","":"downstairs","session_id":"3925800d-b030-4b57-9470-9a36f9d1941e"}
3382025-03-17T22:25:35.382Z{"msg":"version negotiation from state Connecting { state: WaitForPromote, mode: New }","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:25:34.348871109Z","hostname":"w-01JPK2XYXNKNQHJ28D83W62KZ9","pid":1244,"client":"1","":"downstairs","session_id":"3925800d-b030-4b57-9470-9a36f9d1941e"}
3392025-03-17T22:25:35.387Z{"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:25:34.349408471Z","hostname":"w-01JPK2XYXNKNQHJ28D83W62KZ9","pid":1244,"client":"1","":"downstairs","session_id":"3925800d-b030-4b57-9470-9a36f9d1941e"}
3402025-03-17T22:25:35.387Z{"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:25:34.349549251Z","hostname":"w-01JPK2XYXNKNQHJ28D83W62KZ9","pid":1244,"client":"2","":"downstairs","session_id":"3925800d-b030-4b57-9470-9a36f9d1941e"}
3412025-03-17T22:25:35.387Z{"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:25:34.349586891Z","hostname":"w-01JPK2XYXNKNQHJ28D83W62KZ9","pid":1244,"client":"0","":"downstairs","session_id":"3925800d-b030-4b57-9470-9a36f9d1941e"}
3422025-03-17T22:25:35.387Z{"msg":"Waiting for more clients to be ready","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:25:34.349811522Z","hostname":"w-01JPK2XYXNKNQHJ28D83W62KZ9","pid":1244,"session_id":"3925800d-b030-4b57-9470-9a36f9d1941e"}
3432025-03-17T22:25:35.387Z{"msg":"Waiting for more clients to be ready","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:25:34.349889092Z","hostname":"w-01JPK2XYXNKNQHJ28D83W62KZ9","pid":1244,"session_id":"3925800d-b030-4b57-9470-9a36f9d1941e"}
3442025-03-17T22:25:35.387Z{"msg":"[0]R flush_numbers: [3999, 3999, 3999, 3999, 3999]","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:25:34.350004892Z","hostname":"w-01JPK2XYXNKNQHJ28D83W62KZ9","pid":1244,"":"downstairs","":"downstairs","session_id":"3925800d-b030-4b57-9470-9a36f9d1941e"}
3452025-03-17T22:25:35.387Z{"msg":"[0]R generation: [31, 31, 31, 31, 31]","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:25:34.350032763Z","hostname":"w-01JPK2XYXNKNQHJ28D83W62KZ9","pid":1244,"":"downstairs","":"downstairs","session_id":"3925800d-b030-4b57-9470-9a36f9d1941e"}
3462025-03-17T22:25:35.387Z{"msg":"[0]R dirty: [false, false, false, false, false]","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:25:34.350072183Z","hostname":"w-01JPK2XYXNKNQHJ28D83W62KZ9","pid":1244,"":"downstairs","":"downstairs","session_id":"3925800d-b030-4b57-9470-9a36f9d1941e"}
3472025-03-17T22:25:35.387Z{"msg":"[1]R flush_numbers: [3999, 3999, 3999, 3999, 3999]","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:25:34.350123433Z","hostname":"w-01JPK2XYXNKNQHJ28D83W62KZ9","pid":1244,"":"downstairs","":"downstairs","session_id":"3925800d-b030-4b57-9470-9a36f9d1941e"}
3482025-03-17T22:25:35.387Z{"msg":"[1]R generation: [31, 31, 31, 31, 31]","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:25:34.350156953Z","hostname":"w-01JPK2XYXNKNQHJ28D83W62KZ9","pid":1244,"":"downstairs","":"downstairs","session_id":"3925800d-b030-4b57-9470-9a36f9d1941e"}
3492025-03-17T22:25:35.387Z{"msg":"[1]R dirty: [false, false, false, false, false]","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:25:34.350175343Z","hostname":"w-01JPK2XYXNKNQHJ28D83W62KZ9","pid":1244,"":"downstairs","":"downstairs","session_id":"3925800d-b030-4b57-9470-9a36f9d1941e"}
3502025-03-17T22:25:35.387Z{"msg":"[2]R flush_numbers: [3999, 3999, 3999, 3999, 3999]","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:25:34.350204333Z","hostname":"w-01JPK2XYXNKNQHJ28D83W62KZ9","pid":1244,"":"downstairs","":"downstairs","session_id":"3925800d-b030-4b57-9470-9a36f9d1941e"}
3512025-03-17T22:25:35.387Z{"msg":"[2]R generation: [31, 31, 31, 31, 31]","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:25:34.350220263Z","hostname":"w-01JPK2XYXNKNQHJ28D83W62KZ9","pid":1244,"":"downstairs","":"downstairs","session_id":"3925800d-b030-4b57-9470-9a36f9d1941e"}
3522025-03-17T22:25:35.388Z{"msg":"[2]R dirty: [false, false, false, false, false]","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:25:34.350250403Z","hostname":"w-01JPK2XYXNKNQHJ28D83W62KZ9","pid":1244,"":"downstairs","":"downstairs","session_id":"3925800d-b030-4b57-9470-9a36f9d1941e"}
3532025-03-17T22:25:35.388Z{"msg":"Max found gen is 32","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:25:34.350266553Z","hostname":"w-01JPK2XYXNKNQHJ28D83W62KZ9","pid":1244,"":"downstairs","":"downstairs","session_id":"3925800d-b030-4b57-9470-9a36f9d1941e"}
3542025-03-17T22:25:35.388Z{"msg":"Generation requested: 32 >= found:32","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:25:34.350296213Z","hostname":"w-01JPK2XYXNKNQHJ28D83W62KZ9","pid":1244,"":"downstairs","":"downstairs","session_id":"3925800d-b030-4b57-9470-9a36f9d1941e"}
3552025-03-17T22:25:35.388Z{"msg":"Next flush: 4000","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:25:34.350310953Z","hostname":"w-01JPK2XYXNKNQHJ28D83W62KZ9","pid":1244,"":"downstairs","":"downstairs","session_id":"3925800d-b030-4b57-9470-9a36f9d1941e"}
3562025-03-17T22:25:35.388Z{"msg":"All extents match","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:25:34.350325153Z","hostname":"w-01JPK2XYXNKNQHJ28D83W62KZ9","pid":1244,"":"downstairs","":"downstairs","session_id":"3925800d-b030-4b57-9470-9a36f9d1941e"}
3572025-03-17T22:25:35.388Z{"msg":"No downstairs reconciliation required","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:25:34.350361704Z","hostname":"w-01JPK2XYXNKNQHJ28D83W62KZ9","pid":1244,"session_id":"3925800d-b030-4b57-9470-9a36f9d1941e"}
3582025-03-17T22:25:35.388Z{"msg":"Transition from WaitQuorum to Active","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:25:34.350384133Z","hostname":"w-01JPK2XYXNKNQHJ28D83W62KZ9","pid":1244,"client":"0","":"downstairs","session_id":"3925800d-b030-4b57-9470-9a36f9d1941e"}
3592025-03-17T22:25:35.388Z{"msg":"Transition from WaitQuorum to Active","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:25:34.350408194Z","hostname":"w-01JPK2XYXNKNQHJ28D83W62KZ9","pid":1244,"client":"1","":"downstairs","session_id":"3925800d-b030-4b57-9470-9a36f9d1941e"}
3602025-03-17T22:25:35.388Z{"msg":"Transition from WaitQuorum to Active","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:25:34.350434114Z","hostname":"w-01JPK2XYXNKNQHJ28D83W62KZ9","pid":1244,"client":"2","":"downstairs","session_id":"3925800d-b030-4b57-9470-9a36f9d1941e"}
3612025-03-17T22:25:35.388Z{"msg":"All required reconciliation work is completed","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:25:34.350470464Z","hostname":"w-01JPK2XYXNKNQHJ28D83W62KZ9","pid":1244,"session_id":"3925800d-b030-4b57-9470-9a36f9d1941e"}
3622025-03-17T22:25:35.388Z{"msg":"Set Downstairs and Upstairs active after reconciliation","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:25:34.350624014Z","hostname":"w-01JPK2XYXNKNQHJ28D83W62KZ9","pid":1244,"session_id":"3925800d-b030-4b57-9470-9a36f9d1941e"}
3632025-03-17T22:25:35.388Z{"msg":"ae1a52fa-2b67-497c-969c-bb85ce98d076 is now active with session: 3925800d-b030-4b57-9470-9a36f9d1941e","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:25:34.350659074Z","hostname":"w-01JPK2XYXNKNQHJ28D83W62KZ9","pid":1244,"session_id":"3925800d-b030-4b57-9470-9a36f9d1941e"}
3642025-03-17T22:25:35.388Z{"msg":"Set Active after no reconciliation","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:25:34.350681905Z","hostname":"w-01JPK2XYXNKNQHJ28D83W62KZ9","pid":1244,"session_id":"3925800d-b030-4b57-9470-9a36f9d1941e"}
3652025-03-17T22:25:35.388Z{"msg":"The guest has finished waiting for activation with:32","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:25:34.350719234Z","hostname":"w-01JPK2XYXNKNQHJ28D83W62KZ9","pid":1244}
3662025-03-17T22:25:35.388Z{"msg":"Activated sub_volume ae1a52fa-2b67-497c-969c-bb85ce98d076","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:25:34.350757505Z","hostname":"w-01JPK2XYXNKNQHJ28D83W62KZ9","pid":1244}
3672025-03-17T22:25:35.388Z{"msg":"The guest has requested activation with gen:32","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:25:34.350782555Z","hostname":"w-01JPK2XYXNKNQHJ28D83W62KZ9","pid":1244}
3682025-03-17T22:25:35.388Z{"msg":"ae1a52fa-2b67-497c-969c-bb85ce98d076 active request set","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:25:34.350854085Z","hostname":"w-01JPK2XYXNKNQHJ28D83W62KZ9","pid":1244,"session_id":"9b5ea180-40d0-458d-b9f6-f0b4fca0bc94"}
3692025-03-17T22:25:35.388Z{"msg":"sending connect oneshot to client","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:25:34.350902945Z","hostname":"w-01JPK2XYXNKNQHJ28D83W62KZ9","pid":1244,"client":"0","":"downstairs","session_id":"9b5ea180-40d0-458d-b9f6-f0b4fca0bc94"}
3702025-03-17T22:25:35.388Z{"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:25:34.350937685Z","hostname":"w-01JPK2XYXNKNQHJ28D83W62KZ9","pid":1244,"client":"0","":"downstairs","session_id":"9b5ea180-40d0-458d-b9f6-f0b4fca0bc94"}
3712025-03-17T22:25:35.388Z{"msg":"sending connect oneshot to client","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:25:34.350975765Z","hostname":"w-01JPK2XYXNKNQHJ28D83W62KZ9","pid":1244,"client":"1","":"downstairs","session_id":"9b5ea180-40d0-458d-b9f6-f0b4fca0bc94"}
3722025-03-17T22:25:35.388Z{"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:25:34.351007226Z","hostname":"w-01JPK2XYXNKNQHJ28D83W62KZ9","pid":1244,"client":"1","":"downstairs","session_id":"9b5ea180-40d0-458d-b9f6-f0b4fca0bc94"}
3732025-03-17T22:25:35.388Z{"msg":"sending connect oneshot to client","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:25:34.351074736Z","hostname":"w-01JPK2XYXNKNQHJ28D83W62KZ9","pid":1244,"client":"2","":"downstairs","session_id":"9b5ea180-40d0-458d-b9f6-f0b4fca0bc94"}
3742025-03-17T22:25:35.388Z{"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:25:34.351092116Z","hostname":"w-01JPK2XYXNKNQHJ28D83W62KZ9","pid":1244,"client":"2","":"downstairs","session_id":"9b5ea180-40d0-458d-b9f6-f0b4fca0bc94"}
3752025-03-17T22:25:35.388Z{"msg":"connecting to 127.0.0.1:8860","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:25:34.351122156Z","hostname":"w-01JPK2XYXNKNQHJ28D83W62KZ9","pid":1244,"":"io task","client":"2","":"downstairs","session_id":"9b5ea180-40d0-458d-b9f6-f0b4fca0bc94"}
3762025-03-17T22:25:35.388Z{"msg":"connecting to 127.0.0.1:8840","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:25:34.351149786Z","hostname":"w-01JPK2XYXNKNQHJ28D83W62KZ9","pid":1244,"":"io task","client":"0","":"downstairs","session_id":"9b5ea180-40d0-458d-b9f6-f0b4fca0bc94"}
3772025-03-17T22:25:35.388Z{"msg":"connecting to 127.0.0.1:8850","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:25:34.351177416Z","hostname":"w-01JPK2XYXNKNQHJ28D83W62KZ9","pid":1244,"":"io task","client":"1","":"downstairs","session_id":"9b5ea180-40d0-458d-b9f6-f0b4fca0bc94"}
3782025-03-17T22:25:35.388Z{"msg":"ds_connection connected from Ok(127.0.0.1:48892)","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:25:34.351221526Z","hostname":"w-01JPK2XYXNKNQHJ28D83W62KZ9","pid":1244,"":"io task","client":"2","":"downstairs","session_id":"9b5ea180-40d0-458d-b9f6-f0b4fca0bc94"}
3792025-03-17T22:25:35.388Z{"msg":"ds_connection connected from Ok(127.0.0.1:33211)","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:25:34.351246696Z","hostname":"w-01JPK2XYXNKNQHJ28D83W62KZ9","pid":1244,"":"io task","client":"1","":"downstairs","session_id":"9b5ea180-40d0-458d-b9f6-f0b4fca0bc94"}
3802025-03-17T22:25:35.388Z{"msg":"ds_connection connected from Ok(127.0.0.1:39225)","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:25:34.351261566Z","hostname":"w-01JPK2XYXNKNQHJ28D83W62KZ9","pid":1244,"":"io task","client":"0","":"downstairs","session_id":"9b5ea180-40d0-458d-b9f6-f0b4fca0bc94"}
3812025-03-17T22:25:35.388Z{"msg":"version negotiation from state Connecting { state: WaitForPromote, mode: New }","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:25:34.351288776Z","hostname":"w-01JPK2XYXNKNQHJ28D83W62KZ9","pid":1244,"client":"2","":"downstairs","session_id":"9b5ea180-40d0-458d-b9f6-f0b4fca0bc94"}
3822025-03-17T22:25:35.388Z{"msg":"version negotiation from state Connecting { state: WaitForPromote, mode: New }","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:25:34.351303126Z","hostname":"w-01JPK2XYXNKNQHJ28D83W62KZ9","pid":1244,"client":"1","":"downstairs","session_id":"9b5ea180-40d0-458d-b9f6-f0b4fca0bc94"}
3832025-03-17T22:25:35.388Z{"msg":"version negotiation from state Connecting { state: WaitForPromote, mode: New }","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:25:34.351316736Z","hostname":"w-01JPK2XYXNKNQHJ28D83W62KZ9","pid":1244,"client":"0","":"downstairs","session_id":"9b5ea180-40d0-458d-b9f6-f0b4fca0bc94"}
3842025-03-17T22:25:35.388Z{"msg":"downstairs client at Some(127.0.0.1:8850) has region UUID 12345678-0000-0000-0000-000000008850","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:25:34.351433187Z","hostname":"w-01JPK2XYXNKNQHJ28D83W62KZ9","pid":1244,"client":"1","":"downstairs","session_id":"9b5ea180-40d0-458d-b9f6-f0b4fca0bc94"}
3852025-03-17T22:25:35.389Z{"msg":"downstairs client at Some(127.0.0.1:8860) has region UUID 12345678-0000-0000-0000-000000008860","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:25:34.351466417Z","hostname":"w-01JPK2XYXNKNQHJ28D83W62KZ9","pid":1244,"client":"2","":"downstairs","session_id":"9b5ea180-40d0-458d-b9f6-f0b4fca0bc94"}
3862025-03-17T22:25:35.389Z{"msg":"downstairs client at Some(127.0.0.1:8840) has region UUID 12345678-0000-0000-0000-000000008840","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:25:34.351482287Z","hostname":"w-01JPK2XYXNKNQHJ28D83W62KZ9","pid":1244,"client":"0","":"downstairs","session_id":"9b5ea180-40d0-458d-b9f6-f0b4fca0bc94"}
3872025-03-17T22:25:35.389Z{"msg":"Waiting for more clients to be ready","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:25:34.351813418Z","hostname":"w-01JPK2XYXNKNQHJ28D83W62KZ9","pid":1244,"session_id":"9b5ea180-40d0-458d-b9f6-f0b4fca0bc94"}
3882025-03-17T22:25:35.389Z{"msg":"Waiting for more clients to be ready","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:25:34.351865648Z","hostname":"w-01JPK2XYXNKNQHJ28D83W62KZ9","pid":1244,"session_id":"9b5ea180-40d0-458d-b9f6-f0b4fca0bc94"}
3892025-03-17T22:25:35.389Z{"msg":"[0]R flush_numbers: [5321, 5321, 5321, 5321, 5321]","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:25:34.351898208Z","hostname":"w-01JPK2XYXNKNQHJ28D83W62KZ9","pid":1244,"":"downstairs","":"downstairs","session_id":"9b5ea180-40d0-458d-b9f6-f0b4fca0bc94"}
3902025-03-17T22:25:35.389Z{"msg":"[0]R generation: [31, 31, 31, 31, 31]","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:25:34.351914138Z","hostname":"w-01JPK2XYXNKNQHJ28D83W62KZ9","pid":1244,"":"downstairs","":"downstairs","session_id":"9b5ea180-40d0-458d-b9f6-f0b4fca0bc94"}
3912025-03-17T22:25:35.389Z{"msg":"[0]R dirty: [false, false, false, false, false]","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:25:34.351928538Z","hostname":"w-01JPK2XYXNKNQHJ28D83W62KZ9","pid":1244,"":"downstairs","":"downstairs","session_id":"9b5ea180-40d0-458d-b9f6-f0b4fca0bc94"}
3922025-03-17T22:25:35.389Z{"msg":"[1]R flush_numbers: [5321, 5321, 5321, 5321, 5321]","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:25:34.351941908Z","hostname":"w-01JPK2XYXNKNQHJ28D83W62KZ9","pid":1244,"":"downstairs","":"downstairs","session_id":"9b5ea180-40d0-458d-b9f6-f0b4fca0bc94"}
3932025-03-17T22:25:35.389Z{"msg":"[1]R generation: [31, 31, 31, 31, 31]","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:25:34.351968178Z","hostname":"w-01JPK2XYXNKNQHJ28D83W62KZ9","pid":1244,"":"downstairs","":"downstairs","session_id":"9b5ea180-40d0-458d-b9f6-f0b4fca0bc94"}
3942025-03-17T22:25:35.389Z{"msg":"[1]R dirty: [false, false, false, false, false]","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:25:34.351982838Z","hostname":"w-01JPK2XYXNKNQHJ28D83W62KZ9","pid":1244,"":"downstairs","":"downstairs","session_id":"9b5ea180-40d0-458d-b9f6-f0b4fca0bc94"}
3952025-03-17T22:25:35.389Z{"msg":"[2]R flush_numbers: [5321, 5321, 5321, 5321, 5321]","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:25:34.351996078Z","hostname":"w-01JPK2XYXNKNQHJ28D83W62KZ9","pid":1244,"":"downstairs","":"downstairs","session_id":"9b5ea180-40d0-458d-b9f6-f0b4fca0bc94"}
3962025-03-17T22:25:35.389Z{"msg":"[2]R generation: [31, 31, 31, 31, 31]","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:25:34.352008878Z","hostname":"w-01JPK2XYXNKNQHJ28D83W62KZ9","pid":1244,"":"downstairs","":"downstairs","session_id":"9b5ea180-40d0-458d-b9f6-f0b4fca0bc94"}
3972025-03-17T22:25:35.389Z{"msg":"[2]R dirty: [false, false, false, false, false]","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:25:34.352021678Z","hostname":"w-01JPK2XYXNKNQHJ28D83W62KZ9","pid":1244,"":"downstairs","":"downstairs","session_id":"9b5ea180-40d0-458d-b9f6-f0b4fca0bc94"}
3982025-03-17T22:25:35.389Z{"msg":"Max found gen is 32","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:25:34.352042449Z","hostname":"w-01JPK2XYXNKNQHJ28D83W62KZ9","pid":1244,"":"downstairs","":"downstairs","session_id":"9b5ea180-40d0-458d-b9f6-f0b4fca0bc94"}
3992025-03-17T22:25:35.389Z{Wait for a query_work_queue command to finish before sending IO
4002025-03-17T22:25:35.389Z"msg":"Generation requested: 32 >= found:32","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:25:34.352061329Z","hostname":"w-01JPK2XYXNKNQHJ28D83W62KZ9","pid":1244,"":"downstairs","":"downstairs","session_id":"9b5ea180-40d0-458d-b9f6-f0b4fca0bc94"}
4012025-03-17T22:25:35.389Z{"msg":"Next flush: 5322","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:25:34.352080779Z","hostname":"w-01JPK2XYXNKNQHJ28D83W62KZ9","pid":1244,"":"downstairs","":"downstairs","session_id":"9b5ea180-40d0-458d-b9f6-f0b4fca0bc94"}
4022025-03-17T22:25:35.389Z{"msg":"All extents match","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:25:34.352093519Z","hostname":"w-01JPK2XYXNKNQHJ28D83W62KZ9","pid":1244,"":"downstairs","":"downstairs","session_id":"9b5ea180-40d0-458d-b9f6-f0b4fca0bc94"}
4032025-03-17T22:25:35.389Z{"msg":"No downstairs reconciliation required","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:25:34.352113469Z","hostname":"w-01JPK2XYXNKNQHJ28D83W62KZ9","pid":1244,"session_id":"9b5ea180-40d0-458d-b9f6-f0b4fca0bc94"}
4042025-03-17T22:25:35.389Z{"msg":"Transition from WaitQuorum to Active","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:25:34.352125219Z","hostname":"w-01JPK2XYXNKNQHJ28D83W62KZ9","pid":1244,"client":"0","":"downstairs","session_id":"9b5ea180-40d0-458d-b9f6-f0b4fca0bc94"}
4052025-03-17T22:25:35.389Z{"msg":"Transition from WaitQuorum to Active","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:25:34.352138499Z","hostname":"w-01JPK2XYXNKNQHJ28D83W62KZ9","pid":1244,"client":"1","":"downstairs","session_id":"9b5ea180-40d0-458d-b9f6-f0b4fca0bc94"}
4062025-03-17T22:25:35.389Z{"msg":"Transition from WaitQuorum to Active","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:25:34.352157899Z","hostname":"w-01JPK2XYXNKNQHJ28D83W62KZ9","pid":1244,"client":"2","":"downstairs","session_id":"9b5ea180-40d0-458d-b9f6-f0b4fca0bc94"}
4072025-03-17T22:25:35.389Z{"msg":"All required reconciliation work is completed","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:25:34.352171079Z","hostname":"w-01JPK2XYXNKNQHJ28D83W62KZ9","pid":1244,"session_id":"9b5ea180-40d0-458d-b9f6-f0b4fca0bc94"}
4082025-03-17T22:25:35.389Z{"msg":"Set Downstairs and Upstairs active after reconciliation","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:25:34.352189419Z","hostname":"w-01JPK2XYXNKNQHJ28D83W62KZ9","pid":1244,"session_id":"9b5ea180-40d0-458d-b9f6-f0b4fca0bc94"}
4092025-03-17T22:25:35.389Z{"msg":"ae1a52fa-2b67-497c-969c-bb85ce98d076 is now active with session: 9b5ea180-40d0-458d-b9f6-f0b4fca0bc94","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:25:34.352202309Z","hostname":"w-01JPK2XYXNKNQHJ28D83W62KZ9","pid":1244,"session_id":"9b5ea180-40d0-458d-b9f6-f0b4fca0bc94"}
4102025-03-17T22:25:35.389Z{"msg":"Set Active after no reconciliation","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:25:34.352214079Z","hostname":"w-01JPK2XYXNKNQHJ28D83W62KZ9","pid":1244,"session_id":"9b5ea180-40d0-458d-b9f6-f0b4fca0bc94"}
4112025-03-17T22:25:35.389Z{"msg":"The guest has finished waiting for activation with:32","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:25:34.352232989Z","hostname":"w-01JPK2XYXNKNQHJ28D83W62KZ9","pid":1244}
4122025-03-17T22:25:35.389Z{"msg":"Activated sub_volume ae1a52fa-2b67-497c-969c-bb85ce98d076","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:25:34.352245099Z","hostname":"w-01JPK2XYXNKNQHJ28D83W62KZ9","pid":1244}
4132025-03-17T22:25:35.389ZDisk: sv:2 bs:4096 ts:409600 tb:100 max_io:100 or 409600
4142025-03-17T22:25:35.389ZLoading write count information from file "/var/tmp/test_up-build/verify_file"
4152025-03-17T22:25:35.389ZFill test
4162025-03-17T22:25:35.428ZRead and Verify all blocks (0..100 range:false)
4172025-03-17T22:25:35.512ZWrote out file "/var/tmp/test_up-build/verify_file"
4182025-03-17T22:25:35.512ZCLIENT: Tests done. All submitted work has been ACK'd
4192025-03-17T22:25:35.515Z----------------------------------------------------------------
4202025-03-17T22:25:35.515Z Crucible gen:32 GIO:true work queues: Upstairs:0 downstairs:1
4212025-03-17T22:25:35.515ZStates: Active Active Active
4222025-03-17T22:25:35.515ZJOBID ACK TYPE BKS/EXT DS:0 DS:1 DS:2 REPLAY
4232025-03-17T22:25:35.515Z 1002 Acked Read 50 Done Done Done false
4242025-03-17T22:25:35.515Z STATES DS:0 DS:1 DS:2 TOTAL
4252025-03-17T22:25:35.515Z Sent 0 0 0 0
4262025-03-17T22:25:35.515Z Done 1 1 1 3
4272025-03-17T22:25:35.515Z Skipped 0 0 0 0
4282025-03-17T22:25:35.515Z Error 0 0 0 0
4292025-03-17T22:25:35.515ZLast Flush: Some(JobId(1001)) Some(JobId(1001)) Some(JobId(1001))
4302025-03-17T22:25:35.515ZDownstairs last five completed: 1001 1000
4312025-03-17T22:25:35.515ZUpstairs last five completed: 1002 1001 1000
4322025-03-17T22:25:35.515Z----------------------------------------------------------------
4332025-03-17T22:25:35.515Z Crucible gen:32 GIO:true work queues: Upstairs:0 downstairs:1
4342025-03-17T22:25:35.515ZStates: Active Active Active
4352025-03-17T22:25:35.515ZJOBID ACK TYPE BKS/EXT DS:0 DS:1 DS:2 REPLAY
4362025-03-17T22:25:35.515Z 1002 Acked Read 50 Done Done Done false
4372025-03-17T22:25:35.515Z STATES DS:0 DS:1 DS:2 TOTAL
4382025-03-17T22:25:35.515Z Sent 0 0 0 0
4392025-03-17T22:25:35.515Z Done 1 1 1 3
4402025-03-17T22:25:35.515Z Skipped 0 0 0 0
4412025-03-17T22:25:35.515Z Error 0 0 0 0
4422025-03-17T22:25:35.515ZLast Flush: Some(JobId(1001)) Some(JobId(1001)) Some(JobId(1001))
4432025-03-17T22:25:35.515ZDownstairs last five completed: 1001 1000
4442025-03-17T22:25:35.515ZUpstairs last five completed: 1002 1001 1000
4452025-03-17T22:25:35.515ZCLIENT: Up:0 ds:2 act:6
4462025-03-17T22:25:39.513Z----------------------------------------------------------------
4472025-03-17T22:25:39.513Z Crucible gen:32 GIO:true work queues: Upstairs:0 downstairs:0
4482025-03-17T22:25:39.513ZDownstairs last five completed: 1003 1002 1001 1000
4492025-03-17T22:25:39.513ZUpstairs last five completed: 1003 1002 1001 1000
4502025-03-17T22:25:39.533Z----------------------------------------------------------------
4512025-03-17T22:25:39.534Z Crucible gen:32 GIO:true work queues: Upstairs:0 downstairs:0
4522025-03-17T22:25:39.534ZDownstairs last five completed: 1003 1002 1001 1000
4532025-03-17T22:25:39.534ZUpstairs last five completed: 1003 1002 1001 1000
4542025-03-17T22:25:39.534ZCLIENT: Up:0 ds:0 act:6
4552025-03-17T22:25:39.534ZCLIENT: All crucible jobs finished, exiting program
4562025-03-17T22:25:39.534Z{"msg":"Guest handle has been dropped","v":0,"name":"crucible","level":40,"time":"2025-03-17T22:25:38.481121499Z","hostname":"w-01JPK2XYXNKNQHJ28D83W62KZ9","pid":1244}
4572025-03-17T22:25:39.541ZRepair part 1 passed
4582025-03-17T22:25:39.541Z
4592025-03-17T22:25:39.541ZKill the current downstairs
4602025-03-17T22:25:39.689ZDownstairs 2 stopped
4612025-03-17T22:25:39.689Zmv /var/tmp/test_up-build/8830 /var/tmp/test_up-build/new
4622025-03-17T22:25:39.693ZNow put back the original so we have a mismatch
4632025-03-17T22:25:39.693Zmv /var/tmp/test_up-build/previous /var/tmp/test_up-build/8830
4642025-03-17T22:25:39.693ZRestart downstairs with old directory
4652025-03-17T22:25:39.747Z/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:25:39.764ZEXT BLOCKS GEN0 GEN1 GEN2 FL0 FL1 FL2 D0 D1 D2 DIFF
4672025-03-17T22:25:39.767Z 0 000-009 32 32 31 4000 4000 3999 F F F <---
4682025-03-17T22:25:39.768Z 1 010-019 32 32 31 4000 4000 3999 F F F <---
4692025-03-17T22:25:39.768Z 2 020-029 32 32 31 4000 4000 3999 F F F <---
4702025-03-17T22:25:39.768Z 3 030-039 32 32 31 4000 4000 3999 F F F <---
4712025-03-17T22:25:39.768Z 4 040-049 32 32 31 4000 4000 3999 F F F <---
4722025-03-17T22:25:39.769ZMax gen: 32, Max flush: 4000
4732025-03-17T22:25:39.770ZError: Difference in extent metadata found!
4742025-03-17T22:25:39.774Zdump test found error as expected
4752025-03-17T22:25:39.774Z
4762025-03-17T22:25:39.774Z
4772025-03-17T22:25:39.774Z/var/tmp/bins/crutest verify --range -g 33 -q --key dTo8OYwJ4nmwk+WBHlLjCGc4PhTEPwEIOae/e9F5cFU= --dsc 127.0.0.1:9998 --verify-out /var/tmp/test_up-build/verify_file --verify-in /var/tmp/test_up-build/verify_file
4782025-03-17T22:25:39.824Z{"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:25:38.791461659Z","hostname":"w-01JPK2XYXNKNQHJ28D83W62KZ9","pid":1252,"task":"crutest"}
4792025-03-17T22:25:39.829Z{"msg":"dsc has 6 regions. This means 2 sub_volumes","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:25:38.792064771Z","hostname":"w-01JPK2XYXNKNQHJ28D83W62KZ9","pid":1252,"task":"crutest"}
4802025-03-17T22:25:39.829Z{"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:25:38.793664335Z","hostname":"w-01JPK2XYXNKNQHJ28D83W62KZ9","pid":1252,"task":"crutest"}
4812025-03-17T22:25:39.830Z{"msg":"Upstairs starts","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:25:38.793851606Z","hostname":"w-01JPK2XYXNKNQHJ28D83W62KZ9","pid":1252}
4822025-03-17T22:25:39.830Z{"msg":"Crucible Version: BuildInfo {\n version: \"0.0.1\",\n git_sha: \"acc6b11fa639390710fd9a0449e05c901b048ed2\",\n git_commit_timestamp: \"2025-03-17T22:02:02.000000000Z\",\n git_branch: \"renovate/itertools-0.x\",\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:25:38.793896216Z","hostname":"w-01JPK2XYXNKNQHJ28D83W62KZ9","pid":1252}
4832025-03-17T22:25:39.830Z{"msg":"Upstairs <-> Downstairs Message Version: 13","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:25:38.793918466Z","hostname":"w-01JPK2XYXNKNQHJ28D83W62KZ9","pid":1252}
4842025-03-17T22:25:39.830Z{"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-03-17T22:25:38.793933226Z","hostname":"w-01JPK2XYXNKNQHJ28D83W62KZ9","pid":1252}
4852025-03-17T22:25:39.830Z{"msg":"Crucible b306975a-5257-44c1-8516-d485a9ef8108 has session id: 591265c7-40a9-44f9-abee-fc98cc297ace","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:25:38.794466718Z","hostname":"w-01JPK2XYXNKNQHJ28D83W62KZ9","pid":1252,"session_id":"591265c7-40a9-44f9-abee-fc98cc297ace"}
4862025-03-17T22:25:39.830Z{"msg":"Upstairs opts: Upstairs UUID: b306975a-5257-44c1-8516-d485a9ef8108, 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-03-17T22:25:38.794526728Z","hostname":"w-01JPK2XYXNKNQHJ28D83W62KZ9","pid":1252,"session_id":"591265c7-40a9-44f9-abee-fc98cc297ace"}
4872025-03-17T22:25:39.830Z{"msg":"Crucible stats registered with UUID: b306975a-5257-44c1-8516-d485a9ef8108","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:25:38.794553438Z","hostname":"w-01JPK2XYXNKNQHJ28D83W62KZ9","pid":1252,"session_id":"591265c7-40a9-44f9-abee-fc98cc297ace"}
4882025-03-17T22:25:39.830Z{"msg":"could not find Downstairs address for Nexus","v":0,"name":"crucible","level":40,"time":"2025-03-17T22:25:38.794575078Z","hostname":"w-01JPK2XYXNKNQHJ28D83W62KZ9","pid":1252,"session_id":"591265c7-40a9-44f9-abee-fc98cc297ace"}
4892025-03-17T22:25:39.830Z{"msg":"SV 1 has targets: [127.0.0.1:8840, 127.0.0.1:8850, 127.0.0.1:8860]","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:25:38.796517524Z","hostname":"w-01JPK2XYXNKNQHJ28D83W62KZ9","pid":1252,"task":"crutest"}
4902025-03-17T22:25:39.830Z{"msg":"Upstairs starts","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:25:38.796600484Z","hostname":"w-01JPK2XYXNKNQHJ28D83W62KZ9","pid":1252}
4912025-03-17T22:25:39.830Z{"msg":"Crucible Version: BuildInfo {\n version: \"0.0.1\",\n git_sha: \"acc6b11fa639390710fd9a0449e05c901b048ed2\",\n git_commit_timestamp: \"2025-03-17T22:02:02.000000000Z\",\n git_branch: \"renovate/itertools-0.x\",\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:25:38.796636284Z","hostname":"w-01JPK2XYXNKNQHJ28D83W62KZ9","pid":1252}
4922025-03-17T22:25:39.830Z{"msg":"Upstairs <-> Downstairs Message Version: 13","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:25:38.796656604Z","hostname":"w-01JPK2XYXNKNQHJ28D83W62KZ9","pid":1252}
4932025-03-17T22:25:39.830Z{"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-03-17T22:25:38.796670734Z","hostname":"w-01JPK2XYXNKNQHJ28D83W62KZ9","pid":1252}
4942025-03-17T22:25:39.835Z{"msg":"Crucible b306975a-5257-44c1-8516-d485a9ef8108 has session id: 8741b011-951e-4ca3-8aa2-f34cefb23951","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:25:38.797075606Z","hostname":"w-01JPK2XYXNKNQHJ28D83W62KZ9","pid":1252,"session_id":"8741b011-951e-4ca3-8aa2-f34cefb23951"}
4952025-03-17T22:25:39.835Z{"msg":"Upstairs opts: Upstairs UUID: b306975a-5257-44c1-8516-d485a9ef8108, Targets: [127.0.0.1:8840, 127.0.0.1:8850, 127.0.0.1:8860], 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-03-17T22:25:38.797125886Z","hostname":"w-01JPK2XYXNKNQHJ28D83W62KZ9","pid":1252,"session_id":"8741b011-951e-4ca3-8aa2-f34cefb23951"}
4962025-03-17T22:25:39.835Z{"msg":"Crucible stats registered with UUID: b306975a-5257-44c1-8516-d485a9ef8108","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:25:38.797169746Z","hostname":"w-01JPK2XYXNKNQHJ28D83W62KZ9","pid":1252,"session_id":"8741b011-951e-4ca3-8aa2-f34cefb23951"}
4972025-03-17T22:25:39.836Z{"msg":"could not find Downstairs address for Nexus","v":0,"name":"crucible","level":40,"time":"2025-03-17T22:25:38.797199866Z","hostname":"w-01JPK2XYXNKNQHJ28D83W62KZ9","pid":1252,"session_id":"8741b011-951e-4ca3-8aa2-f34cefb23951"}
4982025-03-17T22:25:39.836Z{"msg":"Downstairs in volume = 6","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:25:38.797780868Z","hostname":"w-01JPK2XYXNKNQHJ28D83W62KZ9","pid":1252,"task":"crutest"}
4992025-03-17T22:25:39.836Z{"msg":"The guest has requested activation with gen:33","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:25:38.797823348Z","hostname":"w-01JPK2XYXNKNQHJ28D83W62KZ9","pid":1252}
5002025-03-17T22:25:39.836Z{"msg":"b306975a-5257-44c1-8516-d485a9ef8108 active request set","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:25:38.797851108Z","hostname":"w-01JPK2XYXNKNQHJ28D83W62KZ9","pid":1252,"session_id":"591265c7-40a9-44f9-abee-fc98cc297ace"}
5012025-03-17T22:25:39.836Z{"msg":"sending connect oneshot to client","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:25:38.797868608Z","hostname":"w-01JPK2XYXNKNQHJ28D83W62KZ9","pid":1252,"client":"0","":"downstairs","session_id":"591265c7-40a9-44f9-abee-fc98cc297ace"}
5022025-03-17T22:25:39.836Z{"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:25:38.797897458Z","hostname":"w-01JPK2XYXNKNQHJ28D83W62KZ9","pid":1252,"client":"0","":"downstairs","session_id":"591265c7-40a9-44f9-abee-fc98cc297ace"}
5032025-03-17T22:25:39.836Z{"msg":"sending connect oneshot to client","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:25:38.797925348Z","hostname":"w-01JPK2XYXNKNQHJ28D83W62KZ9","pid":1252,"client":"1","":"downstairs","session_id":"591265c7-40a9-44f9-abee-fc98cc297ace"}
5042025-03-17T22:25:39.836Z{"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:25:38.797950168Z","hostname":"w-01JPK2XYXNKNQHJ28D83W62KZ9","pid":1252,"client":"1","":"downstairs","session_id":"591265c7-40a9-44f9-abee-fc98cc297ace"}
5052025-03-17T22:25:39.836Z{"msg":"sending connect oneshot to client","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:25:38.798046578Z","hostname":"w-01JPK2XYXNKNQHJ28D83W62KZ9","pid":1252,"client":"2","":"downstairs","session_id":"591265c7-40a9-44f9-abee-fc98cc297ace"}
5062025-03-17T22:25:39.836Z{"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:25:38.798091729Z","hostname":"w-01JPK2XYXNKNQHJ28D83W62KZ9","pid":1252,"client":"2","":"downstairs","session_id":"591265c7-40a9-44f9-abee-fc98cc297ace"}
5072025-03-17T22:25:39.836Z{"msg":"connecting to 127.0.0.1:8810","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:25:38.798143239Z","hostname":"w-01JPK2XYXNKNQHJ28D83W62KZ9","pid":1252,"":"io task","client":"0","":"downstairs","session_id":"591265c7-40a9-44f9-abee-fc98cc297ace"}
5082025-03-17T22:25:39.836Z{"msg":"connecting to 127.0.0.1:8830","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:25:38.798186049Z","hostname":"w-01JPK2XYXNKNQHJ28D83W62KZ9","pid":1252,"":"io task","client":"2","":"downstairs","session_id":"591265c7-40a9-44f9-abee-fc98cc297ace"}
5092025-03-17T22:25:39.836Z{"msg":"connecting to 127.0.0.1:8820","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:25:38.798248249Z","hostname":"w-01JPK2XYXNKNQHJ28D83W62KZ9","pid":1252,"":"io task","client":"1","":"downstairs","session_id":"591265c7-40a9-44f9-abee-fc98cc297ace"}
5102025-03-17T22:25:39.837Z{"msg":"ds_connection connected from Ok(127.0.0.1:33607)","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:25:38.798359479Z","hostname":"w-01JPK2XYXNKNQHJ28D83W62KZ9","pid":1252,"":"io task","client":"0","":"downstairs","session_id":"591265c7-40a9-44f9-abee-fc98cc297ace"}
5112025-03-17T22:25:39.837Z{"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:25:38.798416199Z","hostname":"w-01JPK2XYXNKNQHJ28D83W62KZ9","pid":1252,"":"io task","client":"2","":"downstairs","session_id":"591265c7-40a9-44f9-abee-fc98cc297ace"}
5122025-03-17T22:25:39.837Z{"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:25:38.79844756Z","hostname":"w-01JPK2XYXNKNQHJ28D83W62KZ9","pid":1252,"":"io task","client":"2","":"downstairs","session_id":"591265c7-40a9-44f9-abee-fc98cc297ace"}
5132025-03-17T22:25:39.837Z{"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:25:38.79849284Z","hostname":"w-01JPK2XYXNKNQHJ28D83W62KZ9","pid":1252,"session_id":"591265c7-40a9-44f9-abee-fc98cc297ace"}
5142025-03-17T22:25:39.837Z{"msg":"ds_connection connected from Ok(127.0.0.1:39370)","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:25:38.7985206Z","hostname":"w-01JPK2XYXNKNQHJ28D83W62KZ9","pid":1252,"":"io task","client":"1","":"downstairs","session_id":"591265c7-40a9-44f9-abee-fc98cc297ace"}
5152025-03-17T22:25:39.837Z{"msg":"client task is exiting","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:25:38.7985559Z","hostname":"w-01JPK2XYXNKNQHJ28D83W62KZ9","pid":1252,"":"io task","client":"2","":"downstairs","session_id":"591265c7-40a9-44f9-abee-fc98cc297ace"}
5162025-03-17T22:25:39.837Z{"msg":"version negotiation from state Connecting { state: WaitForPromote, mode: New }","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:25:38.7987385Z","hostname":"w-01JPK2XYXNKNQHJ28D83W62KZ9","pid":1252,"client":"0","":"downstairs","session_id":"591265c7-40a9-44f9-abee-fc98cc297ace"}
5172025-03-17T22:25:39.837Z{"msg":"version negotiation from state Connecting { state: WaitForPromote, mode: New }","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:25:38.798768751Z","hostname":"w-01JPK2XYXNKNQHJ28D83W62KZ9","pid":1252,"client":"1","":"downstairs","session_id":"591265c7-40a9-44f9-abee-fc98cc297ace"}
5182025-03-17T22:25:39.837Z{"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:25:38.799366182Z","hostname":"w-01JPK2XYXNKNQHJ28D83W62KZ9","pid":1252,"client":"0","":"downstairs","session_id":"591265c7-40a9-44f9-abee-fc98cc297ace"}
5192025-03-17T22:25:39.837Z{"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:25:38.799403962Z","hostname":"w-01JPK2XYXNKNQHJ28D83W62KZ9","pid":1252,"client":"1","":"downstairs","session_id":"591265c7-40a9-44f9-abee-fc98cc297ace"}
5202025-03-17T22:25:39.837Z{"msg":"Waiting for more clients to be ready","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:25:38.799794204Z","hostname":"w-01JPK2XYXNKNQHJ28D83W62KZ9","pid":1252,"session_id":"591265c7-40a9-44f9-abee-fc98cc297ace"}
5212025-03-17T22:25:39.837Z{"msg":"Waiting for more clients to be ready","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:25:38.799840594Z","hostname":"w-01JPK2XYXNKNQHJ28D83W62KZ9","pid":1252,"session_id":"591265c7-40a9-44f9-abee-fc98cc297ace"}
5222025-03-17T22:25:49.834Z{"msg":"connecting to 127.0.0.1:8830","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:25:48.799796064Z","hostname":"w-01JPK2XYXNKNQHJ28D83W62KZ9","pid":1252,"":"io task","client":"2","":"downstairs","session_id":"591265c7-40a9-44f9-abee-fc98cc297ace"}
5232025-03-17T22:25:49.834Z{"msg":"ds_connection connected from Ok(127.0.0.1:35601)","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:25:48.799918194Z","hostname":"w-01JPK2XYXNKNQHJ28D83W62KZ9","pid":1252,"":"io task","client":"2","":"downstairs","session_id":"591265c7-40a9-44f9-abee-fc98cc297ace"}
5242025-03-17T22:25:49.844Z{"msg":"version negotiation from state Connecting { state: WaitForPromote, mode: New }","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:25:48.801231338Z","hostname":"w-01JPK2XYXNKNQHJ28D83W62KZ9","pid":1252,"client":"2","":"downstairs","session_id":"591265c7-40a9-44f9-abee-fc98cc297ace"}
5252025-03-17T22:25:49.844Z{"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:25:48.801770869Z","hostname":"w-01JPK2XYXNKNQHJ28D83W62KZ9","pid":1252,"client":"2","":"downstairs","session_id":"591265c7-40a9-44f9-abee-fc98cc297ace"}
5262025-03-17T22:25:49.844Z{"msg":"[0]R flush_numbers: [4000, 4000, 4000, 4000, 4000]","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:25:48.802160631Z","hostname":"w-01JPK2XYXNKNQHJ28D83W62KZ9","pid":1252,"":"downstairs","":"downstairs","session_id":"591265c7-40a9-44f9-abee-fc98cc297ace"}
5272025-03-17T22:25:49.844Z{"msg":"[0]R generation: [32, 32, 32, 32, 32]","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:25:48.802194531Z","hostname":"w-01JPK2XYXNKNQHJ28D83W62KZ9","pid":1252,"":"downstairs","":"downstairs","session_id":"591265c7-40a9-44f9-abee-fc98cc297ace"}
5282025-03-17T22:25:49.844Z{"msg":"[0]R dirty: [false, false, false, false, false]","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:25:48.802212771Z","hostname":"w-01JPK2XYXNKNQHJ28D83W62KZ9","pid":1252,"":"downstairs","":"downstairs","session_id":"591265c7-40a9-44f9-abee-fc98cc297ace"}
5292025-03-17T22:25:49.844Z{"msg":"[1]R flush_numbers: [4000, 4000, 4000, 4000, 4000]","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:25:48.802238631Z","hostname":"w-01JPK2XYXNKNQHJ28D83W62KZ9","pid":1252,"":"downstairs","":"downstairs","session_id":"591265c7-40a9-44f9-abee-fc98cc297ace"}
5302025-03-17T22:25:49.844Z{"msg":"[1]R generation: [32, 32, 32, 32, 32]","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:25:48.802254091Z","hostname":"w-01JPK2XYXNKNQHJ28D83W62KZ9","pid":1252,"":"downstairs","":"downstairs","session_id":"591265c7-40a9-44f9-abee-fc98cc297ace"}
5312025-03-17T22:25:49.845Z{"msg":"[1]R dirty: [false, false, false, false, false]","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:25:48.802280141Z","hostname":"w-01JPK2XYXNKNQHJ28D83W62KZ9","pid":1252,"":"downstairs","":"downstairs","session_id":"591265c7-40a9-44f9-abee-fc98cc297ace"}
5322025-03-17T22:25:49.845Z{"msg":"[2]R flush_numbers: [3999, 3999, 3999, 3999, 3999]","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:25:48.802294361Z","hostname":"w-01JPK2XYXNKNQHJ28D83W62KZ9","pid":1252,"":"downstairs","":"downstairs","session_id":"591265c7-40a9-44f9-abee-fc98cc297ace"}
5332025-03-17T22:25:49.845Z{"msg":"[2]R generation: [31, 31, 31, 31, 31]","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:25:48.802308001Z","hostname":"w-01JPK2XYXNKNQHJ28D83W62KZ9","pid":1252,"":"downstairs","":"downstairs","session_id":"591265c7-40a9-44f9-abee-fc98cc297ace"}
5342025-03-17T22:25:49.845Z{"msg":"[2]R dirty: [false, false, false, false, false]","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:25:48.802334001Z","hostname":"w-01JPK2XYXNKNQHJ28D83W62KZ9","pid":1252,"":"downstairs","":"downstairs","session_id":"591265c7-40a9-44f9-abee-fc98cc297ace"}
5352025-03-17T22:25:49.845Z{"msg":"Max found gen is 33","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:25:48.802348291Z","hostname":"w-01JPK2XYXNKNQHJ28D83W62KZ9","pid":1252,"":"downstairs","":"downstairs","session_id":"591265c7-40a9-44f9-abee-fc98cc297ace"}
5362025-03-17T22:25:49.845Z{"msg":"Generation requested: 33 >= found:33","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:25:48.802373801Z","hostname":"w-01JPK2XYXNKNQHJ28D83W62KZ9","pid":1252,"":"downstairs","":"downstairs","session_id":"591265c7-40a9-44f9-abee-fc98cc297ace"}
5372025-03-17T22:25:49.845Z{"msg":"Next flush: 4001","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:25:48.802389271Z","hostname":"w-01JPK2XYXNKNQHJ28D83W62KZ9","pid":1252,"":"downstairs","":"downstairs","session_id":"591265c7-40a9-44f9-abee-fc98cc297ace"}
5382025-03-17T22:25:49.845Z{"msg":"extent 0 needs reconciliation: ExtentMetadata { gen: 32, flush: 4000, dirty: false } ExtentMetadata { gen: 32, flush: 4000, dirty: false } ExtentMetadata { gen: 31, flush: 3999, dirty: false }","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:25:48.802415911Z","hostname":"w-01JPK2XYXNKNQHJ28D83W62KZ9","pid":1252,"":"mend","":"downstairs","":"downstairs","session_id":"591265c7-40a9-44f9-abee-fc98cc297ace"}
5392025-03-17T22:25:49.845Z{"msg":"extent:0 [ExtentMetadata { gen: 32, flush: 4000, dirty: false }, ExtentMetadata { gen: 32, flush: 4000, dirty: false }, ExtentMetadata { gen: 31, flush: 3999, dirty: false }] => 0","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:25:48.802437982Z","hostname":"w-01JPK2XYXNKNQHJ28D83W62KZ9","pid":1252,"":"mend","":"downstairs","":"downstairs","session_id":"591265c7-40a9-44f9-abee-fc98cc297ace"}
5402025-03-17T22:25:49.845Z{"msg":"found dest for source 0 for extent at index 0 => [ClientId(2)]","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:25:48.802460822Z","hostname":"w-01JPK2XYXNKNQHJ28D83W62KZ9","pid":1252,"":"mend","":"downstairs","":"downstairs","session_id":"591265c7-40a9-44f9-abee-fc98cc297ace"}
5412025-03-17T22:25:49.846Z{"msg":"extent 1 needs reconciliation: ExtentMetadata { gen: 32, flush: 4000, dirty: false } ExtentMetadata { gen: 32, flush: 4000, dirty: false } ExtentMetadata { gen: 31, flush: 3999, dirty: false }","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:25:48.802479492Z","hostname":"w-01JPK2XYXNKNQHJ28D83W62KZ9","pid":1252,"":"mend","":"downstairs","":"downstairs","session_id":"591265c7-40a9-44f9-abee-fc98cc297ace"}
5422025-03-17T22:25:49.846Z{"msg":"extent:0 [ExtentMetadata { gen: 32, flush: 4000, dirty: false }, ExtentMetadata { gen: 32, flush: 4000, dirty: false }, ExtentMetadata { gen: 31, flush: 3999, dirty: false }] => 0","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:25:48.802504842Z","hostname":"w-01JPK2XYXNKNQHJ28D83W62KZ9","pid":1252,"":"mend","":"downstairs","":"downstairs","session_id":"591265c7-40a9-44f9-abee-fc98cc297ace"}
5432025-03-17T22:25:49.846Z{"msg":"found dest for source 0 for extent at index 1 => [ClientId(2)]","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:25:48.802522492Z","hostname":"w-01JPK2XYXNKNQHJ28D83W62KZ9","pid":1252,"":"mend","":"downstairs","":"downstairs","session_id":"591265c7-40a9-44f9-abee-fc98cc297ace"}
5442025-03-17T22:25:49.846Z{"msg":"extent 2 needs reconciliation: ExtentMetadata { gen: 32, flush: 4000, dirty: false } ExtentMetadata { gen: 32, flush: 4000, dirty: false } ExtentMetadata { gen: 31, flush: 3999, dirty: false }","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:25:48.802547462Z","hostname":"w-01JPK2XYXNKNQHJ28D83W62KZ9","pid":1252,"":"mend","":"downstairs","":"downstairs","session_id":"591265c7-40a9-44f9-abee-fc98cc297ace"}
5452025-03-17T22:25:49.846Z{"msg":"extent:0 [ExtentMetadata { gen: 32, flush: 4000, dirty: false }, ExtentMetadata { gen: 32, flush: 4000, dirty: false }, ExtentMetadata { gen: 31, flush: 3999, dirty: false }] => 0","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:25:48.802567622Z","hostname":"w-01JPK2XYXNKNQHJ28D83W62KZ9","pid":1252,"":"mend","":"downstairs","":"downstairs","session_id":"591265c7-40a9-44f9-abee-fc98cc297ace"}
5462025-03-17T22:25:49.846Z{"msg":"found dest for source 0 for extent at index 2 => [ClientId(2)]","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:25:48.802593592Z","hostname":"w-01JPK2XYXNKNQHJ28D83W62KZ9","pid":1252,"":"mend","":"downstairs","":"downstairs","session_id":"591265c7-40a9-44f9-abee-fc98cc297ace"}
5472025-03-17T22:25:49.846Z{"msg":"extent 3 needs reconciliation: ExtentMetadata { gen: 32, flush: 4000, dirty: false } ExtentMetadata { gen: 32, flush: 4000, dirty: false } ExtentMetadata { gen: 31, flush: 3999, dirty: false }","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:25:48.802629512Z","hostname":"w-01JPK2XYXNKNQHJ28D83W62KZ9","pid":1252,"":"mend","":"downstairs","":"downstairs","session_id":"591265c7-40a9-44f9-abee-fc98cc297ace"}
5482025-03-17T22:25:49.847Z{"msg":"extent:0 [ExtentMetadata { gen: 32, flush: 4000, dirty: false }, ExtentMetadata { gen: 32, flush: 4000, dirty: false }, ExtentMetadata { gen: 31, flush: 3999, dirty: false }] => 0","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:25:48.802654462Z","hostname":"w-01JPK2XYXNKNQHJ28D83W62KZ9","pid":1252,"":"mend","":"downstairs","":"downstairs","session_id":"591265c7-40a9-44f9-abee-fc98cc297ace"}
5492025-03-17T22:25:49.847Z{"msg":"found dest for source 0 for extent at index 3 => [ClientId(2)]","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:25:48.802682952Z","hostname":"w-01JPK2XYXNKNQHJ28D83W62KZ9","pid":1252,"":"mend","":"downstairs","":"downstairs","session_id":"591265c7-40a9-44f9-abee-fc98cc297ace"}
5502025-03-17T22:25:49.847Z{"msg":"extent 4 needs reconciliation: ExtentMetadata { gen: 32, flush: 4000, dirty: false } ExtentMetadata { gen: 32, flush: 4000, dirty: false } ExtentMetadata { gen: 31, flush: 3999, dirty: false }","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:25:48.802701472Z","hostname":"w-01JPK2XYXNKNQHJ28D83W62KZ9","pid":1252,"":"mend","":"downstairs","":"downstairs","session_id":"591265c7-40a9-44f9-abee-fc98cc297ace"}
5512025-03-17T22:25:49.847Z{"msg":"extent:0 [ExtentMetadata { gen: 32, flush: 4000, dirty: false }, ExtentMetadata { gen: 32, flush: 4000, dirty: false }, ExtentMetadata { gen: 31, flush: 3999, dirty: false }] => 0","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:25:48.802733052Z","hostname":"w-01JPK2XYXNKNQHJ28D83W62KZ9","pid":1252,"":"mend","":"downstairs","":"downstairs","session_id":"591265c7-40a9-44f9-abee-fc98cc297ace"}
5522025-03-17T22:25:49.847Z{"msg":"found dest for source 0 for extent at index 4 => [ClientId(2)]","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:25:48.802748252Z","hostname":"w-01JPK2XYXNKNQHJ28D83W62KZ9","pid":1252,"":"mend","":"downstairs","":"downstairs","session_id":"591265c7-40a9-44f9-abee-fc98cc297ace"}
5532025-03-17T22:25:49.847Z{"msg":"Transition from Connecting { state: WaitQuorum, mode: New } to Reconcile","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:25:48.802781723Z","hostname":"w-01JPK2XYXNKNQHJ28D83W62KZ9","pid":1252,"client":"0","":"downstairs","session_id":"591265c7-40a9-44f9-abee-fc98cc297ace"}
5542025-03-17T22:25:49.847Z{"msg":"Transition from Connecting { state: WaitQuorum, mode: New } to Reconcile","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:25:48.802817053Z","hostname":"w-01JPK2XYXNKNQHJ28D83W62KZ9","pid":1252,"client":"1","":"downstairs","session_id":"591265c7-40a9-44f9-abee-fc98cc297ace"}
5552025-03-17T22:25:49.847Z{"msg":"Transition from Connecting { state: WaitQuorum, mode: New } to Reconcile","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:25:48.802839553Z","hostname":"w-01JPK2XYXNKNQHJ28D83W62KZ9","pid":1252,"client":"2","":"downstairs","session_id":"591265c7-40a9-44f9-abee-fc98cc297ace"}
5562025-03-17T22:25:49.847Z{"msg":"Full repair list: {ExtentId(3): ExtentFix { source: ClientId(0), dest: [ClientId(2)] }, ExtentId(1): ExtentFix { source: ClientId(0), dest: [ClientId(2)] }, ExtentId(0): ExtentFix { source: ClientId(0), dest: [ClientId(2)] }, ExtentId(2): 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:25:48.802869363Z","hostname":"w-01JPK2XYXNKNQHJ28D83W62KZ9","pid":1252,"":"downstairs","":"downstairs","session_id":"591265c7-40a9-44f9-abee-fc98cc297ace"}
5572025-03-17T22:25:49.848Z{"msg":"Task list: [ReconcileIO { id: ReconciliationId(0), op: ExtentFlush { repair_id: ReconciliationId(0), extent_id: ExtentId(3), client_id: ClientId(0), flush_number: 4001, gen_number: 33 }, state: ClientData([New, New, New]) }, ReconcileIO { id: ReconciliationId(1), op: ExtentClose { repair_id: ReconciliationId(1), extent_id: ExtentId(3) }, state: ClientData([New, New, New]) }, ReconcileIO { id: ReconciliationId(2), op: ExtentRepair { repair_id: ReconciliationId(2), 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(3), op: ExtentReopen { repair_id: ReconciliationId(3), extent_id: ExtentId(3) }, 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: 4001, 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(0), client_id: ClientId(0), flush_number: 4001, gen_number: 33 }, state: ClientData([New, New, New]) }, ReconcileIO { id: ReconciliationId(9), op: ExtentClose { repair_id: ReconciliationId(9), extent_id: ExtentId(0) }, state: ClientData([New, New, New]) }, ReconcileIO { id: ReconciliationId(10), op: ExtentRepair { repair_id: ReconciliationId(10), 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(11), op: ExtentReopen { repair_id: ReconciliationId(11), extent_id: ExtentId(0) }, state: ClientData([New, New, New]) }, ReconcileIO { id: ReconciliationId(12), op: ExtentFlush { repair_id: ReconciliationId(12), extent_id: ExtentId(2), client_id: ClientId(0), flush_number: 4001, gen_number: 33 }, state: ClientData([New, New, New]) }, ReconcileIO { id: ReconciliationId(13), op: ExtentClose { repair_id: ReconciliationId(13), extent_id: ExtentId(2) }, state: ClientData([New, New, New]) }, ReconcileIO { id: ReconciliationId(14), op: ExtentRepair { repair_id: ReconciliationId(14), extent_id: ExtentId(2), source_client_id: ClientId(0), source_repair_address: 0.0.0.0:12810, dest_clients: [ClientId(2)] }, state: ClientData([New, New, New]) }, ReconcileIO { id: ReconciliationId(15), op: ExtentReopen { repair_id: ReconciliationId(15), extent_id: ExtentId(2) }, state: ClientData([New, New, New]) }, ReconcileIO { id: ReconciliationId(16), op: ExtentFlush { repair_id: ReconciliationId(16), extent_id: ExtentId(4), client_id: ClientId(0), flush_number: 4001, 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:25:48.802980133Z","hostname":"w-01JPK2XYXNKNQHJ28D83W62KZ9","pid":1252,"":"downstairs","":"downstairs","session_id":"591265c7-40a9-44f9-abee-fc98cc297ace"}
5582025-03-17T22:25:49.848Z{"msg":"starting reconciliation 22eaae73-88ee-4038-87f3-2acb7aa3a26b: found 20 extents that need repair","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:25:48.803009633Z","hostname":"w-01JPK2XYXNKNQHJ28D83W62KZ9","pid":1252,"":"downstairs","":"downstairs","session_id":"591265c7-40a9-44f9-abee-fc98cc297ace"}
5592025-03-17T22:25:49.848Z{"msg":"sending reconcile request ReconciliationId(2)","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:25:48.803095173Z","hostname":"w-01JPK2XYXNKNQHJ28D83W62KZ9","pid":1252,"client":"2","":"downstairs","session_id":"591265c7-40a9-44f9-abee-fc98cc297ace"}
5602025-03-17T22:25:49.853Z{"msg":"sending reconcile request ReconciliationId(6)","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:25:48.811696909Z","hostname":"w-01JPK2XYXNKNQHJ28D83W62KZ9","pid":1252,"client":"2","":"downstairs","session_id":"591265c7-40a9-44f9-abee-fc98cc297ace"}
5612025-03-17T22:25:49.853Z{"msg":"sending reconcile request ReconciliationId(10)","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:25:48.81535828Z","hostname":"w-01JPK2XYXNKNQHJ28D83W62KZ9","pid":1252,"client":"2","":"downstairs","session_id":"591265c7-40a9-44f9-abee-fc98cc297ace"}
5622025-03-17T22:25:49.854Z{"msg":"sending reconcile request ReconciliationId(14)","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:25:48.819001111Z","hostname":"w-01JPK2XYXNKNQHJ28D83W62KZ9","pid":1252,"client":"2","":"downstairs","session_id":"591265c7-40a9-44f9-abee-fc98cc297ace"}
5632025-03-17T22:25:49.869Z{"msg":"sending reconcile request ReconciliationId(18)","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:25:48.822629522Z","hostname":"w-01JPK2XYXNKNQHJ28D83W62KZ9","pid":1252,"client":"2","":"downstairs","session_id":"591265c7-40a9-44f9-abee-fc98cc297ace"}
5642025-03-17T22:25:49.869Z{"msg":"done with reconciliation","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:25:48.825657851Z","hostname":"w-01JPK2XYXNKNQHJ28D83W62KZ9","pid":1252,"":"downstairs","":"downstairs","session_id":"591265c7-40a9-44f9-abee-fc98cc297ace"}
5652025-03-17T22:25:49.869Z{"msg":"Transition from Reconcile to Active","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:25:48.825695171Z","hostname":"w-01JPK2XYXNKNQHJ28D83W62KZ9","pid":1252,"client":"0","":"downstairs","session_id":"591265c7-40a9-44f9-abee-fc98cc297ace"}
5662025-03-17T22:25:49.869Z{"msg":"Transition from Reconcile to Active","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:25:48.825711671Z","hostname":"w-01JPK2XYXNKNQHJ28D83W62KZ9","pid":1252,"client":"1","":"downstairs","session_id":"591265c7-40a9-44f9-abee-fc98cc297ace"}
5672025-03-17T22:25:49.869Z{"msg":"Transition from Reconcile to Active","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:25:48.825726531Z","hostname":"w-01JPK2XYXNKNQHJ28D83W62KZ9","pid":1252,"client":"2","":"downstairs","session_id":"591265c7-40a9-44f9-abee-fc98cc297ace"}
5682025-03-17T22:25:49.869Z{"msg":"All required reconciliation work is completed","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:25:48.825739861Z","hostname":"w-01JPK2XYXNKNQHJ28D83W62KZ9","pid":1252,"session_id":"591265c7-40a9-44f9-abee-fc98cc297ace"}
5692025-03-17T22:25:49.869Z{"msg":"Set Downstairs and Upstairs active after reconciliation","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:25:48.825759281Z","hostname":"w-01JPK2XYXNKNQHJ28D83W62KZ9","pid":1252,"session_id":"591265c7-40a9-44f9-abee-fc98cc297ace"}
5702025-03-17T22:25:49.869Z{"msg":"b306975a-5257-44c1-8516-d485a9ef8108 is now active with session: 591265c7-40a9-44f9-abee-fc98cc297ace","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:25:48.825773241Z","hostname":"w-01JPK2XYXNKNQHJ28D83W62KZ9","pid":1252,"session_id":"591265c7-40a9-44f9-abee-fc98cc297ace"}
5712025-03-17T22:25:49.870Z{"msg":"The guest has finished waiting for activation with:33","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:25:48.825792552Z","hostname":"w-01JPK2XYXNKNQHJ28D83W62KZ9","pid":1252}
5722025-03-17T22:25:49.870Z{"msg":"Activated sub_volume b306975a-5257-44c1-8516-d485a9ef8108","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:25:48.825804282Z","hostname":"w-01JPK2XYXNKNQHJ28D83W62KZ9","pid":1252}
5732025-03-17T22:25:49.870Z{"msg":"The guest has requested activation with gen:33","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:25:48.825856072Z","hostname":"w-01JPK2XYXNKNQHJ28D83W62KZ9","pid":1252}
5742025-03-17T22:25:49.870Z{"msg":"b306975a-5257-44c1-8516-d485a9ef8108 active request set","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:25:48.825879802Z","hostname":"w-01JPK2XYXNKNQHJ28D83W62KZ9","pid":1252,"session_id":"8741b011-951e-4ca3-8aa2-f34cefb23951"}
5752025-03-17T22:25:49.870Z{"msg":"sending connect oneshot to client","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:25:48.825892472Z","hostname":"w-01JPK2XYXNKNQHJ28D83W62KZ9","pid":1252,"client":"0","":"downstairs","session_id":"8741b011-951e-4ca3-8aa2-f34cefb23951"}
5762025-03-17T22:25:49.870Z{"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:25:48.825907782Z","hostname":"w-01JPK2XYXNKNQHJ28D83W62KZ9","pid":1252,"client":"0","":"downstairs","session_id":"8741b011-951e-4ca3-8aa2-f34cefb23951"}
5772025-03-17T22:25:49.870Z{"msg":"sending connect oneshot to client","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:25:48.825921592Z","hostname":"w-01JPK2XYXNKNQHJ28D83W62KZ9","pid":1252,"client":"1","":"downstairs","session_id":"8741b011-951e-4ca3-8aa2-f34cefb23951"}
5782025-03-17T22:25:49.870Z{"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:25:48.825936272Z","hostname":"w-01JPK2XYXNKNQHJ28D83W62KZ9","pid":1252,"client":"1","":"downstairs","session_id":"8741b011-951e-4ca3-8aa2-f34cefb23951"}
5792025-03-17T22:25:49.870Z{"msg":"sending connect oneshot to client","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:25:48.825949512Z","hostname":"w-01JPK2XYXNKNQHJ28D83W62KZ9","pid":1252,"client":"2","":"downstairs","session_id":"8741b011-951e-4ca3-8aa2-f34cefb23951"}
5802025-03-17T22:25:49.870Z{"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:25:48.825963182Z","hostname":"w-01JPK2XYXNKNQHJ28D83W62KZ9","pid":1252,"client":"2","":"downstairs","session_id":"8741b011-951e-4ca3-8aa2-f34cefb23951"}
5812025-03-17T22:25:49.871Z{"msg":"connecting to 127.0.0.1:8860","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:25:48.825983452Z","hostname":"w-01JPK2XYXNKNQHJ28D83W62KZ9","pid":1252,"":"io task","client":"2","":"downstairs","session_id":"8741b011-951e-4ca3-8aa2-f34cefb23951"}
5822025-03-17T22:25:49.871Z{"msg":"connecting to 127.0.0.1:8840","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:25:48.826017672Z","hostname":"w-01JPK2XYXNKNQHJ28D83W62KZ9","pid":1252,"":"io task","client":"0","":"downstairs","session_id":"8741b011-951e-4ca3-8aa2-f34cefb23951"}
5832025-03-17T22:25:49.871Z{"msg":"connecting to 127.0.0.1:8850","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:25:48.826043512Z","hostname":"w-01JPK2XYXNKNQHJ28D83W62KZ9","pid":1252,"":"io task","client":"1","":"downstairs","session_id":"8741b011-951e-4ca3-8aa2-f34cefb23951"}
5842025-03-17T22:25:49.871Z{"msg":"ds_connection connected from Ok(127.0.0.1:48199)","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:25:48.826125402Z","hostname":"w-01JPK2XYXNKNQHJ28D83W62KZ9","pid":1252,"":"io task","client":"0","":"downstairs","session_id":"8741b011-951e-4ca3-8aa2-f34cefb23951"}
5852025-03-17T22:25:49.871Z{"msg":"ds_connection connected from Ok(127.0.0.1:41823)","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:25:48.826164553Z","hostname":"w-01JPK2XYXNKNQHJ28D83W62KZ9","pid":1252,"":"io task","client":"2","":"downstairs","session_id":"8741b011-951e-4ca3-8aa2-f34cefb23951"}
5862025-03-17T22:25:49.871Z{"msg":"ds_connection connected from Ok(127.0.0.1:54165)","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:25:48.826267713Z","hostname":"w-01JPK2XYXNKNQHJ28D83W62KZ9","pid":1252,"":"io task","client":"1","":"downstairs","session_id":"8741b011-951e-4ca3-8aa2-f34cefb23951"}
5872025-03-17T22:25:49.871Z{"msg":"version negotiation from state Connecting { state: WaitForPromote, mode: New }","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:25:48.826502894Z","hostname":"w-01JPK2XYXNKNQHJ28D83W62KZ9","pid":1252,"client":"0","":"downstairs","session_id":"8741b011-951e-4ca3-8aa2-f34cefb23951"}
5882025-03-17T22:25:49.871Z{"msg":"version negotiation from state Connecting { state: WaitForPromote, mode: New }","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:25:48.826638464Z","hostname":"w-01JPK2XYXNKNQHJ28D83W62KZ9","pid":1252,"client":"1","":"downstairs","session_id":"8741b011-951e-4ca3-8aa2-f34cefb23951"}
5892025-03-17T22:25:49.871Z{"msg":"version negotiation from state Connecting { state: WaitForPromote, mode: New }","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:25:48.826691854Z","hostname":"w-01JPK2XYXNKNQHJ28D83W62KZ9","pid":1252,"client":"2","":"downstairs","session_id":"8741b011-951e-4ca3-8aa2-f34cefb23951"}
5902025-03-17T22:25:49.871Z{"msg":"downstairs client at Some(127.0.0.1:8840) has region UUID 12345678-0000-0000-0000-000000008840","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:25:48.827040605Z","hostname":"w-01JPK2XYXNKNQHJ28D83W62KZ9","pid":1252,"client":"0","":"downstairs","session_id":"8741b011-951e-4ca3-8aa2-f34cefb23951"}
5912025-03-17T22:25:49.871Z{"msg":"downstairs client at Some(127.0.0.1:8850) has region UUID 12345678-0000-0000-0000-000000008850","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:25:48.827080585Z","hostname":"w-01JPK2XYXNKNQHJ28D83W62KZ9","pid":1252,"client":"1","":"downstairs","session_id":"8741b011-951e-4ca3-8aa2-f34cefb23951"}
5922025-03-17T22:25:49.871Z{"msg":"downstairs client at Some(127.0.0.1:8860) has region UUID 12345678-0000-0000-0000-000000008860","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:25:48.827314946Z","hostname":"w-01JPK2XYXNKNQHJ28D83W62KZ9","pid":1252,"client":"2","":"downstairs","session_id":"8741b011-951e-4ca3-8aa2-f34cefb23951"}
5932025-03-17T22:25:49.871Z{"msg":"Waiting for more clients to be ready","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:25:48.827464157Z","hostname":"w-01JPK2XYXNKNQHJ28D83W62KZ9","pid":1252,"session_id":"8741b011-951e-4ca3-8aa2-f34cefb23951"}
5942025-03-17T22:25:49.872Z{"msg":"Waiting for more clients to be ready","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:25:48.827499537Z","hostname":"w-01JPK2XYXNKNQHJ28D83W62KZ9","pid":1252,"session_id":"8741b011-951e-4ca3-8aa2-f34cefb23951"}
5952025-03-17T22:25:49.872Z{"msg":"[0]R flush_numbers: [5322, 5322, 5322, 5322, 5322]","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:25:48.827637657Z","hostname":"w-01JPK2XYXNKNQHJ28D83W62KZ9","pid":1252,"":"downstairs","":"downstairs","session_id":"8741b011-951e-4ca3-8aa2-f34cefb23951"}
5962025-03-17T22:25:49.872Z{"msg":"[0]R generation: [32, 32, 32, 32, 32]","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:25:48.827665507Z","hostname":"w-01JPK2XYXNKNQHJ28D83W62KZ9","pid":1252,"":"downstairs","":"downstairs","session_id":"8741b011-951e-4ca3-8aa2-f34cefb23951"}
5972025-03-17T22:25:49.872Z{"msg":"[0]R dirty: [false, false, false, false, false]","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:25:48.827680557Z","hostname":"w-01JPK2XYXNKNQHJ28D83W62KZ9","pid":1252,"":"downstairs","":"downstairs","session_id":"8741b011-951e-4ca3-8aa2-f34cefb23951"}
5982025-03-17T22:25:49.872Z{"msg":"[1]R flush_numbers: [5322, 5322, 5322, 5322, 5322]","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:25:48.827702187Z","hostname":"w-01JPK2XYXNKNQHJ28D83W62KZ9","pid":1252,"":"downstairs","":"downstairs","session_id":"8741b011-951e-4ca3-8aa2-f34cefb23951"}
5992025-03-17T22:25:49.872Z{"msg":"[1]R generation: [32, 32, 32, 32, 32]","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:25:48.827715887Z","hostname":"w-01JPK2XYXNKNQHJ28D83W62KZ9","pid":1252,"":"downstairs","":"downstairs","session_id":"8741b011-951e-4ca3-8aa2-f34cefb23951"}
6002025-03-17T22:25:49.872Z{"msg":"[1]R dirty: [false, false, false, false, false]","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:25:48.827736537Z","hostname":"w-01JPK2XYXNKNQHJ28D83W62KZ9","pid":1252,"":"downstairs","":"downstairs","session_id":"8741b011-951e-4ca3-8aa2-f34cefb23951"}
6012025-03-17T22:25:49.872Z{"msg":"[2]R flush_numbers: [5322, 5322, 5322, 5322, 5322]","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:25:48.827750647Z","hostname":"w-01JPK2XYXNKNQHJ28D83W62KZ9","pid":1252,"":"downstairs","":"downstairs","session_id":"8741b011-951e-4ca3-8aa2-f34cefb23951"}
6022025-03-17T22:25:49.872Z{"msg":"[2]R generation: [32, 32, 32, 32, 32]","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:25:48.827770998Z","hostname":"w-01JPK2XYXNKNQHJ28D83W62KZ9","pid":1252,"":"downstairs","":"downstairs","session_id":"8741b011-951e-4ca3-8aa2-f34cefb23951"}
6032025-03-17T22:25:49.872Z{"msg":"[2]R dirty: [false, false, false, false, false]","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:25:48.827784318Z","hostname":"w-01JPK2XYXNKNQHJ28D83W62KZ9","pid":1252,"":"downstairs","":"downstairs","session_id":"8741b011-951e-4ca3-8aa2-f34cefb23951"}
6042025-03-17T22:25:49.872Z{"msg":"Max found gen is 33","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:25:48.827796978Z","hostname":"w-01JPK2XYXNKNQHJ28D83W62KZ9","pid":1252,"":"downstairs","":"downstairs","session_id":"8741b011-951e-4ca3-8aa2-f34cefb23951"}
6052025-03-17T22:25:49.872Z{"msg":"Generation requested: 33 >= found:33","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:25:48.827809738Z","hostname":"w-01JPK2XYXNKNQHJ28D83W62KZ9","pid":1252,"":"Wait for a query_work_queue command to finish before sending IO
6062025-03-17T22:25:49.872Zdownstairs","":"downstairs","session_id":"8741b011-951e-4ca3-8aa2-f34cefb23951"}
6072025-03-17T22:25:49.872Z{"msg":"Next flush: 5323","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:25:48.827839688Z","hostname":"w-01JPK2XYXNKNQHJ28D83W62KZ9","pid":1252,"":"downstairs","":"downstairs","session_id":"8741b011-951e-4ca3-8aa2-f34cefb23951"}
6082025-03-17T22:25:49.872Z{"msg":"All extents match","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:25:48.827853488Z","hostname":"w-01JPK2XYXNKNQHJ28D83W62KZ9","pid":1252,"":"downstairs","":"downstairs","session_id":"8741b011-951e-4ca3-8aa2-f34cefb23951"}
6092025-03-17T22:25:49.873Z{"msg":"No downstairs reconciliation required","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:25:48.827874338Z","hostname":"w-01JPK2XYXNKNQHJ28D83W62KZ9","pid":1252,"session_id":"8741b011-951e-4ca3-8aa2-f34cefb23951"}
6102025-03-17T22:25:49.873Z{"msg":"Transition from WaitQuorum to Active","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:25:48.827887598Z","hostname":"w-01JPK2XYXNKNQHJ28D83W62KZ9","pid":1252,"client":"0","":"downstairs","session_id":"8741b011-951e-4ca3-8aa2-f34cefb23951"}
6112025-03-17T22:25:49.873Z{"msg":"Transition from WaitQuorum to Active","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:25:48.827908738Z","hostname":"w-01JPK2XYXNKNQHJ28D83W62KZ9","pid":1252,"client":"1","":"downstairs","session_id":"8741b011-951e-4ca3-8aa2-f34cefb23951"}
6122025-03-17T22:25:49.873Z{"msg":"Transition from WaitQuorum to Active","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:25:48.827921898Z","hostname":"w-01JPK2XYXNKNQHJ28D83W62KZ9","pid":1252,"client":"2","":"downstairs","session_id":"8741b011-951e-4ca3-8aa2-f34cefb23951"}
6132025-03-17T22:25:49.873Z{"msg":"All required reconciliation work is completed","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:25:48.827935888Z","hostname":"w-01JPK2XYXNKNQHJ28D83W62KZ9","pid":1252,"session_id":"8741b011-951e-4ca3-8aa2-f34cefb23951"}
6142025-03-17T22:25:49.873Z{"msg":"Set Downstairs and Upstairs active after reconciliation","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:25:48.827955798Z","hostname":"w-01JPK2XYXNKNQHJ28D83W62KZ9","pid":1252,"session_id":"8741b011-951e-4ca3-8aa2-f34cefb23951"}
6152025-03-17T22:25:49.873Z{"msg":"b306975a-5257-44c1-8516-d485a9ef8108 is now active with session: 8741b011-951e-4ca3-8aa2-f34cefb23951","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:25:48.827969478Z","hostname":"w-01JPK2XYXNKNQHJ28D83W62KZ9","pid":1252,"session_id":"8741b011-951e-4ca3-8aa2-f34cefb23951"}
6162025-03-17T22:25:49.873Z{"msg":"Set Active after no reconciliation","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:25:48.827989098Z","hostname":"w-01JPK2XYXNKNQHJ28D83W62KZ9","pid":1252,"session_id":"8741b011-951e-4ca3-8aa2-f34cefb23951"}
6172025-03-17T22:25:49.873Z{"msg":"The guest has finished waiting for activation with:33","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:25:48.828022548Z","hostname":"w-01JPK2XYXNKNQHJ28D83W62KZ9","pid":1252}
6182025-03-17T22:25:49.873Z{"msg":"Activated sub_volume b306975a-5257-44c1-8516-d485a9ef8108","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:25:48.828035368Z","hostname":"w-01JPK2XYXNKNQHJ28D83W62KZ9","pid":1252}
6192025-03-17T22:25:49.873ZDisk: sv:2 bs:4096 ts:409600 tb:100 max_io:100 or 409600
6202025-03-17T22:25:49.873ZLoading write count information from file "/var/tmp/test_up-build/verify_file"
6212025-03-17T22:25:49.873ZRead and Verify all blocks (0..100 range:true)
6222025-03-17T22:25:49.941ZWrote out file "/var/tmp/test_up-build/verify_file"
6232025-03-17T22:25:49.941ZVerify test completed
6242025-03-17T22:25:49.945ZWrote out file "/var/tmp/test_up-build/verify_file"
6252025-03-17T22:25:49.945ZCLIENT: Tests done. All submitted work has been ACK'd
6262025-03-17T22:25:49.945Z----------------------------------------------------------------
6272025-03-17T22:25:49.945Z Crucible gen:33 GIO:true work queues: Upstairs:0 downstairs:1
6282025-03-17T22:25:49.945ZStates: Active Active Active
6292025-03-17T22:25:49.945ZJOBID ACK TYPE BKS/EXT DS:0 DS:1 DS:2 REPLAY
6302025-03-17T22:25:49.945Z 1000 Acked Read 50 Done Done Done false
6312025-03-17T22:25:49.945Z STATES DS:0 DS:1 DS:2 TOTAL
6322025-03-17T22:25:49.945Z Sent 0 0 0 0
6332025-03-17T22:25:49.945Z Done 1 1 1 3
6342025-03-17T22:25:49.945Z Skipped 0 0 0 0
6352025-03-17T22:25:49.945Z Error 0 0 0 0
6362025-03-17T22:25:49.945ZLast Flush: None None None
6372025-03-17T22:25:49.945ZDownstairs last five completed:
6382025-03-17T22:25:49.945ZUpstairs last five completed: 1000
6392025-03-17T22:25:49.945Z----------------------------------------------------------------
6402025-03-17T22:25:49.945Z Crucible gen:33 GIO:true work queues: Upstairs:0 downstairs:1
6412025-03-17T22:25:49.945ZStates: Active Active Active
6422025-03-17T22:25:49.945ZJOBID ACK TYPE BKS/EXT DS:0 DS:1 DS:2 REPLAY
6432025-03-17T22:25:49.945Z 1000 Acked Read 50 Done Done Done false
6442025-03-17T22:25:49.945Z STATES DS:0 DS:1 DS:2 TOTAL
6452025-03-17T22:25:49.945Z Sent 0 0 0 0
6462025-03-17T22:25:49.945Z Done 1 1 1 3
6472025-03-17T22:25:49.945Z Skipped 0 0 0 0
6482025-03-17T22:25:49.945Z Error 0 0 0 0
6492025-03-17T22:25:49.945ZLast Flush: None None None
6502025-03-17T22:25:49.945ZDownstairs last five completed:
6512025-03-17T22:25:49.945ZUpstairs last five completed: 1000
6522025-03-17T22:25:49.945ZCLIENT: Up:0 ds:2 act:6
6532025-03-17T22:25:53.943Z----------------------------------------------------------------
6542025-03-17T22:25:53.943Z Crucible gen:33 GIO:true work queues: Upstairs:0 downstairs:0
6552025-03-17T22:25:53.943ZDownstairs last five completed: 1001 1000
6562025-03-17T22:25:53.943ZUpstairs last five completed: 1001 1000
6572025-03-17T22:25:53.947Z----------------------------------------------------------------
6582025-03-17T22:25:53.947Z Crucible gen:33 GIO:true work queues: Upstairs:0 downstairs:0
6592025-03-17T22:25:53.947ZDownstairs last five completed: 1001 1000
6602025-03-17T22:25:53.947ZUpstairs last five completed: 1001 1000
6612025-03-17T22:25:53.947ZCLIENT: Up:0 ds:0 act:6
6622025-03-17T22:25:53.947ZCLIENT: All crucible jobs finished, exiting program
6632025-03-17T22:25:53.947Z{"msg":"Guest handle has been dropped","v":0,"name":"crucible","level":40,"time":"2025-03-17T22:25:52.911264842Z","hostname":"w-01JPK2XYXNKNQHJ28D83W62KZ9","pid":1252}
6642025-03-17T22:25:53.951ZRepair part 2 passed
6652025-03-17T22:25:53.954Z/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
6662025-03-17T22:25:53.969ZEXT BLOCKS GEN0 GEN1 GEN2 FL0 FL1 FL2 D0 D1 D2 DIFF
6672025-03-17T22:25:53.969Z 0 000-009 32 32 32 4000 4000 4000 F F F
6682025-03-17T22:25:53.969Z 1 010-019 32 32 32 4000 4000 4000 F F F
6692025-03-17T22:25:53.969Z 2 020-029 32 32 32 4000 4000 4000 F F F
6702025-03-17T22:25:53.969Z 3 030-039 32 32 32 4000 4000 4000 F F F
6712025-03-17T22:25:53.969Z 4 040-049 32 32 32 4000 4000 4000 F F F
6722025-03-17T22:25:53.973ZMax gen: 32, Max flush: 4000
6732025-03-17T22:25:53.976Zdump test passed
6742025-03-17T22:25:53.976Z/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
6752025-03-17T22:25:53.990Z Extent 1
6762025-03-17T22:25:53.993ZGEN 32 32 32
6772025-03-17T22:25:53.993ZFLUSH_ID 4000 4000 4000
6782025-03-17T22:25:53.993ZDIRTY
6792025-03-17T22:25:53.993Z
6802025-03-17T22:25:53.993ZBLOCK D0 D1 D2 C0 C1 C2 DIFF
6812025-03-17T22:25:53.993Z010 A A A A A A
6822025-03-17T22:25:53.997Z011 A A A A A A
6832025-03-17T22:25:53.997Z012 A A A A A A
6842025-03-17T22:25:53.997Z013 A A A A A A
6852025-03-17T22:25:54.001Z014 A A A A A A
6862025-03-17T22:25:54.001Z015 A A A A A A
6872025-03-17T22:25:54.001Z016 A A A A A A
6882025-03-17T22:25:54.004Z017 A A A A A A
6892025-03-17T22:25:54.004Z018 A A A A A A
6902025-03-17T22:25:54.007Z019 A A A A A A
6912025-03-17T22:25:54.011Zdump extent test passed
6922025-03-17T22:25:54.011Z/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
6932025-03-17T22:25:54.023ZExtent 2 Block in extent 0 Actual block 20
6942025-03-17T22:25:54.023Z
6952025-03-17T22:25:54.027Z DATA SHA256 VER
6962025-03-17T22:25:54.027Z------ ---------------------------------------------------------------- ---
6972025-03-17T22:25:54.027Z 0 f38a029ccaf2f223934edc5b182cef6d71985ebfd165ea063537ab4cb5d8c427 A
6982025-03-17T22:25:54.027Z 1 f38a029ccaf2f223934edc5b182cef6d71985ebfd165ea063537ab4cb5d8c427 A
6992025-03-17T22:25:54.027Z 2 f38a029ccaf2f223934edc5b182cef6d71985ebfd165ea063537ab4cb5d8c427 A
7002025-03-17T22:25:54.027Z
7012025-03-17T22:25:54.027ZNONCES 0 1 2 DIFF
7022025-03-17T22:25:54.027Z------ ------------------------ ------------------------ ------------------------ -----
7032025-03-17T22:25:54.027Z 0 d73888dd983c64aca7aeb449 d73888dd983c64aca7aeb449 d73888dd983c64aca7aeb449
7042025-03-17T22:25:54.027Z
7052025-03-17T22:25:54.027Z TAGS 0 1 2 DIFF
7062025-03-17T22:25:54.027Z------ -------------------------------- -------------------------------- -------------------------------- -----
7072025-03-17T22:25:54.027Z 0 6e989cca6e6ad5f1d37d956e8a63928b 6e989cca6e6ad5f1d37d956e8a63928b 6e989cca6e6ad5f1d37d956e8a63928b
7082025-03-17T22:25:54.027Z
7092025-03-17T22:25:54.027ZHASHES 0 1 2 DIFF
7102025-03-17T22:25:54.027Z------ ---------------- ---------------- ---------------- -----
7112025-03-17T22:25:54.027Z
7122025-03-17T22:25:54.031Zdump block test passed
7132025-03-17T22:25:54.031ZInitial upstairs tests have completed, stopping all downstairs
7142025-03-17T22:25:59.098ZCreating 7 larger downstairs regions
7152025-03-17T22:25:59.278ZStarting 7 downstairs
7162025-03-17T22:26:04.294Zdsc restarted at PID: 1268
7172025-03-17T22:26:04.682ZNow do the replace-reconcile test
7182025-03-17T22:26:04.742ZUsing 8870 for the replacement port
7192025-03-17T22:29:12.093ZCompleted test: replace-reconcile
7202025-03-17T22:29:12.098ZNow do the replace-before-active test
7212025-03-17T22:32:46.590ZCompleted test: replace-before-active
7222025-03-17T22:32:46.590ZAll tests have completed, stopping all downstairs
7232025-03-17T22:32:46.649Z
7242025-03-17T22:32:46.649ZAll Tests have passed
7252025-03-17T22:32:46.652Z13:55 Test duration
7262025-03-17T22:32:46.652Z
7272025-03-17T22:32:46.652Zreal 13:55.283641820
7282025-03-17T22:32:46.652Zuser 19:04.070486838
7292025-03-17T22:32:46.652Zsys 24.515046845
7302025-03-17T22:32:46.652Ztrap 0.549631178
7312025-03-17T22:32:46.652Ztflt 0.038687279
7322025-03-17T22:32:46.652Zdflt 0.029196080
7332025-03-17T22:32:46.652Zkflt 0.002197990
7342025-03-17T22:32:46.652Zlock 25:49:41.310318794
7352025-03-17T22:32:46.652Zslp 1:15:36.406543180
7362025-03-17T22:32:46.652Zlat 2:03.787502860
7372025-03-17T22:32:46.652Zstop 0.211398906
7382025-03-17T22:32:46.652Z+ echo 'test-up-2region-encrypted ends'
7392025-03-17T22:32:46.652Ztest-up-2region-encrypted ends
7402025-03-17T22:32:51.655Zprocess exited: duration 843712 ms, exit code 0
7412025-03-17T22:32:51.655Zexec warning: : stdio descriptors remain open after task exit; waiting 60 seconds for them to close
7422025-03-17T22:33:51.693Zexec warning: : stdout descriptor may be held open by a background process; giving up!
7432025-03-17T22:33:51.693Zexec warning: : stderr descriptor may be held open by a background process; giving up!
 
7442025-03-17T22:33:51.707Zfound 17 output files
7452025-03-17T22:33:51.707Zuploading: /tmp/test_up-build/dsc-out.txt (53549 bytes)
7462025-03-17T22:33:52.722Zuploaded: /tmp/test_up-build/dsc-out.txt
7472025-03-17T22:33:52.725Zuploading: /tmp/test_up-build/test_up_out.txt (8283682 bytes)
7482025-03-17T22:33:53.873Zuploaded: /tmp/test_up-build/test_up_out.txt
7492025-03-17T22:33:53.876Zuploading: /tmp/test_up-build/dsc/downstairs-8810.txt (147254 bytes)
7502025-03-17T22:33:54.898Zuploaded: /tmp/test_up-build/dsc/downstairs-8810.txt
7512025-03-17T22:33:54.898Zuploading: /tmp/test_up-build/dsc/downstairs-8820.txt (144646 bytes)
7522025-03-17T22:33:55.918Zuploaded: /tmp/test_up-build/dsc/downstairs-8820.txt
7532025-03-17T22:33:55.918Zuploading: /tmp/test_up-build/dsc/downstairs-8830.txt (250997 bytes)
7542025-03-17T22:33:56.949Zuploaded: /tmp/test_up-build/dsc/downstairs-8830.txt
7552025-03-17T22:33:56.952Zuploading: /tmp/test_up-build/dsc/downstairs-8840.txt (139432 bytes)
7562025-03-17T22:33:57.970Zuploaded: /tmp/test_up-build/dsc/downstairs-8840.txt
7572025-03-17T22:33:57.970Zuploading: /tmp/test_up-build/dsc/downstairs-8850.txt (2499 bytes)
7582025-03-17T22:33:58.979Zuploaded: /tmp/test_up-build/dsc/downstairs-8850.txt
7592025-03-17T22:33:58.983Zuploading: /tmp/test_up-build/dsc/downstairs-8860.txt (36391 bytes)
7602025-03-17T22:33:59.996Zuploaded: /tmp/test_up-build/dsc/downstairs-8860.txt
7612025-03-17T22:33:59.999Zuploading: /tmp/test_up-build/dsc/downstairs-8870.txt (842015 bytes)
7622025-03-17T22:34:01.051Zuploaded: /tmp/test_up-build/dsc/downstairs-8870.txt
7632025-03-17T22:34:01.059Zuploading: /tmp/debug/df.txt (1270 bytes)
7642025-03-17T22:34:02.072Zuploaded: /tmp/debug/df.txt
7652025-03-17T22:34:02.072Zuploading: /tmp/debug/dtrace.txt (945656 bytes)
7662025-03-17T22:34:02.127Zupload warning: file "/tmp/debug/dtrace.txt" changed size mid upload: 945656 -> 1070168
7672025-03-17T22:34:03.139Zuploaded: /tmp/debug/dtrace.txt
7682025-03-17T22:34:03.143Zuploading: /tmp/debug/iostat.txt (268567 bytes)
7692025-03-17T22:34:03.165Zupload warning: file "/tmp/debug/iostat.txt" changed size mid upload: 268567 -> 271845
7702025-03-17T22:34:04.180Zuploaded: /tmp/debug/iostat.txt
7712025-03-17T22:34:04.180Zuploading: /tmp/debug/mpstat.txt (655036 bytes)
7722025-03-17T22:34:04.214Zupload warning: file "/tmp/debug/mpstat.txt" changed size mid upload: 655036 -> 663760
7732025-03-17T22:34:05.225Zuploaded: /tmp/debug/mpstat.txt
7742025-03-17T22:34:05.230Zuploading: /tmp/debug/paging.txt (116191 bytes)
7752025-03-17T22:34:05.241Zupload warning: file "/tmp/debug/paging.txt" changed size mid upload: 116191 -> 117818
7762025-03-17T22:34:06.251Zuploaded: /tmp/debug/paging.txt
7772025-03-17T22:34:06.251Zuploading: /tmp/debug/prstat.txt (1276151 bytes)
7782025-03-17T22:34:06.277Zupload warning: file "/tmp/debug/prstat.txt" changed size mid upload: 1276151 -> 1295504
7792025-03-17T22:34:07.291Zuploaded: /tmp/debug/prstat.txt
7802025-03-17T22:34:07.291Zuploading: /tmp/debug/psrinfo.txt (1528 bytes)
7812025-03-17T22:34:08.319Zuploaded: /tmp/debug/psrinfo.txt
7822025-03-17T22:34:08.320Zuploading: /tmp/debug/upstairs-info.txt (184800 bytes)
7832025-03-17T22:34:09.431Zuploaded: /tmp/debug/upstairs-info.txt