01JQ0RMPKKHAWBRTP9VX9D9V3Z: 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: 01JQ0RMZ5CBHN3F5GNH1RWHJ5A

Tags:

Artefacts:

Output:

SEQ GLOBAL TIME DETAILS
12025-03-23T06:01:15.359Zjob dependencies complete; ready to run (waiting for 14 m 1 s)
22025-03-23T06:02:04.493Zjob assigned to worker 01JQ0SETNSKZ27QMNBAK8ZTS6N [factory aws, i-04c00caa4d8fceb52] (queued for 49 s)
32025-03-23T06:02:12.820Zdownloading input: /input/build/work/bins/crucible-downstairs.gz
42025-03-23T06:02:13.996Zdownloaded input: /input/build/work/bins/crucible-downstairs.gz
52025-03-23T06:02:13.996Zdownloading input: /input/build/work/bins/crucible-hammer.gz
62025-03-23T06:02:15.110Zdownloaded input: /input/build/work/bins/crucible-hammer.gz
72025-03-23T06:02:15.110Zdownloading input: /input/build/work/bins/crutest.gz
82025-03-23T06:02:16.298Zdownloaded input: /input/build/work/bins/crutest.gz
92025-03-23T06:02:16.298Zdownloading input: /input/build/work/bins/dsc.gz
102025-03-23T06:02:16.950Zdownloaded input: /input/build/work/bins/dsc.gz
112025-03-23T06:02:16.955Zdownloading input: /input/build/work/scripts/perf-downstairs-tick.d
122025-03-23T06:02:16.968Zdownloaded input: /input/build/work/scripts/perf-downstairs-tick.d
132025-03-23T06:02:16.968Zdownloading input: /input/build/work/scripts/test_ds.sh
142025-03-23T06:02:16.987Zdownloaded input: /input/build/work/scripts/test_ds.sh
152025-03-23T06:02:16.987Zdownloading input: /input/build/work/scripts/test_live_repair.sh
162025-03-23T06:02:17.006Zdownloaded input: /input/build/work/scripts/test_live_repair.sh
172025-03-23T06:02:17.007Zdownloading input: /input/build/work/scripts/test_repair.sh
182025-03-23T06:02:17.022Zdownloaded input: /input/build/work/scripts/test_repair.sh
192025-03-23T06:02:17.022Zdownloading input: /input/build/work/scripts/test_replay.sh
202025-03-23T06:02:17.042Zdownloaded input: /input/build/work/scripts/test_replay.sh
212025-03-23T06:02:17.042Zdownloading input: /input/build/work/scripts/test_up.sh
222025-03-23T06:02:17.060Zdownloaded input: /input/build/work/scripts/test_up.sh
232025-03-23T06:02:17.060Zdownloading input: /input/build/work/scripts/upstairs_info.d
242025-03-23T06:02:17.079Zdownloaded input: /input/build/work/scripts/upstairs_info.d
252025-03-23T06:02:17.083Zdownloading input: /input/build/tmp/cargo-test-out.log
262025-03-23T06:02:17.785Zdownloaded input: /input/build/tmp/cargo-test-out.log
 
272025-03-23T06:02:17.785Zstarting task 0: "setup"
282025-03-23T06:02:17.792Z++ uname -s
292025-03-23T06:02:17.797Z+ kern=SunOS
302025-03-23T06:02:17.797Z+ build_user=build
312025-03-23T06:02:17.797Z+ build_uid=12345
322025-03-23T06:02:17.797Z+ work_dir=/work
332025-03-23T06:02:17.797Z+ input_dir=/input
342025-03-23T06:02:17.797Z+ [[ 0 == 12345 ]]
352025-03-23T06:02:17.797Z+ case "$kern" in
362025-03-23T06:02:17.797Z+ groupadd -g 12345 build
372025-03-23T06:02:17.801Z+ useradd -u 12345 -g build -d /home/build -s /bin/bash -c build -P 'Primary Administrator' build
382025-03-23T06:02:19.804Z+ zfs create -o mountpoint=/work rpool/work
392025-03-23T06:02:20.068Z++ awk '$2 == "/home" { print $3 }' /etc/mnttab
402025-03-23T06:02:20.071Z+ home_fs=zfs
412025-03-23T06:02:20.072Z+ [[ zfs == autofs ]]
422025-03-23T06:02:20.072Z+ mkdir -p /home/build
432025-03-23T06:02:20.075Z+ chown build:build /home/build /work
442025-03-23T06:02:22.076Z+ chmod 0700 /home/build /work
452025-03-23T06:02:22.079Zprocess exited: duration 4293 ms, exit code 0
 
462025-03-23T06:02:22.089Zstarting task 1: "authentication"
472025-03-23T06:02:22.106Zprocess exited: duration 19 ms, exit code 0
 
482025-03-23T06:02:22.116Zstarting task 2: "build"
492025-03-23T06:02:22.120Z+ banner cores
502025-03-23T06:02:22.125Z
512025-03-23T06:02:22.125Z #### #### ##### ###### ####
522025-03-23T06:02:22.125Z # # # # # # # #
532025-03-23T06:02:22.125Z # # # # # ##### ####
542025-03-23T06:02:22.125Z # # # ##### # #
552025-03-23T06:02:22.125Z # # # # # # # # #
562025-03-23T06:02:22.125Z #### #### # # ###### ####
572025-03-23T06:02:22.125Z
582025-03-23T06:02:22.125Z+ pfexec coreadm -i /tmp/core.%f.%p -g /tmp/core.%f.%p -e global -e log -e proc-setid -e global-setid
592025-03-23T06:02:22.132Z+ banner unpack
602025-03-23T06:02:22.136Z
612025-03-23T06:02:22.136Z # # # # ##### ## #### # #
622025-03-23T06:02:22.136Z # # ## # # # # # # # # #
632025-03-23T06:02:22.136Z # # # # # # # # # # ####
642025-03-23T06:02:22.136Z # # # # # ##### ###### # # #
652025-03-23T06:02:22.136Z # # # ## # # # # # # #
662025-03-23T06:02:22.136Z #### # # # # # #### # #
672025-03-23T06:02:22.136Z
682025-03-23T06:02:22.136Z+ mkdir -p /var/tmp/bins
692025-03-23T06:02:22.139Z+ for t in "$input/bins/"*.gz
702025-03-23T06:02:22.139Z++ basename /input/build/work/bins/crucible-downstairs.gz
712025-03-23T06:02:22.139Z+ b=crucible-downstairs.gz
722025-03-23T06:02:22.139Z+ b=crucible-downstairs
732025-03-23T06:02:22.139Z+ gunzip
742025-03-23T06:02:24.526Z+ chmod +x /var/tmp/bins/crucible-downstairs
752025-03-23T06:02:24.529Z+ for t in "$input/bins/"*.gz
762025-03-23T06:02:24.529Z++ basename /input/build/work/bins/crucible-hammer.gz
772025-03-23T06:02:24.532Z+ b=crucible-hammer.gz
782025-03-23T06:02:24.532Z+ b=crucible-hammer
792025-03-23T06:02:24.532Z+ gunzip
802025-03-23T06:02:26.771Z+ chmod +x /var/tmp/bins/crucible-hammer
812025-03-23T06:02:26.774Z+ for t in "$input/bins/"*.gz
822025-03-23T06:02:26.774Z++ basename /input/build/work/bins/crutest.gz
832025-03-23T06:02:26.777Z+ b=crutest.gz
842025-03-23T06:02:26.777Z+ b=crutest
852025-03-23T06:02:26.777Z+ gunzip
862025-03-23T06:02:29.231Z+ chmod +x /var/tmp/bins/crutest
872025-03-23T06:02:29.235Z+ for t in "$input/bins/"*.gz
882025-03-23T06:02:29.235Z++ basename /input/build/work/bins/dsc.gz
892025-03-23T06:02:29.238Z+ b=dsc.gz
902025-03-23T06:02:29.238Z+ b=dsc
912025-03-23T06:02:29.238Z+ gunzip
922025-03-23T06:02:30.534Z+ chmod +x /var/tmp/bins/dsc
932025-03-23T06:02:30.538Z+ export BINDIR=/var/tmp/bins
942025-03-23T06:02:30.538Z+ BINDIR=/var/tmp/bins
952025-03-23T06:02:30.538Z+ jobpid=1147
962025-03-23T06:02:30.538Z+ echo 'Setup debug logging'
972025-03-23T06:02:30.538ZSetup debug logging
982025-03-23T06:02:30.538Z+ mkdir /tmp/debug
992025-03-23T06:02:30.538Z+ sleep 3600
1002025-03-23T06:02:30.541Z+ psrinfo -v
1012025-03-23T06:02:30.544Z+ df -h
1022025-03-23T06:02:30.560Z+ prstat -d d -mLc 1
1032025-03-23T06:02:30.563Z+ iostat -T d -xn 1
1042025-03-23T06:02:30.563Z+ mpstat -T d 1
1052025-03-23T06:02:30.563Z+ vmstat -T d -p 1
1062025-03-23T06:02:30.563Z+ pfexec dtrace -Z -s /input/build/work/scripts/perf-downstairs-tick.d
1072025-03-23T06:02:30.567Z+ banner test_up_2r_encrypted
1082025-03-23T06:02:30.567Z+ pfexec dtrace -Z -s /input/build/work/scripts/upstairs_info.d
1092025-03-23T06:02:30.567Z #####
1102025-03-23T06:02:30.568Z ##### ###### #### ##### # # ##### # # #####
1112025-03-23T06:02:30.568Z # # # # # # # # # # #
1122025-03-23T06:02:30.568Z # ##### #### # # # # # ##### # #
1132025-03-23T06:02:30.568Z # # # # # # ##### # #####
1142025-03-23T06:02:30.568Z # # # # # # # # # # #
1152025-03-23T06:02:30.568Z # ###### #### # ####### #### # ####### ####### # #
1162025-03-23T06:02:30.568Z
1172025-03-23T06:02:30.568Z+ ptime -m bash /input/build/work/scripts/test_up.sh -r 2 -N encrypted
1182025-03-23T06:02:30.577Z/input/build/work
1192025-03-23T06:02:30.589ZUsing 2 region sets
1202025-03-23T06:02:30.589ZTurn off color for downstairs dump
1212025-03-23T06:02:30.603ZUpstairs using key: Dt8v/c59Kokn019xjOMnOkX3zbETL5mD7zrCLjwHGnM=
1222025-03-23T06:02:30.606Zdsc output goes to /tmp/test_up-build/dsc-out.txt
1232025-03-23T06:02:30.606ZCreating 6 downstairs regions
1242025-03-23T06:02:31.010ZStarting 6 downstairs
1252025-03-23T06:02:31.013Zdsc started at PID: 1195
1262025-03-23T06:02:36.338ZDisable automatic restart on all downstairs
1272025-03-23T06:02:36.390Z
1282025-03-23T06:02:36.390ZBegin tests, output goes to /tmp/test_up-build/test_up_out.txt
1292025-03-23T06:02:36.393ZRunning test: span
1302025-03-23T06:02:40.567ZCompleted test: span
1312025-03-23T06:02:45.574ZRunning test: big
1322025-03-23T06:02:50.155ZCompleted test: big
1332025-03-23T06:02:55.163ZRunning test: dep
1342025-03-23T06:03:28.284ZCompleted test: dep
1352025-03-23T06:03:33.291ZRunning test: balloon
1362025-03-23T06:07:45.444ZCompleted test: balloon
1372025-03-23T06:07:50.452ZRunning test: deactivate
1382025-03-23T06:08:45.103ZCompleted test: deactivate
1392025-03-23T06:08:50.111ZRunning hammer
1402025-03-23T06:09:07.838ZRun repair tests
1412025-03-23T06:09:07.841Z/var/tmp/bins/crutest fill -g 31 -q --key Dt8v/c59Kokn019xjOMnOkX3zbETL5mD7zrCLjwHGnM= --dsc 127.0.0.1:9998 --verify-out /var/tmp/test_up-build/verify_file
1422025-03-23T06:09:07.901Z{"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-23T06:09:06.194762749Z","hostname":"w-01JQ0SETNSKZ27QMNBAK8ZTS6N","pid":1238,"task":"crutest"}
1432025-03-23T06:09:07.904Z{"msg":"dsc has 6 regions. This means 2 sub_volumes","v":0,"name":"crucible","level":30,"time":"2025-03-23T06:09:06.195314233Z","hostname":"w-01JQ0SETNSKZ27QMNBAK8ZTS6N","pid":1238,"task":"crutest"}
1442025-03-23T06:09:07.904Z{"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-23T06:09:06.197071688Z","hostname":"w-01JQ0SETNSKZ27QMNBAK8ZTS6N","pid":1238,"task":"crutest"}
1452025-03-23T06:09:07.904Z{"msg":"Upstairs starts","v":0,"name":"crucible","level":30,"time":"2025-03-23T06:09:06.19725382Z","hostname":"w-01JQ0SETNSKZ27QMNBAK8ZTS6N","pid":1238}
1462025-03-23T06:09:07.904Z{"msg":"Crucible Version: BuildInfo {\n version: \"0.0.1\",\n git_sha: \"a0baefa8a6d4c0e5f0d4f746f2af5de9c08b52b6\",\n git_commit_timestamp: \"2025-03-23T05:46:50.000000000Z\",\n git_branch: \"renovate/rust-1.x\",\n rustc_semver: \"1.85.1\",\n rustc_channel: \"stable\",\n rustc_host_triple: \"x86_64-unknown-illumos\",\n rustc_commit_sha: \"4eb161250e340c8f48f66e2b929ef4a5bed7c181\",\n cargo_triple: \"x86_64-unknown-illumos\",\n debug: true,\n opt_level: 0,\n}","v":0,"name":"crucible","level":30,"time":"2025-03-23T06:09:06.197324999Z","hostname":"w-01JQ0SETNSKZ27QMNBAK8ZTS6N","pid":1238}
1472025-03-23T06:09:07.904Z{"msg":"Upstairs <-> Downstairs Message Version: 13","v":0,"name":"crucible","level":30,"time":"2025-03-23T06:09:06.197355614Z","hostname":"w-01JQ0SETNSKZ27QMNBAK8ZTS6N","pid":1238}
1482025-03-23T06:09:07.904Z{"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-23T06:09:06.197376371Z","hostname":"w-01JQ0SETNSKZ27QMNBAK8ZTS6N","pid":1238}
1492025-03-23T06:09:07.904Z{"msg":"Crucible 78c2d3fe-cf8a-4389-891d-df623ed8389c has session id: 0c5da301-5bfe-495b-ab00-bef6ee38a502","v":0,"name":"crucible","level":30,"time":"2025-03-23T06:09:06.197975457Z","hostname":"w-01JQ0SETNSKZ27QMNBAK8ZTS6N","pid":1238,"session_id":"0c5da301-5bfe-495b-ab00-bef6ee38a502"}
1502025-03-23T06:09:07.904Z{"msg":"Upstairs opts: Upstairs UUID: 78c2d3fe-cf8a-4389-891d-df623ed8389c, 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-23T06:09:06.1980858Z","hostname":"w-01JQ0SETNSKZ27QMNBAK8ZTS6N","pid":1238,"session_id":"0c5da301-5bfe-495b-ab00-bef6ee38a502"}
1512025-03-23T06:09:07.904Z{"msg":"Crucible stats registered with UUID: 78c2d3fe-cf8a-4389-891d-df623ed8389c","v":0,"name":"crucible","level":30,"time":"2025-03-23T06:09:06.198124084Z","hostname":"w-01JQ0SETNSKZ27QMNBAK8ZTS6N","pid":1238,"session_id":"0c5da301-5bfe-495b-ab00-bef6ee38a502"}
1522025-03-23T06:09:07.904Z{"msg":"could not find Downstairs address for Nexus","v":0,"name":"crucible","level":40,"time":"2025-03-23T06:09:06.19814662Z","hostname":"w-01JQ0SETNSKZ27QMNBAK8ZTS6N","pid":1238,"session_id":"0c5da301-5bfe-495b-ab00-bef6ee38a502"}
1532025-03-23T06:09:07.908Z{"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-23T06:09:06.200076028Z","hostname":"w-01JQ0SETNSKZ27QMNBAK8ZTS6N","pid":1238,"task":"crutest"}
1542025-03-23T06:09:07.908Z{"msg":"Upstairs starts","v":0,"name":"crucible","level":30,"time":"2025-03-23T06:09:06.200158786Z","hostname":"w-01JQ0SETNSKZ27QMNBAK8ZTS6N","pid":1238}
1552025-03-23T06:09:07.908Z{"msg":"Crucible Version: BuildInfo {\n version: \"0.0.1\",\n git_sha: \"a0baefa8a6d4c0e5f0d4f746f2af5de9c08b52b6\",\n git_commit_timestamp: \"2025-03-23T05:46:50.000000000Z\",\n git_branch: \"renovate/rust-1.x\",\n rustc_semver: \"1.85.1\",\n rustc_channel: \"stable\",\n rustc_host_triple: \"x86_64-unknown-illumos\",\n rustc_commit_sha: \"4eb161250e340c8f48f66e2b929ef4a5bed7c181\",\n cargo_triple: \"x86_64-unknown-illumos\",\n debug: true,\n opt_level: 0,\n}","v":0,"name":"crucible","level":30,"time":"2025-03-23T06:09:06.20019516Z","hostname":"w-01JQ0SETNSKZ27QMNBAK8ZTS6N","pid":1238}
1562025-03-23T06:09:07.908Z{"msg":"Upstairs <-> Downstairs Message Version: 13","v":0,"name":"crucible","level":30,"time":"2025-03-23T06:09:06.200216777Z","hostname":"w-01JQ0SETNSKZ27QMNBAK8ZTS6N","pid":1238}
1572025-03-23T06:09:07.908Z{"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-23T06:09:06.200231904Z","hostname":"w-01JQ0SETNSKZ27QMNBAK8ZTS6N","pid":1238}
1582025-03-23T06:09:07.908Z{"msg":"Crucible 78c2d3fe-cf8a-4389-891d-df623ed8389c has session id: ab6a02da-3b45-4329-820c-88ddb5fb293a","v":0,"name":"crucible","level":30,"time":"2025-03-23T06:09:06.200583899Z","hostname":"w-01JQ0SETNSKZ27QMNBAK8ZTS6N","pid":1238,"session_id":"ab6a02da-3b45-4329-820c-88ddb5fb293a"}
1592025-03-23T06:09:07.908Z{"msg":"Upstairs opts: Upstairs UUID: 78c2d3fe-cf8a-4389-891d-df623ed8389c, 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-23T06:09:06.200634151Z","hostname":"w-01JQ0SETNSKZ27QMNBAK8ZTS6N","pid":1238,"session_id":"ab6a02da-3b45-4329-820c-88ddb5fb293a"}
1602025-03-23T06:09:07.908Z{"msg":"Crucible stats registered with UUID: 78c2d3fe-cf8a-4389-891d-df623ed8389c","v":0,"name":"crucible","level":30,"time":"2025-03-23T06:09:06.200684083Z","hostname":"w-01JQ0SETNSKZ27QMNBAK8ZTS6N","pid":1238,"session_id":"ab6a02da-3b45-4329-820c-88ddb5fb293a"}
1612025-03-23T06:09:07.908Z{"msg":"could not find Downstairs address for Nexus","v":0,"name":"crucible","level":40,"time":"2025-03-23T06:09:06.2007077Z","hostname":"w-01JQ0SETNSKZ27QMNBAK8ZTS6N","pid":1238,"session_id":"ab6a02da-3b45-4329-820c-88ddb5fb293a"}
1622025-03-23T06:09:07.908Z{"msg":"Downstairs in volume = 6","v":0,"name":"crucible","level":30,"time":"2025-03-23T06:09:06.201334722Z","hostname":"w-01JQ0SETNSKZ27QMNBAK8ZTS6N","pid":1238,"task":"crutest"}
1632025-03-23T06:09:07.908Z{"msg":"The guest has requested activation with gen:31","v":0,"name":"crucible","level":30,"time":"2025-03-23T06:09:06.201377175Z","hostname":"w-01JQ0SETNSKZ27QMNBAK8ZTS6N","pid":1238}
1642025-03-23T06:09:07.908Z{"msg":"78c2d3fe-cf8a-4389-891d-df623ed8389c active request set","v":0,"name":"crucible","level":30,"time":"2025-03-23T06:09:06.201477399Z","hostname":"w-01JQ0SETNSKZ27QMNBAK8ZTS6N","pid":1238,"session_id":"0c5da301-5bfe-495b-ab00-bef6ee38a502"}
1652025-03-23T06:09:07.908Z{"msg":"sending connect oneshot to client","v":0,"name":"crucible","level":30,"time":"2025-03-23T06:09:06.201534031Z","hostname":"w-01JQ0SETNSKZ27QMNBAK8ZTS6N","pid":1238,"client":"0","":"downstairs","session_id":"0c5da301-5bfe-495b-ab00-bef6ee38a502"}
1662025-03-23T06:09:07.908Z{"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-23T06:09:06.20159929Z","hostname":"w-01JQ0SETNSKZ27QMNBAK8ZTS6N","pid":1238,"client":"0","":"downstairs","session_id":"0c5da301-5bfe-495b-ab00-bef6ee38a502"}
1672025-03-23T06:09:07.908Z{"msg":"sending connect oneshot to client","v":0,"name":"crucible","level":30,"time":"2025-03-23T06:09:06.201646203Z","hostname":"w-01JQ0SETNSKZ27QMNBAK8ZTS6N","pid":1238,"client":"1","":"downstairs","session_id":"0c5da301-5bfe-495b-ab00-bef6ee38a502"}
1682025-03-23T06:09:07.908Z{"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-23T06:09:06.201669549Z","hostname":"w-01JQ0SETNSKZ27QMNBAK8ZTS6N","pid":1238,"client":"1","":"downstairs","session_id":"0c5da301-5bfe-495b-ab00-bef6ee38a502"}
1692025-03-23T06:09:07.908Z{"msg":"sending connect oneshot to client","v":0,"name":"crucible","level":30,"time":"2025-03-23T06:09:06.201699065Z","hostname":"w-01JQ0SETNSKZ27QMNBAK8ZTS6N","pid":1238,"client":"2","":"downstairs","session_id":"0c5da301-5bfe-495b-ab00-bef6ee38a502"}
1702025-03-23T06:09:07.908Z{"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-23T06:09:06.20172715Z","hostname":"w-01JQ0SETNSKZ27QMNBAK8ZTS6N","pid":1238,"client":"2","":"downstairs","session_id":"0c5da301-5bfe-495b-ab00-bef6ee38a502"}
1712025-03-23T06:09:07.908Z{"msg":"connecting to 127.0.0.1:8830","v":0,"name":"crucible","level":30,"time":"2025-03-23T06:09:06.201929618Z","hostname":"w-01JQ0SETNSKZ27QMNBAK8ZTS6N","pid":1238,"":"io task","client":"2","":"downstairs","session_id":"0c5da301-5bfe-495b-ab00-bef6ee38a502"}
1722025-03-23T06:09:07.908Z{"msg":"connecting to 127.0.0.1:8810","v":0,"name":"crucible","level":30,"time":"2025-03-23T06:09:06.201971422Z","hostname":"w-01JQ0SETNSKZ27QMNBAK8ZTS6N","pid":1238,"":"io task","client":"0","":"downstairs","session_id":"0c5da301-5bfe-495b-ab00-bef6ee38a502"}
1732025-03-23T06:09:07.908Z{"msg":"connecting to 127.0.0.1:8820","v":0,"name":"crucible","level":30,"time":"2025-03-23T06:09:06.202013696Z","hostname":"w-01JQ0SETNSKZ27QMNBAK8ZTS6N","pid":1238,"":"io task","client":"1","":"downstairs","session_id":"0c5da301-5bfe-495b-ab00-bef6ee38a502"}
1742025-03-23T06:09:07.908Z{"msg":"ds_connection connected from Ok(127.0.0.1:36492)","v":0,"name":"crucible","level":30,"time":"2025-03-23T06:09:06.202037292Z","hostname":"w-01JQ0SETNSKZ27QMNBAK8ZTS6N","pid":1238,"":"io task","client":"2","":"downstairs","session_id":"0c5da301-5bfe-495b-ab00-bef6ee38a502"}
1752025-03-23T06:09:07.908Z{"msg":"ds_connection connected from Ok(127.0.0.1:53184)","v":0,"name":"crucible","level":30,"time":"2025-03-23T06:09:06.202062178Z","hostname":"w-01JQ0SETNSKZ27QMNBAK8ZTS6N","pid":1238,"":"io task","client":"0","":"downstairs","session_id":"0c5da301-5bfe-495b-ab00-bef6ee38a502"}
1762025-03-23T06:09:07.908Z{"msg":"ds_connection connected from Ok(127.0.0.1:42765)","v":0,"name":"crucible","level":30,"time":"2025-03-23T06:09:06.202077506Z","hostname":"w-01JQ0SETNSKZ27QMNBAK8ZTS6N","pid":1238,"":"io task","client":"1","":"downstairs","session_id":"0c5da301-5bfe-495b-ab00-bef6ee38a502"}
1772025-03-23T06:09:07.908Z{"msg":"version negotiation from state Connecting { state: WaitForPromote, mode: New }","v":0,"name":"crucible","level":30,"time":"2025-03-23T06:09:06.202465345Z","hostname":"w-01JQ0SETNSKZ27QMNBAK8ZTS6N","pid":1238,"client":"1","":"downstairs","session_id":"0c5da301-5bfe-495b-ab00-bef6ee38a502"}
1782025-03-23T06:09:07.908Z{"msg":"version negotiation from state Connecting { state: WaitForPromote, mode: New }","v":0,"name":"crucible","level":30,"time":"2025-03-23T06:09:06.202501139Z","hostname":"w-01JQ0SETNSKZ27QMNBAK8ZTS6N","pid":1238,"client":"2","":"downstairs","session_id":"0c5da301-5bfe-495b-ab00-bef6ee38a502"}
1792025-03-23T06:09:07.908Z{"msg":"version negotiation from state Connecting { state: WaitForPromote, mode: New }","v":0,"name":"crucible","level":30,"time":"2025-03-23T06:09:06.202517277Z","hostname":"w-01JQ0SETNSKZ27QMNBAK8ZTS6N","pid":1238,"client":"0","":"downstairs","session_id":"0c5da301-5bfe-495b-ab00-bef6ee38a502"}
1802025-03-23T06:09:07.908Z{"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-23T06:09:06.203112264Z","hostname":"w-01JQ0SETNSKZ27QMNBAK8ZTS6N","pid":1238,"client":"1","":"downstairs","session_id":"0c5da301-5bfe-495b-ab00-bef6ee38a502"}
1812025-03-23T06:09:07.908Z{"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-23T06:09:06.203155237Z","hostname":"w-01JQ0SETNSKZ27QMNBAK8ZTS6N","pid":1238,"client":"2","":"downstairs","session_id":"0c5da301-5bfe-495b-ab00-bef6ee38a502"}
1822025-03-23T06:09:07.908Z{"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-23T06:09:06.203254951Z","hostname":"w-01JQ0SETNSKZ27QMNBAK8ZTS6N","pid":1238,"client":"0","":"downstairs","session_id":"0c5da301-5bfe-495b-ab00-bef6ee38a502"}
1832025-03-23T06:09:07.914Z{"msg":"Waiting for more clients to be ready","v":0,"name":"crucible","level":30,"time":"2025-03-23T06:09:06.203571132Z","hostname":"w-01JQ0SETNSKZ27QMNBAK8ZTS6N","pid":1238,"session_id":"0c5da301-5bfe-495b-ab00-bef6ee38a502"}
1842025-03-23T06:09:07.914Z{"msg":"Waiting for more clients to be ready","v":0,"name":"crucible","level":30,"time":"2025-03-23T06:09:06.203613685Z","hostname":"w-01JQ0SETNSKZ27QMNBAK8ZTS6N","pid":1238,"session_id":"0c5da301-5bfe-495b-ab00-bef6ee38a502"}
1852025-03-23T06:09:07.914Z{"msg":"[0]R flush_numbers: [3995, 3995, 3995, 3995, 3995]","v":0,"name":"crucible","level":30,"time":"2025-03-23T06:09:06.203650389Z","hostname":"w-01JQ0SETNSKZ27QMNBAK8ZTS6N","pid":1238,"":"downstairs","":"downstairs","session_id":"0c5da301-5bfe-495b-ab00-bef6ee38a502"}
1862025-03-23T06:09:07.914Z{"msg":"[0]R generation: [25, 25, 25, 25, 25]","v":0,"name":"crucible","level":30,"time":"2025-03-23T06:09:06.203673246Z","hostname":"w-01JQ0SETNSKZ27QMNBAK8ZTS6N","pid":1238,"":"downstairs","":"downstairs","session_id":"0c5da301-5bfe-495b-ab00-bef6ee38a502"}
1872025-03-23T06:09:07.914Z{"msg":"[0]R dirty: [false, false, false, false, false]","v":0,"name":"crucible","level":30,"time":"2025-03-23T06:09:06.203687824Z","hostname":"w-01JQ0SETNSKZ27QMNBAK8ZTS6N","pid":1238,"":"downstairs","":"downstairs","session_id":"0c5da301-5bfe-495b-ab00-bef6ee38a502"}
1882025-03-23T06:09:07.914Z{"msg":"[1]R flush_numbers: [3995, 3995, 3995, 3995, 3995]","v":0,"name":"crucible","level":30,"time":"2025-03-23T06:09:06.203701732Z","hostname":"w-01JQ0SETNSKZ27QMNBAK8ZTS6N","pid":1238,"":"downstairs","":"downstairs","session_id":"0c5da301-5bfe-495b-ab00-bef6ee38a502"}
1892025-03-23T06:09:07.914Z{"msg":"[1]R generation: [25, 25, 25, 25, 25]","v":0,"name":"crucible","level":30,"time":"2025-03-23T06:09:06.203714479Z","hostname":"w-01JQ0SETNSKZ27QMNBAK8ZTS6N","pid":1238,"":"downstairs","":"downstairs","session_id":"0c5da301-5bfe-495b-ab00-bef6ee38a502"}
1902025-03-23T06:09:07.914Z{"msg":"[1]R dirty: [false, false, false, false, false]","v":0,"name":"crucible","level":30,"time":"2025-03-23T06:09:06.203727337Z","hostname":"w-01JQ0SETNSKZ27QMNBAK8ZTS6N","pid":1238,"":"downstairs","":"downstairs","session_id":"0c5da301-5bfe-495b-ab00-bef6ee38a502"}
1912025-03-23T06:09:07.914Z{"msg":"[2]R flush_numbers: [3995, 3995, 3995, 3995, 3995]","v":0,"name":"crucible","level":30,"time":"2025-03-23T06:09:06.203757643Z","hostname":"w-01JQ0SETNSKZ27QMNBAK8ZTS6N","pid":1238,"":"downstairs","":"downstairs","session_id":"0c5da301-5bfe-495b-ab00-bef6ee38a502"}
1922025-03-23T06:09:07.914Z{"msg":"[2]R generation: [25, 25, 25, 25, 25]","v":0,"name":"crucible","level":30,"time":"2025-03-23T06:09:06.20377406Z","hostname":"w-01JQ0SETNSKZ27QMNBAK8ZTS6N","pid":1238,"":"downstairs","":"downstairs","session_id":"0c5da301-5bfe-495b-ab00-bef6ee38a502"}
1932025-03-23T06:09:07.914Z{"msg":"[2]R dirty: [false, false, false, false, false]","v":0,"name":"crucible","level":30,"time":"2025-03-23T06:09:06.203797317Z","hostname":"w-01JQ0SETNSKZ27QMNBAK8ZTS6N","pid":1238,"":"downstairs","":"downstairs","session_id":"0c5da301-5bfe-495b-ab00-bef6ee38a502"}
1942025-03-23T06:09:07.914Z{"msg":"Max found gen is 26","v":0,"name":"crucible","level":30,"time":"2025-03-23T06:09:06.203811814Z","hostname":"w-01JQ0SETNSKZ27QMNBAK8ZTS6N","pid":1238,"":"downstairs","":"downstairs","session_id":"0c5da301-5bfe-495b-ab00-bef6ee38a502"}
1952025-03-23T06:09:07.914Z{"msg":"Generation requested: 31 >= found:26","v":0,"name":"crucible","level":30,"time":"2025-03-23T06:09:06.203832491Z","hostname":"w-01JQ0SETNSKZ27QMNBAK8ZTS6N","pid":1238,"":"downstairs","":"downstairs","session_id":"0c5da301-5bfe-495b-ab00-bef6ee38a502"}
1962025-03-23T06:09:07.914Z{"msg":"Next flush: 3996","v":0,"name":"crucible","level":30,"time":"2025-03-23T06:09:06.203845689Z","hostname":"w-01JQ0SETNSKZ27QMNBAK8ZTS6N","pid":1238,"":"downstairs","":"downstairs","session_id":"0c5da301-5bfe-495b-ab00-bef6ee38a502"}
1972025-03-23T06:09:07.914Z{"msg":"All extents match","v":0,"name":"crucible","level":30,"time":"2025-03-23T06:09:06.203865886Z","hostname":"w-01JQ0SETNSKZ27QMNBAK8ZTS6N","pid":1238,"":"downstairs","":"downstairs","session_id":"0c5da301-5bfe-495b-ab00-bef6ee38a502"}
1982025-03-23T06:09:07.914Z{"msg":"No downstairs reconciliation required","v":0,"name":"crucible","level":30,"time":"2025-03-23T06:09:06.203879454Z","hostname":"w-01JQ0SETNSKZ27QMNBAK8ZTS6N","pid":1238,"session_id":"0c5da301-5bfe-495b-ab00-bef6ee38a502"}
1992025-03-23T06:09:07.914Z{"msg":"Transition from WaitQuorum to Active","v":0,"name":"crucible","level":30,"time":"2025-03-23T06:09:06.203908129Z","hostname":"w-01JQ0SETNSKZ27QMNBAK8ZTS6N","pid":1238,"client":"0","":"downstairs","session_id":"0c5da301-5bfe-495b-ab00-bef6ee38a502"}
2002025-03-23T06:09:07.914Z{"msg":"Transition from WaitQuorum to Active","v":0,"name":"crucible","level":30,"time":"2025-03-23T06:09:06.203927976Z","hostname":"w-01JQ0SETNSKZ27QMNBAK8ZTS6N","pid":1238,"client":"1","":"downstairs","session_id":"0c5da301-5bfe-495b-ab00-bef6ee38a502"}
2012025-03-23T06:09:07.914Z{"msg":"Transition from WaitQuorum to Active","v":0,"name":"crucible","level":30,"time":"2025-03-23T06:09:06.20397017Z","hostname":"w-01JQ0SETNSKZ27QMNBAK8ZTS6N","pid":1238,"client":"2","":"downstairs","session_id":"0c5da301-5bfe-495b-ab00-bef6ee38a502"}
2022025-03-23T06:09:07.914Z{"msg":"All required reconciliation work is completed","v":0,"name":"crucible","level":30,"time":"2025-03-23T06:09:06.203994866Z","hostname":"w-01JQ0SETNSKZ27QMNBAK8ZTS6N","pid":1238,"session_id":"0c5da301-5bfe-495b-ab00-bef6ee38a502"}
2032025-03-23T06:09:07.914Z{"msg":"Set Downstairs and Upstairs active after reconciliation","v":0,"name":"crucible","level":30,"time":"2025-03-23T06:09:06.204036349Z","hostname":"w-01JQ0SETNSKZ27QMNBAK8ZTS6N","pid":1238,"session_id":"0c5da301-5bfe-495b-ab00-bef6ee38a502"}
2042025-03-23T06:09:07.914Z{"msg":"78c2d3fe-cf8a-4389-891d-df623ed8389c is now active with session: 0c5da301-5bfe-495b-ab00-bef6ee38a502","v":0,"name":"crucible","level":30,"time":"2025-03-23T06:09:06.204075323Z","hostname":"w-01JQ0SETNSKZ27QMNBAK8ZTS6N","pid":1238,"session_id":"0c5da301-5bfe-495b-ab00-bef6ee38a502"}
2052025-03-23T06:09:07.914Z{"msg":"Set Active after no reconciliation","v":0,"name":"crucible","level":30,"time":"2025-03-23T06:09:06.204102669Z","hostname":"w-01JQ0SETNSKZ27QMNBAK8ZTS6N","pid":1238,"session_id":"0c5da301-5bfe-495b-ab00-bef6ee38a502"}
2062025-03-23T06:09:07.914Z{"msg":"The guest has finished waiting for activation with:31","v":0,"name":"crucible","level":30,"time":"2025-03-23T06:09:06.204298648Z","hostname":"w-01JQ0SETNSKZ27QMNBAK8ZTS6N","pid":1238}
2072025-03-23T06:09:07.914Z{"msg":"Activated sub_volume 78c2d3fe-cf8a-4389-891d-df623ed8389c","v":0,"name":"crucible","level":30,"time":"2025-03-23T06:09:06.204324814Z","hostname":"w-01JQ0SETNSKZ27QMNBAK8ZTS6N","pid":1238}
2082025-03-23T06:09:07.914Z{"msg":"The guest has requested activation with gen:31","v":0,"name":"crucible","level":30,"time":"2025-03-23T06:09:06.204358219Z","hostname":"w-01JQ0SETNSKZ27QMNBAK8ZTS6N","pid":1238}
2092025-03-23T06:09:07.914Z{"msg":"78c2d3fe-cf8a-4389-891d-df623ed8389c active request set","v":0,"name":"crucible","level":30,"time":"2025-03-23T06:09:06.204396613Z","hostname":"w-01JQ0SETNSKZ27QMNBAK8ZTS6N","pid":1238,"session_id":"ab6a02da-3b45-4329-820c-88ddb5fb293a"}
2102025-03-23T06:09:07.914Z{"msg":"sending connect oneshot to client","v":0,"name":"crucible","level":30,"time":"2025-03-23T06:09:06.204435897Z","hostname":"w-01JQ0SETNSKZ27QMNBAK8ZTS6N","pid":1238,"client":"0","":"downstairs","session_id":"ab6a02da-3b45-4329-820c-88ddb5fb293a"}
2112025-03-23T06:09:07.914Z{"msg":"client set_active_request while in Connecting { state: Start { auto_promote: true }, mode: New }; waiting...","v":0,"name":"crucible","level":30,"time":"2025-03-23T06:09:06.204518524Z","hostname":"w-01JQ0SETNSKZ27QMNBAK8ZTS6N","pid":1238,"client":"0","":"downstairs","session_id":"ab6a02da-3b45-4329-820c-88ddb5fb293a"}
2122025-03-23T06:09:07.914Z{"msg":"sending connect oneshot to client","v":0,"name":"crucible","level":30,"time":"2025-03-23T06:09:06.204572665Z","hostname":"w-01JQ0SETNSKZ27QMNBAK8ZTS6N","pid":1238,"client":"1","":"downstairs","session_id":"ab6a02da-3b45-4329-820c-88ddb5fb293a"}
2132025-03-23T06:09:07.914Z{"msg":"client set_active_request while in Connecting { state: Start { auto_promote: true }, mode: New }; waiting...","v":0,"name":"crucible","level":30,"time":"2025-03-23T06:09:06.204602571Z","hostname":"w-01JQ0SETNSKZ27QMNBAK8ZTS6N","pid":1238,"client":"1","":"downstairs","session_id":"ab6a02da-3b45-4329-820c-88ddb5fb293a"}
2142025-03-23T06:09:07.914Z{"msg":"sending connect oneshot to client","v":0,"name":"crucible","level":30,"time":"2025-03-23T06:09:06.204644434Z","hostname":"w-01JQ0SETNSKZ27QMNBAK8ZTS6N","pid":1238,"client":"2","":"downstairs","session_id":"ab6a02da-3b45-4329-820c-88ddb5fb293a"}
2152025-03-23T06:09:07.914Z{"msg":"client set_active_request while in Connecting { state: Start { auto_promote: true }, mode: New }; waiting...","v":0,"name":"crucible","level":30,"time":"2025-03-23T06:09:06.204701775Z","hostname":"w-01JQ0SETNSKZ27QMNBAK8ZTS6N","pid":1238,"client":"2","":"downstairs","session_id":"ab6a02da-3b45-4329-820c-88ddb5fb293a"}
2162025-03-23T06:09:07.914Z{"msg":"connecting to 127.0.0.1:8860","v":0,"name":"crucible","level":30,"time":"2025-03-23T06:09:06.2047364Z","hostname":"w-01JQ0SETNSKZ27QMNBAK8ZTS6N","pid":1238,"":"io task","client":"2","":"downstairs","session_id":"ab6a02da-3b45-4329-820c-88ddb5fb293a"}
2172025-03-23T06:09:07.914Z{"msg":"connecting to 127.0.0.1:8840","v":0,"name":"crucible","level":30,"time":"2025-03-23T06:09:06.204787512Z","hostname":"w-01JQ0SETNSKZ27QMNBAK8ZTS6N","pid":1238,"":"io task","client":"0","":"downstairs","session_id":"ab6a02da-3b45-4329-820c-88ddb5fb293a"}
2182025-03-23T06:09:07.914Z{"msg":"connecting to 127.0.0.1:8850","v":0,"name":"crucible","level":30,"time":"2025-03-23T06:09:06.204819097Z","hostname":"w-01JQ0SETNSKZ27QMNBAK8ZTS6N","pid":1238,"":"io task","client":"1","":"downstairs","session_id":"ab6a02da-3b45-4329-820c-88ddb5fb293a"}
2192025-03-23T06:09:07.914Z{"msg":"ds_connection connected from Ok(127.0.0.1:57177)","v":0,"name":"crucible","level":30,"time":"2025-03-23T06:09:06.204857971Z","hostname":"w-01JQ0SETNSKZ27QMNBAK8ZTS6N","pid":1238,"":"io task","client":"2","":"downstairs","session_id":"ab6a02da-3b45-4329-820c-88ddb5fb293a"}
2202025-03-23T06:09:07.914Z{"msg":"ds_connection connected from Ok(127.0.0.1:41033)","v":0,"name":"crucible","level":30,"time":"2025-03-23T06:09:06.204887576Z","hostname":"w-01JQ0SETNSKZ27QMNBAK8ZTS6N","pid":1238,"":"io task","client":"1","":"downstairs","session_id":"ab6a02da-3b45-4329-820c-88ddb5fb293a"}
2212025-03-23T06:09:07.915Z{"msg":"ds_connection connected from Ok(127.0.0.1:45546)","v":0,"name":"crucible","level":30,"time":"2025-03-23T06:09:06.20492415Z","hostname":"w-01JQ0SETNSKZ27QMNBAK8ZTS6N","pid":1238,"":"io task","client":"0","":"downstairs","session_id":"ab6a02da-3b45-4329-820c-88ddb5fb293a"}
2222025-03-23T06:09:07.915Z{"msg":"version negotiation from state Connecting { state: WaitForPromote, mode: New }","v":0,"name":"crucible","level":30,"time":"2025-03-23T06:09:06.204953116Z","hostname":"w-01JQ0SETNSKZ27QMNBAK8ZTS6N","pid":1238,"client":"2","":"downstairs","session_id":"ab6a02da-3b45-4329-820c-88ddb5fb293a"}
2232025-03-23T06:09:07.915Z{"msg":"version negotiation from state Connecting { state: WaitForPromote, mode: New }","v":0,"name":"crucible","level":30,"time":"2025-03-23T06:09:06.204981011Z","hostname":"w-01JQ0SETNSKZ27QMNBAK8ZTS6N","pid":1238,"client":"1","":"downstairs","session_id":"ab6a02da-3b45-4329-820c-88ddb5fb293a"}
2242025-03-23T06:09:07.915Z{"msg":"version negotiation from state Connecting { state: WaitForPromote, mode: New }","v":0,"name":"crucible","level":30,"time":"2025-03-23T06:09:06.20505285Z","hostname":"w-01JQ0SETNSKZ27QMNBAK8ZTS6N","pid":1238,"client":"0","":"downstairs","session_id":"ab6a02da-3b45-4329-820c-88ddb5fb293a"}
2252025-03-23T06:09:07.915Z{"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-23T06:09:06.205241431Z","hostname":"w-01JQ0SETNSKZ27QMNBAK8ZTS6N","pid":1238,"client":"2","":"downstairs","session_id":"ab6a02da-3b45-4329-820c-88ddb5fb293a"}
2262025-03-23T06:09:07.915Z{"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-23T06:09:06.205291353Z","hostname":"w-01JQ0SETNSKZ27QMNBAK8ZTS6N","pid":1238,"client":"1","":"downstairs","session_id":"ab6a02da-3b45-4329-820c-88ddb5fb293a"}
2272025-03-23T06:09:07.915Z{"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-23T06:09:06.20543369Z","hostname":"w-01JQ0SETNSKZ27QMNBAK8ZTS6N","pid":1238,"client":"0","":"downstairs","session_id":"ab6a02da-3b45-4329-820c-88ddb5fb293a"}
2282025-03-23T06:09:07.915Z{"msg":"Waiting for more clients to be ready","v":0,"name":"crucible","level":30,"time":"2025-03-23T06:09:06.205579158Z","hostname":"w-01JQ0SETNSKZ27QMNBAK8ZTS6N","pid":1238,"session_id":"ab6a02da-3b45-4329-820c-88ddb5fb293a"}
2292025-03-23T06:09:07.915Z{"msg":"Waiting for more clients to be ready","v":0,"name":"crucible","level":30,"time":"2025-03-23T06:09:06.205687491Z","hostname":"w-01JQ0SETNSKZ27QMNBAK8ZTS6N","pid":1238,"session_id":"ab6a02da-3b45-4329-820c-88ddb5fb293a"}
2302025-03-23T06:09:07.915Z{"msg":"[0]R flush_numbers: [5316, 5316, 5316, 5315, 5310]","v":0,"name":"crucible","level":30,"time":"2025-03-23T06:09:06.205779956Z","hostname":"w-01JQ0SETNSKZ27QMNBAK8ZTS6N","pid":1238,"":"downstairs","":"downstairs","session_id":"ab6a02da-3b45-4329-820c-88ddb5fb293a"}
2312025-03-23T06:09:07.915Z{"msg":"[0]R generation: [14, 14, 14, 13, 12]","v":0,"name":"crucible","level":30,"time":"2025-03-23T06:09:06.205816701Z","hostname":"w-01JQ0SETNSKZ27QMNBAK8ZTS6N","pid":1238,"":"downstairs","":"downstairs","session_id":"ab6a02da-3b45-4329-820c-88ddb5fb293a"}
2322025-03-23T06:09:07.915Z{"msg":"[0]R dirty: [false, false, false, false, false]","v":0,"name":"crucible","level":30,"time":"2025-03-23T06:09:06.205833048Z","hostname":"w-01JQ0SETNSKZ27QMNBAK8ZTS6N","pid":1238,"":"downstairs","":"downstairs","session_id":"ab6a02da-3b45-4329-820c-88ddb5fb293a"}
2332025-03-23T06:09:07.915Z{"msg":"[1]R flush_numbers: [5316, 5316, 5316, 5315, 5310]","v":0,"name":"crucible","level":30,"time":"2025-03-23T06:09:06.205854445Z","hostname":"w-01JQ0SETNSKZ27QMNBAK8ZTS6N","pid":1238,"":"downstairs","":"downstairs","session_id":"ab6a02da-3b45-4329-820c-88ddb5fb293a"}
2342025-03-23T06:09:07.915Z{"msg":"[1]R generation: [14, 14, 14, 13, 12]","v":0,"name":"crucible","level":30,"time":"2025-03-23T06:09:06.205868013Z","hostname":"w-01JQ0SETNSKZ27QMNBAK8ZTS6N","pid":1238,"":"downstairs","":"downstairs","session_id":"ab6a02da-3b45-4329-820c-88ddb5fb293a"}
2352025-03-23T06:09:07.915Z{"msg":"[1]R dirty: [false, false, false, false, false]","v":0,"name":"crucible","level":30,"time":"2025-03-23T06:09:06.205888929Z","hostname":"w-01JQ0SETNSKZ27QMNBAK8ZTS6N","pid":1238,"":"downstairs","":"downstairs","session_id":"ab6a02da-3b45-4329-820c-88ddb5fb293a"}
2362025-03-23T06:09:07.915Z{"msg":"[2]R flush_numbers: [5316, 5316, 5316, 5315, 5310]","v":0,"name":"crucible","level":30,"time":"2025-03-23T06:09:06.205902847Z","hostname":"w-01JQ0SETNSKZ27QMNBAK8ZTS6N","pid":1238,"":"downstairs","":"downstairs","session_id":"ab6a02da-3b45-4329-820c-88ddb5fb293a"}
2372025-03-23T06:09:07.915Z{"msg":"[2]R generation: [14, 14, 14, 13, 12]","v":0,"name":"crucible","level":30,"time":"2025-03-23T06:09:06.205923424Z","hostname":"w-01JQ0SETNSKZ27QMNBAK8ZTS6N","pid":1238,"":"downstairs","":"downstairs","session_id":"ab6a02da-3b45-4329-820c-88ddb5fb293a"}
2382025-03-23T06:09:07.915Z{"msg":"[2]R dirty: [false, false, false, false, false]","v":0,"name":"crucible","level":30,"time":"2025-03-23T06:09:06.205937462Z","hostname":"w-01JQ0SETNSKZ27QMNBAK8ZTS6N","pid":1238,"":"downstairs","":"downstairs","session_id":"ab6a02da-3b45-4329-820c-88ddb5fb293a"}
2392025-03-23T06:09:07.915Z{"msg":"Max found gen is 15","v":0,"name":"crucible","level":30,"time":"2025-03-23T06:09:06.205958748Z","hostname":"w-01JQ0SETNSKZ27QMNBAK8ZTS6N","pid":1238,"":"downstairs","":"downstairs","session_id":"ab6a02da-3b45-4329-820c-88ddb5fb293a"}
2402025-03-23T06:09:07.915Z{"msg":"Generation requested: 31 >= found:15","v":0,"name":"crucible","level":30,"time":"2025-03-23T06:09:06.205972036Z","hostname":"w-01JQ0SETNSKZ27QMNBAK8ZTS6N","pid":1238,"":"downstairs","":"downstairs","session_id":"ab6a02da-3b45-4329-820c-88ddb5fb293a"}
2412025-03-23T06:09:07.915Z{"msg":"Next flush: 5317","v":0,"name":"crucible","level":30,"time":"2025-03-23T06:09:06.205984444Z","hostname":"w-01JQ0SETNSKZ27QMNBAK8ZTS6N","pid":1238,"":"downstairs","":"downstairs","session_id":"ab6a02da-3b45-4329-820c-88ddb5fb293a"}
2422025-03-23T06:09:07.915Z{"msg":"All extents match","v":0,"name":"crucible","level":30,"time":"2025-03-23T06:09:06.205997862Z","hostname":"w-01JQ0SETNSKZ27QMNBAK8ZTS6N","pid":1238,"":"downstairs","":"downstairs","session_id":"ab6a02da-3b45-4329-820c-88ddb5fb293a"}
2432025-03-23T06:09:07.915Z{"msg":"No downstairs reconciliation required","v":0,"name":"crucible","level":30Wait for a query_work_queue command to finish before sending IO
2442025-03-23T06:09:07.915Z,"time":"2025-03-23T06:09:06.20601083Z","hostname":"w-01JQ0SETNSKZ27QMNBAK8ZTS6N","pid":1238,"session_id":"ab6a02da-3b45-4329-820c-88ddb5fb293a"}
2452025-03-23T06:09:07.915Z{"msg":"Transition from WaitQuorum to Active","v":0,"name":"crucible","level":30,"time":"2025-03-23T06:09:06.206027308Z","hostname":"w-01JQ0SETNSKZ27QMNBAK8ZTS6N","pid":1238,"client":"0","":"downstairs","session_id":"ab6a02da-3b45-4329-820c-88ddb5fb293a"}
2462025-03-23T06:09:07.915Z{"msg":"Transition from WaitQuorum to Active","v":0,"name":"crucible","level":30,"time":"2025-03-23T06:09:06.206040206Z","hostname":"w-01JQ0SETNSKZ27QMNBAK8ZTS6N","pid":1238,"client":"1","":"downstairs","session_id":"ab6a02da-3b45-4329-820c-88ddb5fb293a"}
2472025-03-23T06:09:07.915Z{"msg":"Transition from WaitQuorum to Active","v":0,"name":"crucible","level":30,"time":"2025-03-23T06:09:06.206060832Z","hostname":"w-01JQ0SETNSKZ27QMNBAK8ZTS6N","pid":1238,"client":"2","":"downstairs","session_id":"ab6a02da-3b45-4329-820c-88ddb5fb293a"}
2482025-03-23T06:09:07.915Z{"msg":"All required reconciliation work is completed","v":0,"name":"crucible","level":30,"time":"2025-03-23T06:09:06.20607497Z","hostname":"w-01JQ0SETNSKZ27QMNBAK8ZTS6N","pid":1238,"session_id":"ab6a02da-3b45-4329-820c-88ddb5fb293a"}
2492025-03-23T06:09:07.915Z{"msg":"Set Downstairs and Upstairs active after reconciliation","v":0,"name":"crucible","level":30,"time":"2025-03-23T06:09:06.206087458Z","hostname":"w-01JQ0SETNSKZ27QMNBAK8ZTS6N","pid":1238,"session_id":"ab6a02da-3b45-4329-820c-88ddb5fb293a"}
2502025-03-23T06:09:07.915Z{"msg":"78c2d3fe-cf8a-4389-891d-df623ed8389c is now active with session: ab6a02da-3b45-4329-820c-88ddb5fb293a","v":0,"name":"crucible","level":30,"time":"2025-03-23T06:09:06.206100036Z","hostname":"w-01JQ0SETNSKZ27QMNBAK8ZTS6N","pid":1238,"session_id":"ab6a02da-3b45-4329-820c-88ddb5fb293a"}
2512025-03-23T06:09:07.915Z{"msg":"Set Active after no reconciliation","v":0,"name":"crucible","level":30,"time":"2025-03-23T06:09:06.206124822Z","hostname":"w-01JQ0SETNSKZ27QMNBAK8ZTS6N","pid":1238,"session_id":"ab6a02da-3b45-4329-820c-88ddb5fb293a"}
2522025-03-23T06:09:07.915Z{"msg":"The guest has finished waiting for activation with:31","v":0,"name":"crucible","level":30,"time":"2025-03-23T06:09:06.206137071Z","hostname":"w-01JQ0SETNSKZ27QMNBAK8ZTS6N","pid":1238}
2532025-03-23T06:09:07.915Z{"msg":"Activated sub_volume 78c2d3fe-cf8a-4389-891d-df623ed8389c","v":0,"name":"crucible","level":30,"time":"2025-03-23T06:09:06.206149549Z","hostname":"w-01JQ0SETNSKZ27QMNBAK8ZTS6N","pid":1238}
2542025-03-23T06:09:07.915ZDisk: sv:2 bs:4096 ts:409600 tb:100 max_io:100 or 409600
2552025-03-23T06:09:07.915ZFill test
2562025-03-23T06:09:07.954ZRead and Verify all blocks (0..100 range:false)
2572025-03-23T06:09:08.032ZWrote out file "/var/tmp/test_up-build/verify_file"
2582025-03-23T06:09:08.032ZCLIENT: Tests done. All submitted work has been ACK'd
2592025-03-23T06:09:08.036Z----------------------------------------------------------------
2602025-03-23T06:09:08.036Z Crucible gen:31 GIO:true work queues: Upstairs:0 downstairs:1
2612025-03-23T06:09:08.036ZStates: Active Active Active
2622025-03-23T06:09:08.036ZJOBID ACK TYPE BKS/EXT DS:0 DS:1 DS:2 REPLAY
2632025-03-23T06:09:08.036Z 1002 Acked Read 50 Done Done Done false
2642025-03-23T06:09:08.036Z STATES DS:0 DS:1 DS:2 TOTAL
2652025-03-23T06:09:08.036Z Sent 0 0 0 0
2662025-03-23T06:09:08.036Z Done 1 1 1 3
2672025-03-23T06:09:08.036Z Skipped 0 0 0 0
2682025-03-23T06:09:08.036Z Error 0 0 0 0
2692025-03-23T06:09:08.036ZLast Flush: Some(JobId(1001)) Some(JobId(1001)) Some(JobId(1001))
2702025-03-23T06:09:08.036ZDownstairs last five completed: 1001 1000
2712025-03-23T06:09:08.036ZUpstairs last five completed: 1002 1001 1000
2722025-03-23T06:09:08.036Z----------------------------------------------------------------
2732025-03-23T06:09:08.036Z Crucible gen:31 GIO:true work queues: Upstairs:0 downstairs:1
2742025-03-23T06:09:08.036ZStates: Active Active Active
2752025-03-23T06:09:08.036ZJOBID ACK TYPE BKS/EXT DS:0 DS:1 DS:2 REPLAY
2762025-03-23T06:09:08.036Z 1002 Acked Read 50 Done Done Done false
2772025-03-23T06:09:08.036Z STATES DS:0 DS:1 DS:2 TOTAL
2782025-03-23T06:09:08.036Z Sent 0 0 0 0
2792025-03-23T06:09:08.036Z Done 1 1 1 3
2802025-03-23T06:09:08.036Z Skipped 0 0 0 0
2812025-03-23T06:09:08.036Z Error 0 0 0 0
2822025-03-23T06:09:08.036ZLast Flush: Some(JobId(1001)) Some(JobId(1001)) Some(JobId(1001))
2832025-03-23T06:09:08.036ZDownstairs last five completed: 1001 1000
2842025-03-23T06:09:08.036ZUpstairs last five completed: 1002 1001 1000
2852025-03-23T06:09:08.036ZCLIENT: Up:0 ds:2 act:6
2862025-03-23T06:09:12.035Z----------------------------------------------------------------
2872025-03-23T06:09:12.035Z Crucible gen:31 GIO:true work queues: Upstairs:0 downstairs:0
2882025-03-23T06:09:12.035ZDownstairs last five completed: 1003 1002 1001 1000
2892025-03-23T06:09:12.035ZUpstairs last five completed: 1003 1002 1001 1000
2902025-03-23T06:09:12.039Z----------------------------------------------------------------
2912025-03-23T06:09:12.039Z Crucible gen:31 GIO:true work queues: Upstairs:0 downstairs:0
2922025-03-23T06:09:12.039ZDownstairs last five completed: 1003 1002 1001 1000
2932025-03-23T06:09:12.039ZUpstairs last five completed: 1003 1002 1001 1000
2942025-03-23T06:09:12.039ZCLIENT: Up:0 ds:0 act:6
2952025-03-23T06:09:12.039ZCLIENT: All crucible jobs finished, exiting program
2962025-03-23T06:09:12.039Z{"msg":"Guest handle has been dropped","v":0,"name":"crucible","level":40,"time":"2025-03-23T06:09:10.33056978Z","hostname":"w-01JQ0SETNSKZ27QMNBAK8ZTS6N","pid":1238}
2972025-03-23T06:09:12.046ZRepair setup passed
2982025-03-23T06:09:12.050ZCopy the region for /var/tmp/test_up-build/8830
2992025-03-23T06:09:12.053Zcp -r /var/tmp/test_up-build/8830 /var/tmp/test_up-build/previous
3002025-03-23T06:09:12.056Z/var/tmp/bins/crutest fill -g 32 -q --key Dt8v/c59Kokn019xjOMnOkX3zbETL5mD7zrCLjwHGnM= --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-23T06:09:12.111Z{"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-23T06:09:10.405669935Z","hostname":"w-01JQ0SETNSKZ27QMNBAK8ZTS6N","pid":1244,"task":"crutest"}
3022025-03-23T06:09:12.114Z{"msg":"dsc has 6 regions. This means 2 sub_volumes","v":0,"name":"crucible","level":30,"time":"2025-03-23T06:09:10.406209001Z","hostname":"w-01JQ0SETNSKZ27QMNBAK8ZTS6N","pid":1244,"task":"crutest"}
3032025-03-23T06:09:12.114Z{"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-23T06:09:10.40793875Z","hostname":"w-01JQ0SETNSKZ27QMNBAK8ZTS6N","pid":1244,"task":"crutest"}
3042025-03-23T06:09:12.114Z{"msg":"Upstairs starts","v":0,"name":"crucible","level":30,"time":"2025-03-23T06:09:10.408149077Z","hostname":"w-01JQ0SETNSKZ27QMNBAK8ZTS6N","pid":1244}
3052025-03-23T06:09:12.114Z{"msg":"Crucible Version: BuildInfo {\n version: \"0.0.1\",\n git_sha: \"a0baefa8a6d4c0e5f0d4f746f2af5de9c08b52b6\",\n git_commit_timestamp: \"2025-03-23T05:46:50.000000000Z\",\n git_branch: \"renovate/rust-1.x\",\n rustc_semver: \"1.85.1\",\n rustc_channel: \"stable\",\n rustc_host_triple: \"x86_64-unknown-illumos\",\n rustc_commit_sha: \"4eb161250e340c8f48f66e2b929ef4a5bed7c181\",\n cargo_triple: \"x86_64-unknown-illumos\",\n debug: true,\n opt_level: 0,\n}","v":0,"name":"crucible","level":30,"time":"2025-03-23T06:09:10.40819911Z","hostname":"w-01JQ0SETNSKZ27QMNBAK8ZTS6N","pid":1244}
3062025-03-23T06:09:12.114Z{"msg":"Upstairs <-> Downstairs Message Version: 13","v":0,"name":"crucible","level":30,"time":"2025-03-23T06:09:10.408231065Z","hostname":"w-01JQ0SETNSKZ27QMNBAK8ZTS6N","pid":1244}
3072025-03-23T06:09:12.114Z{"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-23T06:09:10.408252621Z","hostname":"w-01JQ0SETNSKZ27QMNBAK8ZTS6N","pid":1244}
3082025-03-23T06:09:12.114Z{"msg":"Crucible 4c4289d8-ea7a-42ad-b730-a699d4044f1c has session id: 07e562bd-a107-48db-bf82-3fa9dcb05aa2","v":0,"name":"crucible","level":30,"time":"2025-03-23T06:09:10.408844809Z","hostname":"w-01JQ0SETNSKZ27QMNBAK8ZTS6N","pid":1244,"session_id":"07e562bd-a107-48db-bf82-3fa9dcb05aa2"}
3092025-03-23T06:09:12.114Z{"msg":"Upstairs opts: Upstairs UUID: 4c4289d8-ea7a-42ad-b730-a699d4044f1c, 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-23T06:09:10.40889914Z","hostname":"w-01JQ0SETNSKZ27QMNBAK8ZTS6N","pid":1244,"session_id":"07e562bd-a107-48db-bf82-3fa9dcb05aa2"}
3102025-03-23T06:09:12.114Z{"msg":"Crucible stats registered with UUID: 4c4289d8-ea7a-42ad-b730-a699d4044f1c","v":0,"name":"crucible","level":30,"time":"2025-03-23T06:09:10.408923566Z","hostname":"w-01JQ0SETNSKZ27QMNBAK8ZTS6N","pid":1244,"session_id":"07e562bd-a107-48db-bf82-3fa9dcb05aa2"}
3112025-03-23T06:09:12.114Z{"msg":"could not find Downstairs address for Nexus","v":0,"name":"crucible","level":40,"time":"2025-03-23T06:09:10.40896121Z","hostname":"w-01JQ0SETNSKZ27QMNBAK8ZTS6N","pid":1244,"session_id":"07e562bd-a107-48db-bf82-3fa9dcb05aa2"}
3122025-03-23T06:09:12.118Z{"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-23T06:09:10.410979645Z","hostname":"w-01JQ0SETNSKZ27QMNBAK8ZTS6N","pid":1244,"task":"crutest"}
3132025-03-23T06:09:12.118Z{"msg":"Upstairs starts","v":0,"name":"crucible","level":30,"time":"2025-03-23T06:09:10.411040615Z","hostname":"w-01JQ0SETNSKZ27QMNBAK8ZTS6N","pid":1244}
3142025-03-23T06:09:12.118Z{"msg":"Crucible Version: BuildInfo {\n version: \"0.0.1\",\n git_sha: \"a0baefa8a6d4c0e5f0d4f746f2af5de9c08b52b6\",\n git_commit_timestamp: \"2025-03-23T05:46:50.000000000Z\",\n git_branch: \"renovate/rust-1.x\",\n rustc_semver: \"1.85.1\",\n rustc_channel: \"stable\",\n rustc_host_triple: \"x86_64-unknown-illumos\",\n rustc_commit_sha: \"4eb161250e340c8f48f66e2b929ef4a5bed7c181\",\n cargo_triple: \"x86_64-unknown-illumos\",\n debug: true,\n opt_level: 0,\n}","v":0,"name":"crucible","level":30,"time":"2025-03-23T06:09:10.411065461Z","hostname":"w-01JQ0SETNSKZ27QMNBAK8ZTS6N","pid":1244}
3152025-03-23T06:09:12.118Z{"msg":"Upstairs <-> Downstairs Message Version: 13","v":0,"name":"crucible","level":30,"time":"2025-03-23T06:09:10.411086188Z","hostname":"w-01JQ0SETNSKZ27QMNBAK8ZTS6N","pid":1244}
3162025-03-23T06:09:12.118Z{"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-23T06:09:10.411101386Z","hostname":"w-01JQ0SETNSKZ27QMNBAK8ZTS6N","pid":1244}
3172025-03-23T06:09:12.118Z{"msg":"Crucible 4c4289d8-ea7a-42ad-b730-a699d4044f1c has session id: 0d092605-a860-4c29-8c98-27e196aaec1f","v":0,"name":"crucible","level":30,"time":"2025-03-23T06:09:10.411526929Z","hostname":"w-01JQ0SETNSKZ27QMNBAK8ZTS6N","pid":1244,"session_id":"0d092605-a860-4c29-8c98-27e196aaec1f"}
3182025-03-23T06:09:12.118Z{"msg":"Upstairs opts: Upstairs UUID: 4c4289d8-ea7a-42ad-b730-a699d4044f1c, 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-23T06:09:10.411573352Z","hostname":"w-01JQ0SETNSKZ27QMNBAK8ZTS6N","pid":1244,"session_id":"0d092605-a860-4c29-8c98-27e196aaec1f"}
3192025-03-23T06:09:12.118Z{"msg":"Crucible stats registered with UUID: 4c4289d8-ea7a-42ad-b730-a699d4044f1c","v":0,"name":"crucible","level":30,"time":"2025-03-23T06:09:10.411599488Z","hostname":"w-01JQ0SETNSKZ27QMNBAK8ZTS6N","pid":1244,"session_id":"0d092605-a860-4c29-8c98-27e196aaec1f"}
3202025-03-23T06:09:12.118Z{"msg":"could not find Downstairs address for Nexus","v":0,"name":"crucible","level":40,"time":"2025-03-23T06:09:10.411621834Z","hostname":"w-01JQ0SETNSKZ27QMNBAK8ZTS6N","pid":1244,"session_id":"0d092605-a860-4c29-8c98-27e196aaec1f"}
3212025-03-23T06:09:12.118Z{"msg":"Downstairs in volume = 6","v":0,"name":"crucible","level":30,"time":"2025-03-23T06:09:10.412189716Z","hostname":"w-01JQ0SETNSKZ27QMNBAK8ZTS6N","pid":1244,"task":"crutest"}
3222025-03-23T06:09:12.118Z{"msg":"The guest has requested activation with gen:32","v":0,"name":"crucible","level":30,"time":"2025-03-23T06:09:10.41229022Z","hostname":"w-01JQ0SETNSKZ27QMNBAK8ZTS6N","pid":1244}
3232025-03-23T06:09:12.118Z{"msg":"4c4289d8-ea7a-42ad-b730-a699d4044f1c active request set","v":0,"name":"crucible","level":30,"time":"2025-03-23T06:09:10.412323895Z","hostname":"w-01JQ0SETNSKZ27QMNBAK8ZTS6N","pid":1244,"session_id":"07e562bd-a107-48db-bf82-3fa9dcb05aa2"}
3242025-03-23T06:09:12.118Z{"msg":"sending connect oneshot to client","v":0,"name":"crucible","level":30,"time":"2025-03-23T06:09:10.412339542Z","hostname":"w-01JQ0SETNSKZ27QMNBAK8ZTS6N","pid":1244,"client":"0","":"downstairs","session_id":"07e562bd-a107-48db-bf82-3fa9dcb05aa2"}
3252025-03-23T06:09:12.118Z{"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-23T06:09:10.412386085Z","hostname":"w-01JQ0SETNSKZ27QMNBAK8ZTS6N","pid":1244,"client":"0","":"downstairs","session_id":"07e562bd-a107-48db-bf82-3fa9dcb05aa2"}
3262025-03-23T06:09:12.118Z{"msg":"sending connect oneshot to client","v":0,"name":"crucible","level":30,"time":"2025-03-23T06:09:10.412427028Z","hostname":"w-01JQ0SETNSKZ27QMNBAK8ZTS6N","pid":1244,"client":"1","":"downstairs","session_id":"07e562bd-a107-48db-bf82-3fa9dcb05aa2"}
3272025-03-23T06:09:12.118Z{"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-23T06:09:10.412467242Z","hostname":"w-01JQ0SETNSKZ27QMNBAK8ZTS6N","pid":1244,"client":"1","":"downstairs","session_id":"07e562bd-a107-48db-bf82-3fa9dcb05aa2"}
3282025-03-23T06:09:12.118Z{"msg":"sending connect oneshot to client","v":0,"name":"crucible","level":30,"time":"2025-03-23T06:09:10.412512025Z","hostname":"w-01JQ0SETNSKZ27QMNBAK8ZTS6N","pid":1244,"client":"2","":"downstairs","session_id":"07e562bd-a107-48db-bf82-3fa9dcb05aa2"}
3292025-03-23T06:09:12.118Z{"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-23T06:09:10.412554699Z","hostname":"w-01JQ0SETNSKZ27QMNBAK8ZTS6N","pid":1244,"client":"2","":"downstairs","session_id":"07e562bd-a107-48db-bf82-3fa9dcb05aa2"}
3302025-03-23T06:09:12.118Z{"msg":"connecting to 127.0.0.1:8830","v":0,"name":"crucible","level":30,"time":"2025-03-23T06:09:10.412580675Z","hostname":"w-01JQ0SETNSKZ27QMNBAK8ZTS6N","pid":1244,"":"io task","client":"2","":"downstairs","session_id":"07e562bd-a107-48db-bf82-3fa9dcb05aa2"}
3312025-03-23T06:09:12.118Z{"msg":"connecting to 127.0.0.1:8810","v":0,"name":"crucible","level":30,"time":"2025-03-23T06:09:10.412823106Z","hostname":"w-01JQ0SETNSKZ27QMNBAK8ZTS6N","pid":1244,"":"io task","client":"0","":"downstairs","session_id":"07e562bd-a107-48db-bf82-3fa9dcb05aa2"}
3322025-03-23T06:09:12.118Z{"msg":"connecting to 127.0.0.1:8820","v":0,"name":"crucible","level":30,"time":"2025-03-23T06:09:10.41286483Z","hostname":"w-01JQ0SETNSKZ27QMNBAK8ZTS6N","pid":1244,"":"io task","client":"1","":"downstairs","session_id":"07e562bd-a107-48db-bf82-3fa9dcb05aa2"}
3332025-03-23T06:09:12.118Z{"msg":"ds_connection connected from Ok(127.0.0.1:49039)","v":0,"name":"crucible","level":30,"time":"2025-03-23T06:09:10.412896275Z","hostname":"w-01JQ0SETNSKZ27QMNBAK8ZTS6N","pid":1244,"":"io task","client":"2","":"downstairs","session_id":"07e562bd-a107-48db-bf82-3fa9dcb05aa2"}
3342025-03-23T06:09:12.118Z{"msg":"ds_connection connected from Ok(127.0.0.1:56526)","v":0,"name":"crucible","level":30,"time":"2025-03-23T06:09:10.412924641Z","hostname":"w-01JQ0SETNSKZ27QMNBAK8ZTS6N","pid":1244,"":"io task","client":"1","":"downstairs","session_id":"07e562bd-a107-48db-bf82-3fa9dcb05aa2"}
3352025-03-23T06:09:12.124Z{"msg":"ds_connection connected from Ok(127.0.0.1:57562)","v":0,"name":"crucible","level":30,"time":"2025-03-23T06:09:10.412959165Z","hostname":"w-01JQ0SETNSKZ27QMNBAK8ZTS6N","pid":1244,"":"io task","client":"0","":"downstairs","session_id":"07e562bd-a107-48db-bf82-3fa9dcb05aa2"}
3362025-03-23T06:09:12.124Z{"msg":"version negotiation from state Connecting { state: WaitForPromote, mode: New }","v":0,"name":"crucible","level":30,"time":"2025-03-23T06:09:10.413285394Z","hostname":"w-01JQ0SETNSKZ27QMNBAK8ZTS6N","pid":1244,"client":"1","":"downstairs","session_id":"07e562bd-a107-48db-bf82-3fa9dcb05aa2"}
3372025-03-23T06:09:12.124Z{"msg":"version negotiation from state Connecting { state: WaitForPromote, mode: New }","v":0,"name":"crucible","level":30,"time":"2025-03-23T06:09:10.413336106Z","hostname":"w-01JQ0SETNSKZ27QMNBAK8ZTS6N","pid":1244,"client":"2","":"downstairs","session_id":"07e562bd-a107-48db-bf82-3fa9dcb05aa2"}
3382025-03-23T06:09:12.124Z{"msg":"version negotiation from state Connecting { state: WaitForPromote, mode: New }","v":0,"name":"crucible","level":30,"time":"2025-03-23T06:09:10.413370171Z","hostname":"w-01JQ0SETNSKZ27QMNBAK8ZTS6N","pid":1244,"client":"0","":"downstairs","session_id":"07e562bd-a107-48db-bf82-3fa9dcb05aa2"}
3392025-03-23T06:09:12.124Z{"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-23T06:09:10.413960259Z","hostname":"w-01JQ0SETNSKZ27QMNBAK8ZTS6N","pid":1244,"client":"1","":"downstairs","session_id":"07e562bd-a107-48db-bf82-3fa9dcb05aa2"}
3402025-03-23T06:09:12.124Z{"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-23T06:09:10.413997103Z","hostname":"w-01JQ0SETNSKZ27QMNBAK8ZTS6N","pid":1244,"client":"0","":"downstairs","session_id":"07e562bd-a107-48db-bf82-3fa9dcb05aa2"}
3412025-03-23T06:09:12.124Z{"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-23T06:09:10.414045615Z","hostname":"w-01JQ0SETNSKZ27QMNBAK8ZTS6N","pid":1244,"client":"2","":"downstairs","session_id":"07e562bd-a107-48db-bf82-3fa9dcb05aa2"}
3422025-03-23T06:09:12.124Z{"msg":"Waiting for more clients to be ready","v":0,"name":"crucible","level":30,"time":"2025-03-23T06:09:10.414366945Z","hostname":"w-01JQ0SETNSKZ27QMNBAK8ZTS6N","pid":1244,"session_id":"07e562bd-a107-48db-bf82-3fa9dcb05aa2"}
3432025-03-23T06:09:12.124Z{"msg":"Waiting for more clients to be ready","v":0,"name":"crucible","level":30,"time":"2025-03-23T06:09:10.414504224Z","hostname":"w-01JQ0SETNSKZ27QMNBAK8ZTS6N","pid":1244,"session_id":"07e562bd-a107-48db-bf82-3fa9dcb05aa2"}
3442025-03-23T06:09:12.124Z{"msg":"[0]R flush_numbers: [3996, 3996, 3996, 3996, 3996]","v":0,"name":"crucible","level":30,"time":"2025-03-23T06:09:10.414537798Z","hostname":"w-01JQ0SETNSKZ27QMNBAK8ZTS6N","pid":1244,"":"downstairs","":"downstairs","session_id":"07e562bd-a107-48db-bf82-3fa9dcb05aa2"}
3452025-03-23T06:09:12.124Z{"msg":"[0]R generation: [31, 31, 31, 31, 31]","v":0,"name":"crucible","level":30,"time":"2025-03-23T06:09:10.414554256Z","hostname":"w-01JQ0SETNSKZ27QMNBAK8ZTS6N","pid":1244,"":"downstairs","":"downstairs","session_id":"07e562bd-a107-48db-bf82-3fa9dcb05aa2"}
3462025-03-23T06:09:12.124Z{"msg":"[0]R dirty: [false, false, false, false, false]","v":0,"name":"crucible","level":30,"time":"2025-03-23T06:09:10.414567934Z","hostname":"w-01JQ0SETNSKZ27QMNBAK8ZTS6N","pid":1244,"":"downstairs","":"downstairs","session_id":"07e562bd-a107-48db-bf82-3fa9dcb05aa2"}
3472025-03-23T06:09:12.124Z{"msg":"[1]R flush_numbers: [3996, 3996, 3996, 3996, 3996]","v":0,"name":"crucible","level":30,"time":"2025-03-23T06:09:10.414588661Z","hostname":"w-01JQ0SETNSKZ27QMNBAK8ZTS6N","pid":1244,"":"downstairs","":"downstairs","session_id":"07e562bd-a107-48db-bf82-3fa9dcb05aa2"}
3482025-03-23T06:09:12.124Z{"msg":"[1]R generation: [31, 31, 31, 31, 31]","v":0,"name":"crucible","level":30,"time":"2025-03-23T06:09:10.414602148Z","hostname":"w-01JQ0SETNSKZ27QMNBAK8ZTS6N","pid":1244,"":"downstairs","":"downstairs","session_id":"07e562bd-a107-48db-bf82-3fa9dcb05aa2"}
3492025-03-23T06:09:12.124Z{"msg":"[1]R dirty: [false, false, false, false, false]","v":0,"name":"crucible","level":30,"time":"2025-03-23T06:09:10.414616176Z","hostname":"w-01JQ0SETNSKZ27QMNBAK8ZTS6N","pid":1244,"":"downstairs","":"downstairs","session_id":"07e562bd-a107-48db-bf82-3fa9dcb05aa2"}
3502025-03-23T06:09:12.124Z{"msg":"[2]R flush_numbers: [3996, 3996, 3996, 3996, 3996]","v":0,"name":"crucible","level":30,"time":"2025-03-23T06:09:10.414636633Z","hostname":"w-01JQ0SETNSKZ27QMNBAK8ZTS6N","pid":1244,"":"downstairs","":"downstairs","session_id":"07e562bd-a107-48db-bf82-3fa9dcb05aa2"}
3512025-03-23T06:09:12.124Z{"msg":"[2]R generation: [31, 31, 31, 31, 31]","v":0,"name":"crucible","level":30,"time":"2025-03-23T06:09:10.414649871Z","hostname":"w-01JQ0SETNSKZ27QMNBAK8ZTS6N","pid":1244,"":"downstairs","":"downstairs","session_id":"07e562bd-a107-48db-bf82-3fa9dcb05aa2"}
3522025-03-23T06:09:12.124Z{"msg":"[2]R dirty: [false, false, false, false, false]","v":0,"name":"crucible","level":30,"time":"2025-03-23T06:09:10.414662729Z","hostname":"w-01JQ0SETNSKZ27QMNBAK8ZTS6N","pid":1244,"":"downstairs","":"downstairs","session_id":"07e562bd-a107-48db-bf82-3fa9dcb05aa2"}
3532025-03-23T06:09:12.124Z{"msg":"Max found gen is 32","v":0,"name":"crucible","level":30,"time":"2025-03-23T06:09:10.414694294Z","hostname":"w-01JQ0SETNSKZ27QMNBAK8ZTS6N","pid":1244,"":"downstairs","":"downstairs","session_id":"07e562bd-a107-48db-bf82-3fa9dcb05aa2"}
3542025-03-23T06:09:12.124Z{"msg":"Generation requested: 32 >= found:32","v":0,"name":"crucible","level":30,"time":"2025-03-23T06:09:10.414708502Z","hostname":"w-01JQ0SETNSKZ27QMNBAK8ZTS6N","pid":1244,"":"downstairs","":"downstairs","session_id":"07e562bd-a107-48db-bf82-3fa9dcb05aa2"}
3552025-03-23T06:09:12.124Z{"msg":"Next flush: 3997","v":0,"name":"crucible","level":30,"time":"2025-03-23T06:09:10.41472102Z","hostname":"w-01JQ0SETNSKZ27QMNBAK8ZTS6N","pid":1244,"":"downstairs","":"downstairs","session_id":"07e562bd-a107-48db-bf82-3fa9dcb05aa2"}
3562025-03-23T06:09:12.124Z{"msg":"All extents match","v":0,"name":"crucible","level":30,"time":"2025-03-23T06:09:10.414744886Z","hostname":"w-01JQ0SETNSKZ27QMNBAK8ZTS6N","pid":1244,"":"downstairs","":"downstairs","session_id":"07e562bd-a107-48db-bf82-3fa9dcb05aa2"}
3572025-03-23T06:09:12.124Z{"msg":"No downstairs reconciliation required","v":0,"name":"crucible","level":30,"time":"2025-03-23T06:09:10.414762933Z","hostname":"w-01JQ0SETNSKZ27QMNBAK8ZTS6N","pid":1244,"session_id":"07e562bd-a107-48db-bf82-3fa9dcb05aa2"}
3582025-03-23T06:09:12.124Z{"msg":"Transition from WaitQuorum to Active","v":0,"name":"crucible","level":30,"time":"2025-03-23T06:09:10.414775321Z","hostname":"w-01JQ0SETNSKZ27QMNBAK8ZTS6N","pid":1244,"client":"0","":"downstairs","session_id":"07e562bd-a107-48db-bf82-3fa9dcb05aa2"}
3592025-03-23T06:09:12.124Z{"msg":"Transition from WaitQuorum to Active","v":0,"name":"crucible","level":30,"time":"2025-03-23T06:09:10.414788969Z","hostname":"w-01JQ0SETNSKZ27QMNBAK8ZTS6N","pid":1244,"client":"1","":"downstairs","session_id":"07e562bd-a107-48db-bf82-3fa9dcb05aa2"}
3602025-03-23T06:09:12.124Z{"msg":"Transition from WaitQuorum to Active","v":0,"name":"crucible","level":30,"time":"2025-03-23T06:09:10.414802417Z","hostname":"w-01JQ0SETNSKZ27QMNBAK8ZTS6N","pid":1244,"client":"2","":"downstairs","session_id":"07e562bd-a107-48db-bf82-3fa9dcb05aa2"}
3612025-03-23T06:09:12.124Z{"msg":"All required reconciliation work is completed","v":0,"name":"crucible","level":30,"time":"2025-03-23T06:09:10.414823024Z","hostname":"w-01JQ0SETNSKZ27QMNBAK8ZTS6N","pid":1244,"session_id":"07e562bd-a107-48db-bf82-3fa9dcb05aa2"}
3622025-03-23T06:09:12.124Z{"msg":"Set Downstairs and Upstairs active after reconciliation","v":0,"name":"crucible","level":30,"time":"2025-03-23T06:09:10.414835932Z","hostname":"w-01JQ0SETNSKZ27QMNBAK8ZTS6N","pid":1244,"session_id":"07e562bd-a107-48db-bf82-3fa9dcb05aa2"}
3632025-03-23T06:09:12.125Z{"msg":"4c4289d8-ea7a-42ad-b730-a699d4044f1c is now active with session: 07e562bd-a107-48db-bf82-3fa9dcb05aa2","v":0,"name":"crucible","level":30,"time":"2025-03-23T06:09:10.4148482Z","hostname":"w-01JQ0SETNSKZ27QMNBAK8ZTS6N","pid":1244,"session_id":"07e562bd-a107-48db-bf82-3fa9dcb05aa2"}
3642025-03-23T06:09:12.125Z{"msg":"Set Active after no reconciliation","v":0,"name":"crucible","level":30,"time":"2025-03-23T06:09:10.414860468Z","hostname":"w-01JQ0SETNSKZ27QMNBAK8ZTS6N","pid":1244,"session_id":"07e562bd-a107-48db-bf82-3fa9dcb05aa2"}
3652025-03-23T06:09:12.125Z{"msg":"The guest has finished waiting for activation with:32","v":0,"name":"crucible","level":30,"time":"2025-03-23T06:09:10.414872296Z","hostname":"w-01JQ0SETNSKZ27QMNBAK8ZTS6N","pid":1244}
3662025-03-23T06:09:12.125Z{"msg":"Activated sub_volume 4c4289d8-ea7a-42ad-b730-a699d4044f1c","v":0,"name":"crucible","level":30,"time":"2025-03-23T06:09:10.414883554Z","hostname":"w-01JQ0SETNSKZ27QMNBAK8ZTS6N","pid":1244}
3672025-03-23T06:09:12.125Z{"msg":"The guest has requested activation with gen:32","v":0,"name":"crucible","level":30,"time":"2025-03-23T06:09:10.414894103Z","hostname":"w-01JQ0SETNSKZ27QMNBAK8ZTS6N","pid":1244}
3682025-03-23T06:09:12.125Z{"msg":"4c4289d8-ea7a-42ad-b730-a699d4044f1c active request set","v":0,"name":"crucible","level":30,"time":"2025-03-23T06:09:10.414917269Z","hostname":"w-01JQ0SETNSKZ27QMNBAK8ZTS6N","pid":1244,"session_id":"0d092605-a860-4c29-8c98-27e196aaec1f"}
3692025-03-23T06:09:12.125Z{"msg":"sending connect oneshot to client","v":0,"name":"crucible","level":30,"time":"2025-03-23T06:09:10.414940195Z","hostname":"w-01JQ0SETNSKZ27QMNBAK8ZTS6N","pid":1244,"client":"0","":"downstairs","session_id":"0d092605-a860-4c29-8c98-27e196aaec1f"}
3702025-03-23T06:09:12.125Z{"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-23T06:09:10.41497631Z","hostname":"w-01JQ0SETNSKZ27QMNBAK8ZTS6N","pid":1244,"client":"0","":"downstairs","session_id":"0d092605-a860-4c29-8c98-27e196aaec1f"}
3712025-03-23T06:09:12.125Z{"msg":"sending connect oneshot to client","v":0,"name":"crucible","level":30,"time":"2025-03-23T06:09:10.415046509Z","hostname":"w-01JQ0SETNSKZ27QMNBAK8ZTS6N","pid":1244,"client":"1","":"downstairs","session_id":"0d092605-a860-4c29-8c98-27e196aaec1f"}
3722025-03-23T06:09:12.125Z{"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-23T06:09:10.415084123Z","hostname":"w-01JQ0SETNSKZ27QMNBAK8ZTS6N","pid":1244,"client":"1","":"downstairs","session_id":"0d092605-a860-4c29-8c98-27e196aaec1f"}
3732025-03-23T06:09:12.125Z{"msg":"sending connect oneshot to client","v":0,"name":"crucible","level":30,"time":"2025-03-23T06:09:10.415244548Z","hostname":"w-01JQ0SETNSKZ27QMNBAK8ZTS6N","pid":1244,"client":"2","":"downstairs","session_id":"0d092605-a860-4c29-8c98-27e196aaec1f"}
3742025-03-23T06:09:12.125Z{"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-23T06:09:10.415303719Z","hostname":"w-01JQ0SETNSKZ27QMNBAK8ZTS6N","pid":1244,"client":"2","":"downstairs","session_id":"0d092605-a860-4c29-8c98-27e196aaec1f"}
3752025-03-23T06:09:12.125Z{"msg":"connecting to 127.0.0.1:8840","v":0,"name":"crucible","level":30,"time":"2025-03-23T06:09:10.415339273Z","hostname":"w-01JQ0SETNSKZ27QMNBAK8ZTS6N","pid":1244,"":"io task","client":"0","":"downstairs","session_id":"0d092605-a860-4c29-8c98-27e196aaec1f"}
3762025-03-23T06:09:12.125Z{"msg":"connecting to 127.0.0.1:8860","v":0,"name":"crucible","level":30,"time":"2025-03-23T06:09:10.4153605Z","hostname":"w-01JQ0SETNSKZ27QMNBAK8ZTS6N","pid":1244,"":"io task","client":"2","":"downstairs","session_id":"0d092605-a860-4c29-8c98-27e196aaec1f"}
3772025-03-23T06:09:12.125Z{"msg":"connecting to 127.0.0.1:8850","v":0,"name":"crucible","level":30,"time":"2025-03-23T06:09:10.415375867Z","hostname":"w-01JQ0SETNSKZ27QMNBAK8ZTS6N","pid":1244,"":"io task","client":"1","":"downstairs","session_id":"0d092605-a860-4c29-8c98-27e196aaec1f"}
3782025-03-23T06:09:12.125Z{"msg":"ds_connection connected from Ok(127.0.0.1:44122)","v":0,"name":"crucible","level":30,"time":"2025-03-23T06:09:10.415390135Z","hostname":"w-01JQ0SETNSKZ27QMNBAK8ZTS6N","pid":1244,"":"io task","client":"2","":"downstairs","session_id":"0d092605-a860-4c29-8c98-27e196aaec1f"}
3792025-03-23T06:09:12.125Z{"msg":"ds_connection connected from Ok(127.0.0.1:60628)","v":0,"name":"crucible","level":30,"time":"2025-03-23T06:09:10.415403743Z","hostname":"w-01JQ0SETNSKZ27QMNBAK8ZTS6N","pid":1244,"":"io task","client":"0","":"downstairs","session_id":"0d092605-a860-4c29-8c98-27e196aaec1f"}
3802025-03-23T06:09:12.125Z{"msg":"ds_connection connected from Ok(127.0.0.1:41262)","v":0,"name":"crucible","level":30,"time":"2025-03-23T06:09:10.415439528Z","hostname":"w-01JQ0SETNSKZ27QMNBAK8ZTS6N","pid":1244,"":"io task","client":"1","":"downstairs","session_id":"0d092605-a860-4c29-8c98-27e196aaec1f"}
3812025-03-23T06:09:12.125Z{"msg":"version negotiation from state Connecting { state: WaitForPromote, mode: New }","v":0,"name":"crucible","level":30,"time":"2025-03-23T06:09:10.415480711Z","hostname":"w-01JQ0SETNSKZ27QMNBAK8ZTS6N","pid":1244,"client":"2","":"downstairs","session_id":"0d092605-a860-4c29-8c98-27e196aaec1f"}
3822025-03-23T06:09:12.125Z{"msg":"version negotiation from state Connecting { state: WaitForPromote, mode: New }","v":0,"name":"crucible","level":30,"time":"2025-03-23T06:09:10.41561256Z","hostname":"w-01JQ0SETNSKZ27QMNBAK8ZTS6N","pid":1244,"client":"0","":"downstairs","session_id":"0d092605-a860-4c29-8c98-27e196aaec1f"}
3832025-03-23T06:09:12.125Z{"msg":"version negotiation from state Connecting { state: WaitForPromote, mode: New }","v":0,"name":"crucible","level":30,"time":"2025-03-23T06:09:10.415702496Z","hostname":"w-01JQ0SETNSKZ27QMNBAK8ZTS6N","pid":1244,"client":"1","":"downstairs","session_id":"0d092605-a860-4c29-8c98-27e196aaec1f"}
3842025-03-23T06:09:12.125Z{"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-23T06:09:10.416121311Z","hostname":"w-01JQ0SETNSKZ27QMNBAK8ZTS6N","pid":1244,"client":"2","":"downstairs","session_id":"0d092605-a860-4c29-8c98-27e196aaec1f"}
3852025-03-23T06:09:12.125Z{"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-23T06:09:10.416174513Z","hostname":"w-01JQ0SETNSKZ27QMNBAK8ZTS6N","pid":1244,"client":"0","":"downstairs","session_id":"0d092605-a860-4c29-8c98-27e196aaec1f"}
3862025-03-23T06:09:12.125Z{"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-23T06:09:10.416211757Z","hostname":"w-01JQ0SETNSKZ27QMNBAK8ZTS6N","pid":1244,"client":"1","":"downstairs","session_id":"0d092605-a860-4c29-8c98-27e196aaec1f"}
3872025-03-23T06:09:12.125Z{"msg":"Waiting for more clients to be ready","v":0,"name":"crucible","level":30,"time":"2025-03-23T06:09:10.416549494Z","hostname":"w-01JQ0SETNSKZ27QMNBAK8ZTS6N","pid":1244,"session_id":"0d092605-a860-4c29-8c98-27e196aaec1f"}
3882025-03-23T06:09:12.125Z{"msg":"Waiting for more clients to be ready","v":0,"name":"crucible","level":30,"time":"2025-03-23T06:09:10.41657467Z","hostname":"w-01JQ0SETNSKZ27QMNBAK8ZTS6N","pid":1244,"session_id":"0d092605-a860-4c29-8c98-27e196aaec1f"}
3892025-03-23T06:09:12.125Z{"msg":"[0]R flush_numbers: [5317, 5317, 5317, 5317, 5317]","v":0,"name":"crucible","level":30,"time":"2025-03-23T06:09:10.416587988Z","hostname":"w-01JQ0SETNSKZ27QMNBAK8ZTS6N","pid":1244,"":"downstairs","":"downstairs","session_id":"0d092605-a860-4c29-8c98-27e196aaec1f"}
3902025-03-23T06:09:12.125Z{"msg":"[0]R generation: [31, 31, 31, 31, 31]","v":0,"name":"crucible","level":30,"time":"2025-03-23T06:09:10.41663569Z","hostname":"w-01JQ0SETNSKZ27QMNBAK8ZTS6N","pid":1244,"":"downstairs","":"downstairs","session_id":"0d092605-a860-4c29-8c98-27e196aaec1f"}
3912025-03-23T06:09:12.125Z{"msg":"[0]R dirty: [false, false, false, false, false]","v":0,"name":"crucible","level":30,"time":"2025-03-23T06:09:10.416650498Z","hostname":"w-01JQ0SETNSKZ27QMNBAK8ZTS6N","pid":1244,"":"downstairs","":"downstairs","session_id":"0d092605-a860-4c29-8c98-27e196aaec1f"}
3922025-03-23T06:09:12.125Z{"msg":"[1]R flush_numbers: [5317, 5317, 5317, 5317, 5317]","v":0,"name":"crucible","level":30,"time":"2025-03-23T06:09:10.416663476Z","hostname":"w-01JQ0SETNSKZ27QMNBAK8ZTS6N","pid":1244,"":"downstairs","":"downstairs","session_id":"0d092605-a860-4c29-8c98-27e196aaec1f"}
3932025-03-23T06:09:12.125Z{"msg":"[1]R generation: [31, 31, 31, 31, 31]","v":0,"name":"crucible","level":30,"time":"2025-03-23T06:09:10.416712558Z","hostname":"w-01JQ0SETNSKZ27QMNBAK8ZTS6N","pid":1244,"":"downstairs","":"downstairs","session_id":"0d092605-a860-4c29-8c98-27e196aaec1f"}
3942025-03-23T06:09:12.125Z{"msg":"[1]R dirty: [false, false, false, false, false]","v":0,"name":"crucible","level":30,"time":"2025-03-23T06:09:10.416727036Z","hostname":"w-01JQ0SETNSKZ27QMNBAK8ZTS6N","pid":1244,"":"downstairs","":"downstairs","session_id":"0d092605-a860-4c29-8c98-27e196aaec1f"}
3952025-03-23T06:09:12.125Z{"msg":"[2]R flush_numbers: [5317, 5317, 5317, 5317, 5317]","v":0,"name":"crucible","level":30,"time":"2025-03-23T06:09:10.416739834Z","hostname":"w-01JQ0SETNSKZ27QMNBAK8ZTS6N","pid":1244,"":"downstairs","":"downstairs","session_id":"0d092605-a860-4c29-8c98-27e196aaec1f"}
3962025-03-23T06:09:12.125Z{"msg":"[2]R generation: [31, 31, 31, 31, 31]","v":0,"name":"crucible","level":30,"time":"2025-03-23T06:09:10.416752392Z","hostname":"w-01JQ0SETNSKZ27QMNBAK8ZTS6N","pid":1244,"":"downstairs","":"downstairs","session_id":"0d092605-a860-4c29-8c98-27e196aaec1f"}
3972025-03-23T06:09:12.125Z{"msg":"[2]R dirty: [false, false, false, false, false]","v":0,"name":"crucible","level":30,"time":"2025-03-23T06:09:10.41676501Z","hostname":"w-01JQ0SETNSKZ27QMNBAK8ZTS6N","pid":1244,"":"downstairs","":"downstairs","session_id":"0d092605-a860-4c29-8c98-27e196aaec1f"}
3982025-03-23T06:09:12.125Z{"msg":"Max found gen is 32","v":0,"name":"crucible","level":30,"time":"2025-03-23T06:09:10.416785467Z","hostname":"w-01JQ0SETNSKZ27QMNBAK8ZTS6N","pid":1244,"":"downstairs","":"downstairs","session_id":"0d092605-a860-4c29-8c98-27e196aaec1f"}
3992025-03-23T06:09:12.125Z{"msg":"Generation requested: 32 >= found:32","v":0,"name":"crucible","level":30,"time":"2025-03-23T06:09:10.416799665Z","hostname":"w-01JQ0SETNSKZ27QMNBAK8ZTS6N","pid":1244,"":"downstairs","":"downstairs","session_id":"0d092605-a860-4c29-8c98-27e196aaec1f"}
4002025-03-23T06:09:12.125Z{"msg":"Next flush: 5318","v":0,"name":"crucible","level":Wait for a query_work_queue command to finish before sending IO
4012025-03-23T06:09:12.125Z30,"time":"2025-03-23T06:09:10.41682692Z","hostname":"w-01JQ0SETNSKZ27QMNBAK8ZTS6N","pid":1244,"":"downstairs","":"downstairs","session_id":"0d092605-a860-4c29-8c98-27e196aaec1f"}
4022025-03-23T06:09:12.125Z{"msg":"All extents match","v":0,"name":"crucible","level":30,"time":"2025-03-23T06:09:10.416841878Z","hostname":"w-01JQ0SETNSKZ27QMNBAK8ZTS6N","pid":1244,"":"downstairs","":"downstairs","session_id":"0d092605-a860-4c29-8c98-27e196aaec1f"}
4032025-03-23T06:09:12.126Z{"msg":"No downstairs reconciliation required","v":0,"name":"crucible","level":30,"time":"2025-03-23T06:09:10.416862645Z","hostname":"w-01JQ0SETNSKZ27QMNBAK8ZTS6N","pid":1244,"session_id":"0d092605-a860-4c29-8c98-27e196aaec1f"}
4042025-03-23T06:09:12.126Z{"msg":"Transition from WaitQuorum to Active","v":0,"name":"crucible","level":30,"time":"2025-03-23T06:09:10.416875633Z","hostname":"w-01JQ0SETNSKZ27QMNBAK8ZTS6N","pid":1244,"client":"0","":"downstairs","session_id":"0d092605-a860-4c29-8c98-27e196aaec1f"}
4052025-03-23T06:09:12.126Z{"msg":"Transition from WaitQuorum to Active","v":0,"name":"crucible","level":30,"time":"2025-03-23T06:09:10.41689634Z","hostname":"w-01JQ0SETNSKZ27QMNBAK8ZTS6N","pid":1244,"client":"1","":"downstairs","session_id":"0d092605-a860-4c29-8c98-27e196aaec1f"}
4062025-03-23T06:09:12.126Z{"msg":"Transition from WaitQuorum to Active","v":0,"name":"crucible","level":30,"time":"2025-03-23T06:09:10.416909727Z","hostname":"w-01JQ0SETNSKZ27QMNBAK8ZTS6N","pid":1244,"client":"2","":"downstairs","session_id":"0d092605-a860-4c29-8c98-27e196aaec1f"}
4072025-03-23T06:09:12.126Z{"msg":"All required reconciliation work is completed","v":0,"name":"crucible","level":30,"time":"2025-03-23T06:09:10.416922365Z","hostname":"w-01JQ0SETNSKZ27QMNBAK8ZTS6N","pid":1244,"session_id":"0d092605-a860-4c29-8c98-27e196aaec1f"}
4082025-03-23T06:09:12.126Z{"msg":"Set Downstairs and Upstairs active after reconciliation","v":0,"name":"crucible","level":30,"time":"2025-03-23T06:09:10.416935423Z","hostname":"w-01JQ0SETNSKZ27QMNBAK8ZTS6N","pid":1244,"session_id":"0d092605-a860-4c29-8c98-27e196aaec1f"}
4092025-03-23T06:09:12.126Z{"msg":"4c4289d8-ea7a-42ad-b730-a699d4044f1c is now active with session: 0d092605-a860-4c29-8c98-27e196aaec1f","v":0,"name":"crucible","level":30,"time":"2025-03-23T06:09:10.41695528Z","hostname":"w-01JQ0SETNSKZ27QMNBAK8ZTS6N","pid":1244,"session_id":"0d092605-a860-4c29-8c98-27e196aaec1f"}
4102025-03-23T06:09:12.126Z{"msg":"Set Active after no reconciliation","v":0,"name":"crucible","level":30,"time":"2025-03-23T06:09:10.416967968Z","hostname":"w-01JQ0SETNSKZ27QMNBAK8ZTS6N","pid":1244,"session_id":"0d092605-a860-4c29-8c98-27e196aaec1f"}
4112025-03-23T06:09:12.126Z{"msg":"The guest has finished waiting for activation with:32","v":0,"name":"crucible","level":30,"time":"2025-03-23T06:09:10.416979896Z","hostname":"w-01JQ0SETNSKZ27QMNBAK8ZTS6N","pid":1244}
4122025-03-23T06:09:12.126Z{"msg":"Activated sub_volume 4c4289d8-ea7a-42ad-b730-a699d4044f1c","v":0,"name":"crucible","level":30,"time":"2025-03-23T06:09:10.416990735Z","hostname":"w-01JQ0SETNSKZ27QMNBAK8ZTS6N","pid":1244}
4132025-03-23T06:09:12.126ZDisk: sv:2 bs:4096 ts:409600 tb:100 max_io:100 or 409600
4142025-03-23T06:09:12.126ZLoading write count information from file "/var/tmp/test_up-build/verify_file"
4152025-03-23T06:09:12.130ZFill test
4162025-03-23T06:09:12.183ZRead and Verify all blocks (0..100 range:false)
4172025-03-23T06:09:12.280ZWrote out file "/var/tmp/test_up-build/verify_file"
4182025-03-23T06:09:12.280ZCLIENT: Tests done. All submitted work has been ACK'd
4192025-03-23T06:09:12.283Z----------------------------------------------------------------
4202025-03-23T06:09:12.283Z Crucible gen:32 GIO:true work queues: Upstairs:0 downstairs:1
4212025-03-23T06:09:12.283ZStates: Active Active Active
4222025-03-23T06:09:12.283ZJOBID ACK TYPE BKS/EXT DS:0 DS:1 DS:2 REPLAY
4232025-03-23T06:09:12.283Z 1002 Acked Read 50 Done Done Done false
4242025-03-23T06:09:12.283Z STATES DS:0 DS:1 DS:2 TOTAL
4252025-03-23T06:09:12.283Z Sent 0 0 0 0
4262025-03-23T06:09:12.283Z Done 1 1 1 3
4272025-03-23T06:09:12.283Z Skipped 0 0 0 0
4282025-03-23T06:09:12.283Z Error 0 0 0 0
4292025-03-23T06:09:12.283ZLast Flush: Some(JobId(1001)) Some(JobId(1001)) Some(JobId(1001))
4302025-03-23T06:09:12.283ZDownstairs last five completed: 1001 1000
4312025-03-23T06:09:12.283ZUpstairs last five completed: 1002 1001 1000
4322025-03-23T06:09:12.283Z----------------------------------------------------------------
4332025-03-23T06:09:12.283Z Crucible gen:32 GIO:true work queues: Upstairs:0 downstairs:1
4342025-03-23T06:09:12.283ZStates: Active Active Active
4352025-03-23T06:09:12.283ZJOBID ACK TYPE BKS/EXT DS:0 DS:1 DS:2 REPLAY
4362025-03-23T06:09:12.283Z 1002 Acked Read 50 Done Done Done false
4372025-03-23T06:09:12.283Z STATES DS:0 DS:1 DS:2 TOTAL
4382025-03-23T06:09:12.283Z Sent 0 0 0 0
4392025-03-23T06:09:12.283Z Done 1 1 1 3
4402025-03-23T06:09:12.283Z Skipped 0 0 0 0
4412025-03-23T06:09:12.283Z Error 0 0 0 0
4422025-03-23T06:09:12.283ZLast Flush: Some(JobId(1001)) Some(JobId(1001)) Some(JobId(1001))
4432025-03-23T06:09:12.283ZDownstairs last five completed: 1001 1000
4442025-03-23T06:09:12.284ZUpstairs last five completed: 1002 1001 1000
4452025-03-23T06:09:12.284ZCLIENT: Up:0 ds:2 act:6
4462025-03-23T06:09:16.282Z----------------------------------------------------------------
4472025-03-23T06:09:16.282Z Crucible gen:32 GIO:true work queues: Upstairs:0 downstairs:0
4482025-03-23T06:09:16.282ZDownstairs last five completed: 1003 1002 1001 1000
4492025-03-23T06:09:16.282ZUpstairs last five completed: 1003 1002 1001 1000
4502025-03-23T06:09:16.282Z----------------------------------------------------------------
4512025-03-23T06:09:16.282Z Crucible gen:32 GIO:true work queues: Upstairs:0 downstairs:0
4522025-03-23T06:09:16.282ZDownstairs last five completed: 1003 1002 1001 1000
4532025-03-23T06:09:16.282ZUpstairs last five completed: 1003 1002 1001 1000
4542025-03-23T06:09:16.285ZCLIENT: Up:0 ds:0 act:6
4552025-03-23T06:09:16.285ZCLIENT: All crucible jobs finished, exiting program
4562025-03-23T06:09:16.285Z{"msg":"Guest handle has been dropped","v":0,"name":"crucible","level":40,"time":"2025-03-23T06:09:14.576271224Z","hostname":"w-01JQ0SETNSKZ27QMNBAK8ZTS6N","pid":1244}
4572025-03-23T06:09:16.289ZRepair part 1 passed
4582025-03-23T06:09:16.292Z
4592025-03-23T06:09:16.292ZKill the current downstairs
4602025-03-23T06:09:16.456ZDownstairs 2 stopped
4612025-03-23T06:09:16.456Zmv /var/tmp/test_up-build/8830 /var/tmp/test_up-build/new
4622025-03-23T06:09:16.459ZNow put back the original so we have a mismatch
4632025-03-23T06:09:16.459Zmv /var/tmp/test_up-build/previous /var/tmp/test_up-build/8830
4642025-03-23T06:09:16.462ZRestart downstairs with old directory
4652025-03-23T06:09:16.513Z/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-23T06:09:16.530ZEXT BLOCKS GEN0 GEN1 GEN2 FL0 FL1 FL2 D0 D1 D2 DIFF
4672025-03-23T06:09:16.533Z 0 000-009 32 32 31 3997 3997 3996 F F F <---
4682025-03-23T06:09:16.533Z 1 010-019 32 32 31 3997 3997 3996 F F F <---
4692025-03-23T06:09:16.533Z 2 020-029 32 32 31 3997 3997 3996 F F F <---
4702025-03-23T06:09:16.533Z 3 030-039 32 32 31 3997 3997 3996 F F F <---
4712025-03-23T06:09:16.533Z 4 040-049 32 32 31 3997 3997 3996 F F F <---
4722025-03-23T06:09:16.533ZMax gen: 32, Max flush: 3997
4732025-03-23T06:09:16.533ZError: Difference in extent metadata found!
4742025-03-23T06:09:16.536Zdump test found error as expected
4752025-03-23T06:09:16.536Z
4762025-03-23T06:09:16.536Z
4772025-03-23T06:09:16.536Z/var/tmp/bins/crutest verify --range -g 33 -q --key Dt8v/c59Kokn019xjOMnOkX3zbETL5mD7zrCLjwHGnM= --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-23T06:09:16.591Z{"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-23T06:09:14.885385993Z","hostname":"w-01JQ0SETNSKZ27QMNBAK8ZTS6N","pid":1252,"task":"crutest"}
4792025-03-23T06:09:16.595Z{"msg":"dsc has 6 regions. This means 2 sub_volumes","v":0,"name":"crucible","level":30,"time":"2025-03-23T06:09:14.8859218Z","hostname":"w-01JQ0SETNSKZ27QMNBAK8ZTS6N","pid":1252,"task":"crutest"}
4802025-03-23T06:09:16.595Z{"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-23T06:09:14.887587659Z","hostname":"w-01JQ0SETNSKZ27QMNBAK8ZTS6N","pid":1252,"task":"crutest"}
4812025-03-23T06:09:16.595Z{"msg":"Upstairs starts","v":0,"name":"crucible","level":30,"time":"2025-03-23T06:09:14.88777195Z","hostname":"w-01JQ0SETNSKZ27QMNBAK8ZTS6N","pid":1252}
4822025-03-23T06:09:16.595Z{"msg":"Crucible Version: BuildInfo {\n version: \"0.0.1\",\n git_sha: \"a0baefa8a6d4c0e5f0d4f746f2af5de9c08b52b6\",\n git_commit_timestamp: \"2025-03-23T05:46:50.000000000Z\",\n git_branch: \"renovate/rust-1.x\",\n rustc_semver: \"1.85.1\",\n rustc_channel: \"stable\",\n rustc_host_triple: \"x86_64-unknown-illumos\",\n rustc_commit_sha: \"4eb161250e340c8f48f66e2b929ef4a5bed7c181\",\n cargo_triple: \"x86_64-unknown-illumos\",\n debug: true,\n opt_level: 0,\n}","v":0,"name":"crucible","level":30,"time":"2025-03-23T06:09:14.887813534Z","hostname":"w-01JQ0SETNSKZ27QMNBAK8ZTS6N","pid":1252}
4832025-03-23T06:09:16.595Z{"msg":"Upstairs <-> Downstairs Message Version: 13","v":0,"name":"crucible","level":30,"time":"2025-03-23T06:09:14.88783675Z","hostname":"w-01JQ0SETNSKZ27QMNBAK8ZTS6N","pid":1252}
4842025-03-23T06:09:16.595Z{"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-23T06:09:14.887851518Z","hostname":"w-01JQ0SETNSKZ27QMNBAK8ZTS6N","pid":1252}
4852025-03-23T06:09:16.595Z{"msg":"Crucible 12880125-a621-4a99-a1da-fb04ca65dd48 has session id: 847f45ce-3b89-49ec-a8c2-df3c5d03c3e0","v":0,"name":"crucible","level":30,"time":"2025-03-23T06:09:14.888381135Z","hostname":"w-01JQ0SETNSKZ27QMNBAK8ZTS6N","pid":1252,"session_id":"847f45ce-3b89-49ec-a8c2-df3c5d03c3e0"}
4862025-03-23T06:09:16.595Z{"msg":"Upstairs opts: Upstairs UUID: 12880125-a621-4a99-a1da-fb04ca65dd48, 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-23T06:09:14.888440246Z","hostname":"w-01JQ0SETNSKZ27QMNBAK8ZTS6N","pid":1252,"session_id":"847f45ce-3b89-49ec-a8c2-df3c5d03c3e0"}
4872025-03-23T06:09:16.595Z{"msg":"Crucible stats registered with UUID: 12880125-a621-4a99-a1da-fb04ca65dd48","v":0,"name":"crucible","level":30,"time":"2025-03-23T06:09:14.888467402Z","hostname":"w-01JQ0SETNSKZ27QMNBAK8ZTS6N","pid":1252,"session_id":"847f45ce-3b89-49ec-a8c2-df3c5d03c3e0"}
4882025-03-23T06:09:16.595Z{"msg":"could not find Downstairs address for Nexus","v":0,"name":"crucible","level":40,"time":"2025-03-23T06:09:14.888493777Z","hostname":"w-01JQ0SETNSKZ27QMNBAK8ZTS6N","pid":1252,"session_id":"847f45ce-3b89-49ec-a8c2-df3c5d03c3e0"}
4892025-03-23T06:09:16.599Z{"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-23T06:09:14.890555705Z","hostname":"w-01JQ0SETNSKZ27QMNBAK8ZTS6N","pid":1252,"task":"crutest"}
4902025-03-23T06:09:16.599Z{"msg":"Upstairs starts","v":0,"name":"crucible","level":30,"time":"2025-03-23T06:09:14.890637292Z","hostname":"w-01JQ0SETNSKZ27QMNBAK8ZTS6N","pid":1252}
4912025-03-23T06:09:16.599Z{"msg":"Crucible Version: BuildInfo {\n version: \"0.0.1\",\n git_sha: \"a0baefa8a6d4c0e5f0d4f746f2af5de9c08b52b6\",\n git_commit_timestamp: \"2025-03-23T05:46:50.000000000Z\",\n git_branch: \"renovate/rust-1.x\",\n rustc_semver: \"1.85.1\",\n rustc_channel: \"stable\",\n rustc_host_triple: \"x86_64-unknown-illumos\",\n rustc_commit_sha: \"4eb161250e340c8f48f66e2b929ef4a5bed7c181\",\n cargo_triple: \"x86_64-unknown-illumos\",\n debug: true,\n opt_level: 0,\n}","v":0,"name":"crucible","level":30,"time":"2025-03-23T06:09:14.890674376Z","hostname":"w-01JQ0SETNSKZ27QMNBAK8ZTS6N","pid":1252}
4922025-03-23T06:09:16.599Z{"msg":"Upstairs <-> Downstairs Message Version: 13","v":0,"name":"crucible","level":30,"time":"2025-03-23T06:09:14.890735457Z","hostname":"w-01JQ0SETNSKZ27QMNBAK8ZTS6N","pid":1252}
4932025-03-23T06:09:16.599Z{"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-23T06:09:14.890766282Z","hostname":"w-01JQ0SETNSKZ27QMNBAK8ZTS6N","pid":1252}
4942025-03-23T06:09:16.599Z{"msg":"Crucible 12880125-a621-4a99-a1da-fb04ca65dd48 has session id: 4b99ffc6-dedc-4362-8783-3fbc086ec5b6","v":0,"name":"crucible","level":30,"time":"2025-03-23T06:09:14.891117477Z","hostname":"w-01JQ0SETNSKZ27QMNBAK8ZTS6N","pid":1252,"session_id":"4b99ffc6-dedc-4362-8783-3fbc086ec5b6"}
4952025-03-23T06:09:16.599Z{"msg":"Upstairs opts: Upstairs UUID: 12880125-a621-4a99-a1da-fb04ca65dd48, 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-23T06:09:14.891158171Z","hostname":"w-01JQ0SETNSKZ27QMNBAK8ZTS6N","pid":1252,"session_id":"4b99ffc6-dedc-4362-8783-3fbc086ec5b6"}
4962025-03-23T06:09:16.599Z{"msg":"Crucible stats registered with UUID: 12880125-a621-4a99-a1da-fb04ca65dd48","v":0,"name":"crucible","level":30,"time":"2025-03-23T06:09:14.891195395Z","hostname":"w-01JQ0SETNSKZ27QMNBAK8ZTS6N","pid":1252,"session_id":"4b99ffc6-dedc-4362-8783-3fbc086ec5b6"}
4972025-03-23T06:09:16.599Z{"msg":"could not find Downstairs address for Nexus","v":0,"name":"crucible","level":40,"time":"2025-03-23T06:09:14.891217701Z","hostname":"w-01JQ0SETNSKZ27QMNBAK8ZTS6N","pid":1252,"session_id":"4b99ffc6-dedc-4362-8783-3fbc086ec5b6"}
4982025-03-23T06:09:16.599Z{"msg":"Downstairs in volume = 6","v":0,"name":"crucible","level":30,"time":"2025-03-23T06:09:14.891836795Z","hostname":"w-01JQ0SETNSKZ27QMNBAK8ZTS6N","pid":1252,"task":"crutest"}
4992025-03-23T06:09:16.599Z{"msg":"The guest has requested activation with gen:33","v":0,"name":"crucible","level":30,"time":"2025-03-23T06:09:14.891892836Z","hostname":"w-01JQ0SETNSKZ27QMNBAK8ZTS6N","pid":1252}
5002025-03-23T06:09:16.599Z{"msg":"12880125-a621-4a99-a1da-fb04ca65dd48 active request set","v":0,"name":"crucible","level":30,"time":"2025-03-23T06:09:14.891933789Z","hostname":"w-01JQ0SETNSKZ27QMNBAK8ZTS6N","pid":1252,"session_id":"847f45ce-3b89-49ec-a8c2-df3c5d03c3e0"}
5012025-03-23T06:09:16.599Z{"msg":"sending connect oneshot to client","v":0,"name":"crucible","level":30,"time":"2025-03-23T06:09:14.891954926Z","hostname":"w-01JQ0SETNSKZ27QMNBAK8ZTS6N","pid":1252,"client":"0","":"downstairs","session_id":"847f45ce-3b89-49ec-a8c2-df3c5d03c3e0"}
5022025-03-23T06:09:16.599Z{"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-23T06:09:14.89199517Z","hostname":"w-01JQ0SETNSKZ27QMNBAK8ZTS6N","pid":1252,"client":"0","":"downstairs","session_id":"847f45ce-3b89-49ec-a8c2-df3c5d03c3e0"}
5032025-03-23T06:09:16.599Z{"msg":"sending connect oneshot to client","v":0,"name":"crucible","level":30,"time":"2025-03-23T06:09:14.892020616Z","hostname":"w-01JQ0SETNSKZ27QMNBAK8ZTS6N","pid":1252,"client":"1","":"downstairs","session_id":"847f45ce-3b89-49ec-a8c2-df3c5d03c3e0"}
5042025-03-23T06:09:16.599Z{"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-23T06:09:14.892050441Z","hostname":"w-01JQ0SETNSKZ27QMNBAK8ZTS6N","pid":1252,"client":"1","":"downstairs","session_id":"847f45ce-3b89-49ec-a8c2-df3c5d03c3e0"}
5052025-03-23T06:09:16.599Z{"msg":"sending connect oneshot to client","v":0,"name":"crucible","level":30,"time":"2025-03-23T06:09:14.892074797Z","hostname":"w-01JQ0SETNSKZ27QMNBAK8ZTS6N","pid":1252,"client":"2","":"downstairs","session_id":"847f45ce-3b89-49ec-a8c2-df3c5d03c3e0"}
5062025-03-23T06:09:16.599Z{"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-23T06:09:14.892103743Z","hostname":"w-01JQ0SETNSKZ27QMNBAK8ZTS6N","pid":1252,"client":"2","":"downstairs","session_id":"847f45ce-3b89-49ec-a8c2-df3c5d03c3e0"}
5072025-03-23T06:09:16.599Z{"msg":"connecting to 127.0.0.1:8830","v":0,"name":"crucible","level":30,"time":"2025-03-23T06:09:14.892126919Z","hostname":"w-01JQ0SETNSKZ27QMNBAK8ZTS6N","pid":1252,"":"io task","client":"2","":"downstairs","session_id":"847f45ce-3b89-49ec-a8c2-df3c5d03c3e0"}
5082025-03-23T06:09:16.599Z{"msg":"connecting to 127.0.0.1:8810","v":0,"name":"crucible","level":30,"time":"2025-03-23T06:09:14.892154395Z","hostname":"w-01JQ0SETNSKZ27QMNBAK8ZTS6N","pid":1252,"":"io task","client":"0","":"downstairs","session_id":"847f45ce-3b89-49ec-a8c2-df3c5d03c3e0"}
5092025-03-23T06:09:16.599Z{"msg":"connecting to 127.0.0.1:8820","v":0,"name":"crucible","level":30,"time":"2025-03-23T06:09:14.892176622Z","hostname":"w-01JQ0SETNSKZ27QMNBAK8ZTS6N","pid":1252,"":"io task","client":"1","":"downstairs","session_id":"847f45ce-3b89-49ec-a8c2-df3c5d03c3e0"}
5102025-03-23T06:09:16.599Z{"msg":"ds_connection connected from Ok(127.0.0.1:58200)","v":0,"name":"crucible","level":30,"time":"2025-03-23T06:09:14.892199858Z","hostname":"w-01JQ0SETNSKZ27QMNBAK8ZTS6N","pid":1252,"":"io task","client":"0","":"downstairs","session_id":"847f45ce-3b89-49ec-a8c2-df3c5d03c3e0"}
5112025-03-23T06:09:16.599Z{"msg":"ds_connection connected from Ok(127.0.0.1:32945)","v":0,"name":"crucible","level":30,"time":"2025-03-23T06:09:14.892276446Z","hostname":"w-01JQ0SETNSKZ27QMNBAK8ZTS6N","pid":1252,"":"io task","client":"1","":"downstairs","session_id":"847f45ce-3b89-49ec-a8c2-df3c5d03c3e0"}
5122025-03-23T06:09:16.599Z{"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-23T06:09:14.892320349Z","hostname":"w-01JQ0SETNSKZ27QMNBAK8ZTS6N","pid":1252,"":"io task","client":"2","":"downstairs","session_id":"847f45ce-3b89-49ec-a8c2-df3c5d03c3e0"}
5132025-03-23T06:09:16.599Z{"msg":"client task is sending Done(ConnectionFailed(Os { code: 146, kind: ConnectionRefused, message: \"Connection refused\" }))","v":0,"name":"crucible","level":40,"time":"2025-03-23T06:09:14.892350404Z","hostname":"w-01JQ0SETNSKZ27QMNBAK8ZTS6N","pid":1252,"":"io task","client":"2","":"downstairs","session_id":"847f45ce-3b89-49ec-a8c2-df3c5d03c3e0"}
5142025-03-23T06:09:16.599Z{"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-23T06:09:14.892392358Z","hostname":"w-01JQ0SETNSKZ27QMNBAK8ZTS6N","pid":1252,"session_id":"847f45ce-3b89-49ec-a8c2-df3c5d03c3e0"}
5152025-03-23T06:09:16.599Z{"msg":"client task is exiting","v":0,"name":"crucible","level":30,"time":"2025-03-23T06:09:14.892459047Z","hostname":"w-01JQ0SETNSKZ27QMNBAK8ZTS6N","pid":1252,"":"io task","client":"2","":"downstairs","session_id":"847f45ce-3b89-49ec-a8c2-df3c5d03c3e0"}
5162025-03-23T06:09:16.599Z{"msg":"version negotiation from state Connecting { state: WaitForPromote, mode: New }","v":0,"name":"crucible","level":30,"time":"2025-03-23T06:09:14.892853945Z","hostname":"w-01JQ0SETNSKZ27QMNBAK8ZTS6N","pid":1252,"client":"0","":"downstairs","session_id":"847f45ce-3b89-49ec-a8c2-df3c5d03c3e0"}
5172025-03-23T06:09:16.600Z{"msg":"version negotiation from state Connecting { state: WaitForPromote, mode: New }","v":0,"name":"crucible","level":30,"time":"2025-03-23T06:09:14.892891859Z","hostname":"w-01JQ0SETNSKZ27QMNBAK8ZTS6N","pid":1252,"client":"1","":"downstairs","session_id":"847f45ce-3b89-49ec-a8c2-df3c5d03c3e0"}
5182025-03-23T06:09:16.603Z{"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-23T06:09:14.893452672Z","hostname":"w-01JQ0SETNSKZ27QMNBAK8ZTS6N","pid":1252,"client":"0","":"downstairs","session_id":"847f45ce-3b89-49ec-a8c2-df3c5d03c3e0"}
5192025-03-23T06:09:16.603Z{"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-23T06:09:14.893558955Z","hostname":"w-01JQ0SETNSKZ27QMNBAK8ZTS6N","pid":1252,"client":"1","":"downstairs","session_id":"847f45ce-3b89-49ec-a8c2-df3c5d03c3e0"}
5202025-03-23T06:09:16.603Z{"msg":"Waiting for more clients to be ready","v":0,"name":"crucible","level":30,"time":"2025-03-23T06:09:14.893840451Z","hostname":"w-01JQ0SETNSKZ27QMNBAK8ZTS6N","pid":1252,"session_id":"847f45ce-3b89-49ec-a8c2-df3c5d03c3e0"}
5212025-03-23T06:09:16.603Z{"msg":"Waiting for more clients to be ready","v":0,"name":"crucible","level":30,"time":"2025-03-23T06:09:14.893942365Z","hostname":"w-01JQ0SETNSKZ27QMNBAK8ZTS6N","pid":1252,"session_id":"847f45ce-3b89-49ec-a8c2-df3c5d03c3e0"}
5222025-03-23T06:09:26.602Z{"msg":"connecting to 127.0.0.1:8830","v":0,"name":"crucible","level":30,"time":"2025-03-23T06:09:24.893842141Z","hostname":"w-01JQ0SETNSKZ27QMNBAK8ZTS6N","pid":1252,"":"io task","client":"2","":"downstairs","session_id":"847f45ce-3b89-49ec-a8c2-df3c5d03c3e0"}
5232025-03-23T06:09:26.607Z{"msg":"ds_connection connected from Ok(127.0.0.1:39298)","v":0,"name":"crucible","level":30,"time":"2025-03-23T06:09:24.894047009Z","hostname":"w-01JQ0SETNSKZ27QMNBAK8ZTS6N","pid":1252,"":"io task","client":"2","":"downstairs","session_id":"847f45ce-3b89-49ec-a8c2-df3c5d03c3e0"}
5242025-03-23T06:09:26.607Z{"msg":"version negotiation from state Connecting { state: WaitForPromote, mode: New }","v":0,"name":"crucible","level":30,"time":"2025-03-23T06:09:24.895159425Z","hostname":"w-01JQ0SETNSKZ27QMNBAK8ZTS6N","pid":1252,"client":"2","":"downstairs","session_id":"847f45ce-3b89-49ec-a8c2-df3c5d03c3e0"}
5252025-03-23T06:09:26.607Z{"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-23T06:09:24.895841108Z","hostname":"w-01JQ0SETNSKZ27QMNBAK8ZTS6N","pid":1252,"client":"2","":"downstairs","session_id":"847f45ce-3b89-49ec-a8c2-df3c5d03c3e0"}
5262025-03-23T06:09:26.607Z{"msg":"[0]R flush_numbers: [3997, 3997, 3997, 3997, 3997]","v":0,"name":"crucible","level":30,"time":"2025-03-23T06:09:24.896339091Z","hostname":"w-01JQ0SETNSKZ27QMNBAK8ZTS6N","pid":1252,"":"downstairs","":"downstairs","session_id":"847f45ce-3b89-49ec-a8c2-df3c5d03c3e0"}
5272025-03-23T06:09:26.607Z{"msg":"[0]R generation: [32, 32, 32, 32, 32]","v":0,"name":"crucible","level":30,"time":"2025-03-23T06:09:24.896378555Z","hostname":"w-01JQ0SETNSKZ27QMNBAK8ZTS6N","pid":1252,"":"downstairs","":"downstairs","session_id":"847f45ce-3b89-49ec-a8c2-df3c5d03c3e0"}
5282025-03-23T06:09:26.607Z{"msg":"[0]R dirty: [false, false, false, false, false]","v":0,"name":"crucible","level":30,"time":"2025-03-23T06:09:24.896395712Z","hostname":"w-01JQ0SETNSKZ27QMNBAK8ZTS6N","pid":1252,"":"downstairs","":"downstairs","session_id":"847f45ce-3b89-49ec-a8c2-df3c5d03c3e0"}
5292025-03-23T06:09:26.607Z{"msg":"[1]R flush_numbers: [3997, 3997, 3997, 3997, 3997]","v":0,"name":"crucible","level":30,"time":"2025-03-23T06:09:24.89641004Z","hostname":"w-01JQ0SETNSKZ27QMNBAK8ZTS6N","pid":1252,"":"downstairs","":"downstairs","session_id":"847f45ce-3b89-49ec-a8c2-df3c5d03c3e0"}
5302025-03-23T06:09:26.607Z{"msg":"[1]R generation: [32, 32, 32, 32, 32]","v":0,"name":"crucible","level":30,"time":"2025-03-23T06:09:24.896432046Z","hostname":"w-01JQ0SETNSKZ27QMNBAK8ZTS6N","pid":1252,"":"downstairs","":"downstairs","session_id":"847f45ce-3b89-49ec-a8c2-df3c5d03c3e0"}
5312025-03-23T06:09:26.607Z{"msg":"[1]R dirty: [false, false, false, false, false]","v":0,"name":"crucible","level":30,"time":"2025-03-23T06:09:24.896446244Z","hostname":"w-01JQ0SETNSKZ27QMNBAK8ZTS6N","pid":1252,"":"downstairs","":"downstairs","session_id":"847f45ce-3b89-49ec-a8c2-df3c5d03c3e0"}
5322025-03-23T06:09:26.607Z{"msg":"[2]R flush_numbers: [3996, 3996, 3996, 3996, 3996]","v":0,"name":"crucible","level":30,"time":"2025-03-23T06:09:24.896466861Z","hostname":"w-01JQ0SETNSKZ27QMNBAK8ZTS6N","pid":1252,"":"downstairs","":"downstairs","session_id":"847f45ce-3b89-49ec-a8c2-df3c5d03c3e0"}
5332025-03-23T06:09:26.607Z{"msg":"[2]R generation: [31, 31, 31, 31, 31]","v":0,"name":"crucible","level":30,"time":"2025-03-23T06:09:24.896481359Z","hostname":"w-01JQ0SETNSKZ27QMNBAK8ZTS6N","pid":1252,"":"downstairs","":"downstairs","session_id":"847f45ce-3b89-49ec-a8c2-df3c5d03c3e0"}
5342025-03-23T06:09:26.607Z{"msg":"[2]R dirty: [false, false, false, false, false]","v":0,"name":"crucible","level":30,"time":"2025-03-23T06:09:24.896501175Z","hostname":"w-01JQ0SETNSKZ27QMNBAK8ZTS6N","pid":1252,"":"downstairs","":"downstairs","session_id":"847f45ce-3b89-49ec-a8c2-df3c5d03c3e0"}
5352025-03-23T06:09:26.607Z{"msg":"Max found gen is 33","v":0,"name":"crucible","level":30,"time":"2025-03-23T06:09:24.896515243Z","hostname":"w-01JQ0SETNSKZ27QMNBAK8ZTS6N","pid":1252,"":"downstairs","":"downstairs","session_id":"847f45ce-3b89-49ec-a8c2-df3c5d03c3e0"}
5362025-03-23T06:09:26.607Z{"msg":"Generation requested: 33 >= found:33","v":0,"name":"crucible","level":30,"time":"2025-03-23T06:09:24.896529261Z","hostname":"w-01JQ0SETNSKZ27QMNBAK8ZTS6N","pid":1252,"":"downstairs","":"downstairs","session_id":"847f45ce-3b89-49ec-a8c2-df3c5d03c3e0"}
5372025-03-23T06:09:26.607Z{"msg":"Next flush: 3998","v":0,"name":"crucible","level":30,"time":"2025-03-23T06:09:24.896543909Z","hostname":"w-01JQ0SETNSKZ27QMNBAK8ZTS6N","pid":1252,"":"downstairs","":"downstairs","session_id":"847f45ce-3b89-49ec-a8c2-df3c5d03c3e0"}
5382025-03-23T06:09:26.608Z{"msg":"extent 0 needs reconciliation: ExtentMetadata { gen: 32, flush: 3997, dirty: false } ExtentMetadata { gen: 32, flush: 3997, dirty: false } ExtentMetadata { gen: 31, flush: 3996, dirty: false }","v":0,"name":"crucible","level":30,"time":"2025-03-23T06:09:24.896572424Z","hostname":"w-01JQ0SETNSKZ27QMNBAK8ZTS6N","pid":1252,"":"mend","":"downstairs","":"downstairs","session_id":"847f45ce-3b89-49ec-a8c2-df3c5d03c3e0"}
5392025-03-23T06:09:26.608Z{"msg":"extent:0 [ExtentMetadata { gen: 32, flush: 3997, dirty: false }, ExtentMetadata { gen: 32, flush: 3997, dirty: false }, ExtentMetadata { gen: 31, flush: 3996, dirty: false }] => 0","v":0,"name":"crucible","level":30,"time":"2025-03-23T06:09:24.896591431Z","hostname":"w-01JQ0SETNSKZ27QMNBAK8ZTS6N","pid":1252,"":"mend","":"downstairs","":"downstairs","session_id":"847f45ce-3b89-49ec-a8c2-df3c5d03c3e0"}
5402025-03-23T06:09:26.608Z{"msg":"found dest for source 0 for extent at index 0 => [ClientId(2)]","v":0,"name":"crucible","level":30,"time":"2025-03-23T06:09:24.896613148Z","hostname":"w-01JQ0SETNSKZ27QMNBAK8ZTS6N","pid":1252,"":"mend","":"downstairs","":"downstairs","session_id":"847f45ce-3b89-49ec-a8c2-df3c5d03c3e0"}
5412025-03-23T06:09:26.608Z{"msg":"extent 1 needs reconciliation: ExtentMetadata { gen: 32, flush: 3997, dirty: false } ExtentMetadata { gen: 32, flush: 3997, dirty: false } ExtentMetadata { gen: 31, flush: 3996, dirty: false }","v":0,"name":"crucible","level":30,"time":"2025-03-23T06:09:24.896629025Z","hostname":"w-01JQ0SETNSKZ27QMNBAK8ZTS6N","pid":1252,"":"mend","":"downstairs","":"downstairs","session_id":"847f45ce-3b89-49ec-a8c2-df3c5d03c3e0"}
5422025-03-23T06:09:26.608Z{"msg":"extent:0 [ExtentMetadata { gen: 32, flush: 3997, dirty: false }, ExtentMetadata { gen: 32, flush: 3997, dirty: false }, ExtentMetadata { gen: 31, flush: 3996, dirty: false }] => 0","v":0,"name":"crucible","level":30,"time":"2025-03-23T06:09:24.896651312Z","hostname":"w-01JQ0SETNSKZ27QMNBAK8ZTS6N","pid":1252,"":"mend","":"downstairs","":"downstairs","session_id":"847f45ce-3b89-49ec-a8c2-df3c5d03c3e0"}
5432025-03-23T06:09:26.608Z{"msg":"found dest for source 0 for extent at index 1 => [ClientId(2)]","v":0,"name":"crucible","level":30,"time":"2025-03-23T06:09:24.896666459Z","hostname":"w-01JQ0SETNSKZ27QMNBAK8ZTS6N","pid":1252,"":"mend","":"downstairs","":"downstairs","session_id":"847f45ce-3b89-49ec-a8c2-df3c5d03c3e0"}
5442025-03-23T06:09:26.608Z{"msg":"extent 2 needs reconciliation: ExtentMetadata { gen: 32, flush: 3997, dirty: false } ExtentMetadata { gen: 32, flush: 3997, dirty: false } ExtentMetadata { gen: 31, flush: 3996, dirty: false }","v":0,"name":"crucible","level":30,"time":"2025-03-23T06:09:24.896681647Z","hostname":"w-01JQ0SETNSKZ27QMNBAK8ZTS6N","pid":1252,"":"mend","":"downstairs","":"downstairs","session_id":"847f45ce-3b89-49ec-a8c2-df3c5d03c3e0"}
5452025-03-23T06:09:26.608Z{"msg":"extent:0 [ExtentMetadata { gen: 32, flush: 3997, dirty: false }, ExtentMetadata { gen: 32, flush: 3997, dirty: false }, ExtentMetadata { gen: 31, flush: 3996, dirty: false }] => 0","v":0,"name":"crucible","level":30,"time":"2025-03-23T06:09:24.896703404Z","hostname":"w-01JQ0SETNSKZ27QMNBAK8ZTS6N","pid":1252,"":"mend","":"downstairs","":"downstairs","session_id":"847f45ce-3b89-49ec-a8c2-df3c5d03c3e0"}
5462025-03-23T06:09:26.608Z{"msg":"found dest for source 0 for extent at index 2 => [ClientId(2)]","v":0,"name":"crucible","level":30,"time":"2025-03-23T06:09:24.896718441Z","hostname":"w-01JQ0SETNSKZ27QMNBAK8ZTS6N","pid":1252,"":"mend","":"downstairs","":"downstairs","session_id":"847f45ce-3b89-49ec-a8c2-df3c5d03c3e0"}
5472025-03-23T06:09:26.608Z{"msg":"extent 3 needs reconciliation: ExtentMetadata { gen: 32, flush: 3997, dirty: false } ExtentMetadata { gen: 32, flush: 3997, dirty: false } ExtentMetadata { gen: 31, flush: 3996, dirty: false }","v":0,"name":"crucible","level":30,"time":"2025-03-23T06:09:24.896740648Z","hostname":"w-01JQ0SETNSKZ27QMNBAK8ZTS6N","pid":1252,"":"mend","":"downstairs","":"downstairs","session_id":"847f45ce-3b89-49ec-a8c2-df3c5d03c3e0"}
5482025-03-23T06:09:26.608Z{"msg":"extent:0 [ExtentMetadata { gen: 32, flush: 3997, dirty: false }, ExtentMetadata { gen: 32, flush: 3997, dirty: false }, ExtentMetadata { gen: 31, flush: 3996, dirty: false }] => 0","v":0,"name":"crucible","level":30,"time":"2025-03-23T06:09:24.896756775Z","hostname":"w-01JQ0SETNSKZ27QMNBAK8ZTS6N","pid":1252,"":"mend","":"downstairs","":"downstairs","session_id":"847f45ce-3b89-49ec-a8c2-df3c5d03c3e0"}
5492025-03-23T06:09:26.608Z{"msg":"found dest for source 0 for extent at index 3 => [ClientId(2)]","v":0,"name":"crucible","level":30,"time":"2025-03-23T06:09:24.896777452Z","hostname":"w-01JQ0SETNSKZ27QMNBAK8ZTS6N","pid":1252,"":"mend","":"downstairs","":"downstairs","session_id":"847f45ce-3b89-49ec-a8c2-df3c5d03c3e0"}
5502025-03-23T06:09:26.608Z{"msg":"extent 4 needs reconciliation: ExtentMetadata { gen: 32, flush: 3997, dirty: false } ExtentMetadata { gen: 32, flush: 3997, dirty: false } ExtentMetadata { gen: 31, flush: 3996, dirty: false }","v":0,"name":"crucible","level":30,"time":"2025-03-23T06:09:24.896793879Z","hostname":"w-01JQ0SETNSKZ27QMNBAK8ZTS6N","pid":1252,"":"mend","":"downstairs","":"downstairs","session_id":"847f45ce-3b89-49ec-a8c2-df3c5d03c3e0"}
5512025-03-23T06:09:26.608Z{"msg":"extent:0 [ExtentMetadata { gen: 32, flush: 3997, dirty: false }, ExtentMetadata { gen: 32, flush: 3997, dirty: false }, ExtentMetadata { gen: 31, flush: 3996, dirty: false }] => 0","v":0,"name":"crucible","level":30,"time":"2025-03-23T06:09:24.896810057Z","hostname":"w-01JQ0SETNSKZ27QMNBAK8ZTS6N","pid":1252,"":"mend","":"downstairs","":"downstairs","session_id":"847f45ce-3b89-49ec-a8c2-df3c5d03c3e0"}
5522025-03-23T06:09:26.608Z{"msg":"found dest for source 0 for extent at index 4 => [ClientId(2)]","v":0,"name":"crucible","level":30,"time":"2025-03-23T06:09:24.896824495Z","hostname":"w-01JQ0SETNSKZ27QMNBAK8ZTS6N","pid":1252,"":"mend","":"downstairs","":"downstairs","session_id":"847f45ce-3b89-49ec-a8c2-df3c5d03c3e0"}
5532025-03-23T06:09:26.608Z{"msg":"Transition from Connecting { state: WaitQuorum, mode: New } to Reconcile","v":0,"name":"crucible","level":30,"time":"2025-03-23T06:09:24.896849621Z","hostname":"w-01JQ0SETNSKZ27QMNBAK8ZTS6N","pid":1252,"client":"0","":"downstairs","session_id":"847f45ce-3b89-49ec-a8c2-df3c5d03c3e0"}
5542025-03-23T06:09:26.608Z{"msg":"Transition from Connecting { state: WaitQuorum, mode: New } to Reconcile","v":0,"name":"crucible","level":30,"time":"2025-03-23T06:09:24.896874087Z","hostname":"w-01JQ0SETNSKZ27QMNBAK8ZTS6N","pid":1252,"client":"1","":"downstairs","session_id":"847f45ce-3b89-49ec-a8c2-df3c5d03c3e0"}
5552025-03-23T06:09:26.608Z{"msg":"Transition from Connecting { state: WaitQuorum, mode: New } to Reconcile","v":0,"name":"crucible","level":30,"time":"2025-03-23T06:09:24.896888585Z","hostname":"w-01JQ0SETNSKZ27QMNBAK8ZTS6N","pid":1252,"client":"2","":"downstairs","session_id":"847f45ce-3b89-49ec-a8c2-df3c5d03c3e0"}
5562025-03-23T06:09:26.608Z{"msg":"Full repair list: {ExtentId(1): ExtentFix { source: ClientId(0), dest: [ClientId(2)] }, ExtentId(3): 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)] }, ExtentId(0): ExtentFix { source: ClientId(0), dest: [ClientId(2)] }}","v":0,"name":"crucible","level":30,"time":"2025-03-23T06:09:24.896906142Z","hostname":"w-01JQ0SETNSKZ27QMNBAK8ZTS6N","pid":1252,"":"downstairs","":"downstairs","session_id":"847f45ce-3b89-49ec-a8c2-df3c5d03c3e0"}
5572025-03-23T06:09:26.608Z{"msg":"Task list: [ReconcileIO { id: ReconciliationId(0), op: ExtentFlush { repair_id: ReconciliationId(0), extent_id: ExtentId(1), client_id: ClientId(0), flush_number: 3998, gen_number: 33 }, state: ClientData([New, New, New]) }, ReconcileIO { id: ReconciliationId(1), op: ExtentClose { repair_id: ReconciliationId(1), extent_id: ExtentId(1) }, state: ClientData([New, New, New]) }, ReconcileIO { id: ReconciliationId(2), op: ExtentRepair { repair_id: ReconciliationId(2), extent_id: ExtentId(1), source_client_id: ClientId(0), source_repair_address: 0.0.0.0:12810, dest_clients: [ClientId(2)] }, state: ClientData([New, New, New]) }, ReconcileIO { id: ReconciliationId(3), op: ExtentReopen { repair_id: ReconciliationId(3), extent_id: ExtentId(1) }, state: ClientData([New, New, New]) }, ReconcileIO { id: ReconciliationId(4), op: ExtentFlush { repair_id: ReconciliationId(4), extent_id: ExtentId(3), client_id: ClientId(0), flush_number: 3998, gen_number: 33 }, state: ClientData([New, New, New]) }, ReconcileIO { id: ReconciliationId(5), op: ExtentClose { repair_id: ReconciliationId(5), extent_id: ExtentId(3) }, state: ClientData([New, New, New]) }, ReconcileIO { id: ReconciliationId(6), op: ExtentRepair { repair_id: ReconciliationId(6), extent_id: ExtentId(3), source_client_id: ClientId(0), source_repair_address: 0.0.0.0:12810, dest_clients: [ClientId(2)] }, state: ClientData([New, New, New]) }, ReconcileIO { id: ReconciliationId(7), op: ExtentReopen { repair_id: ReconciliationId(7), extent_id: ExtentId(3) }, state: ClientData([New, New, New]) }, ReconcileIO { id: ReconciliationId(8), op: ExtentFlush { repair_id: ReconciliationId(8), extent_id: ExtentId(2), client_id: ClientId(0), flush_number: 3998, gen_number: 33 }, state: ClientData([New, New, New]) }, ReconcileIO { id: ReconciliationId(9), op: ExtentClose { repair_id: ReconciliationId(9), extent_id: ExtentId(2) }, state: ClientData([New, New, New]) }, ReconcileIO { id: ReconciliationId(10), op: ExtentRepair { repair_id: ReconciliationId(10), extent_id: ExtentId(2), source_client_id: ClientId(0), source_repair_address: 0.0.0.0:12810, dest_clients: [ClientId(2)] }, state: ClientData([New, New, New]) }, ReconcileIO { id: ReconciliationId(11), op: ExtentReopen { repair_id: ReconciliationId(11), extent_id: ExtentId(2) }, state: ClientData([New, New, New]) }, ReconcileIO { id: ReconciliationId(12), op: ExtentFlush { repair_id: ReconciliationId(12), extent_id: ExtentId(4), client_id: ClientId(0), flush_number: 3998, gen_number: 33 }, state: ClientData([New, New, New]) }, ReconcileIO { id: ReconciliationId(13), op: ExtentClose { repair_id: ReconciliationId(13), extent_id: ExtentId(4) }, state: ClientData([New, New, New]) }, ReconcileIO { id: ReconciliationId(14), op: ExtentRepair { repair_id: ReconciliationId(14), extent_id: ExtentId(4), source_client_id: ClientId(0), source_repair_address: 0.0.0.0:12810, dest_clients: [ClientId(2)] }, state: ClientData([New, New, New]) }, ReconcileIO { id: ReconciliationId(15), op: ExtentReopen { repair_id: ReconciliationId(15), extent_id: ExtentId(4) }, state: ClientData([New, New, New]) }, ReconcileIO { id: ReconciliationId(16), op: ExtentFlush { repair_id: ReconciliationId(16), extent_id: ExtentId(0), client_id: ClientId(0), flush_number: 3998, gen_number: 33 }, state: ClientData([New, New, New]) }, ReconcileIO { id: ReconciliationId(17), op: ExtentClose { repair_id: ReconciliationId(17), extent_id: ExtentId(0) }, state: ClientData([New, New, New]) }, ReconcileIO { id: ReconciliationId(18), op: ExtentRepair { repair_id: ReconciliationId(18), extent_id: ExtentId(0), source_client_id: ClientId(0), source_repair_address: 0.0.0.0:12810, dest_clients: [ClientId(2)] }, state: ClientData([New, New, New]) }, ReconcileIO { id: ReconciliationId(19), op: ExtentReopen { repair_id: ReconciliationId(19), extent_id: ExtentId(0) }, state: ClientData([New, New, New]) }]","v":0,"name":"crucible","level":30,"time":"2025-03-23T06:09:24.896987759Z","hostname":"w-01JQ0SETNSKZ27QMNBAK8ZTS6N","pid":1252,"":"downstairs","":"downstairs","session_id":"847f45ce-3b89-49ec-a8c2-df3c5d03c3e0"}
5582025-03-23T06:09:26.608Z{"msg":"starting reconciliation ab07e748-431f-440a-ae29-e81664b1a754: found 20 extents that need repair","v":0,"name":"crucible","level":30,"time":"2025-03-23T06:09:24.897057998Z","hostname":"w-01JQ0SETNSKZ27QMNBAK8ZTS6N","pid":1252,"":"downstairs","":"downstairs","session_id":"847f45ce-3b89-49ec-a8c2-df3c5d03c3e0"}
5592025-03-23T06:09:26.608Z{"msg":"sending reconcile request ReconciliationId(2)","v":0,"name":"crucible","level":30,"time":"2025-03-23T06:09:24.897457516Z","hostname":"w-01JQ0SETNSKZ27QMNBAK8ZTS6N","pid":1252,"client":"2","":"downstairs","session_id":"847f45ce-3b89-49ec-a8c2-df3c5d03c3e0"}
5602025-03-23T06:09:26.614Z{"msg":"sending reconcile request ReconciliationId(6)","v":0,"name":"crucible","level":30,"time":"2025-03-23T06:09:24.906554503Z","hostname":"w-01JQ0SETNSKZ27QMNBAK8ZTS6N","pid":1252,"client":"2","":"downstairs","session_id":"847f45ce-3b89-49ec-a8c2-df3c5d03c3e0"}
5612025-03-23T06:09:26.618Z{"msg":"sending reconcile request ReconciliationId(10)","v":0,"name":"crucible","level":30,"time":"2025-03-23T06:09:24.910272442Z","hostname":"w-01JQ0SETNSKZ27QMNBAK8ZTS6N","pid":1252,"client":"2","":"downstairs","session_id":"847f45ce-3b89-49ec-a8c2-df3c5d03c3e0"}
5622025-03-23T06:09:26.621Z{"msg":"sending reconcile request ReconciliationId(14)","v":0,"name":"crucible","level":30,"time":"2025-03-23T06:09:24.913878148Z","hostname":"w-01JQ0SETNSKZ27QMNBAK8ZTS6N","pid":1252,"client":"2","":"downstairs","session_id":"847f45ce-3b89-49ec-a8c2-df3c5d03c3e0"}
5632025-03-23T06:09:26.625Z{"msg":"sending reconcile request ReconciliationId(18)","v":0,"name":"crucible","level":30,"time":"2025-03-23T06:09:24.917372472Z","hostname":"w-01JQ0SETNSKZ27QMNBAK8ZTS6N","pid":1252,"client":"2","":"downstairs","session_id":"847f45ce-3b89-49ec-a8c2-df3c5d03c3e0"}
5642025-03-23T06:09:26.628Z{"msg":"done with reconciliation","v":0,"name":"crucible","level":30,"time":"2025-03-23T06:09:24.92051733Z","hostname":"w-01JQ0SETNSKZ27QMNBAK8ZTS6N","pid":1252,"":"downstairs","":"downstairs","session_id":"847f45ce-3b89-49ec-a8c2-df3c5d03c3e0"}
5652025-03-23T06:09:26.628Z{"msg":"Transition from Reconcile to Active","v":0,"name":"crucible","level":30,"time":"2025-03-23T06:09:24.920575671Z","hostname":"w-01JQ0SETNSKZ27QMNBAK8ZTS6N","pid":1252,"client":"0","":"downstairs","session_id":"847f45ce-3b89-49ec-a8c2-df3c5d03c3e0"}
5662025-03-23T06:09:26.632Z{"msg":"Transition from Reconcile to Active","v":0,"name":"crucible","level":30,"time":"2025-03-23T06:09:24.920601456Z","hostname":"w-01JQ0SETNSKZ27QMNBAK8ZTS6N","pid":1252,"client":"1","":"downstairs","session_id":"847f45ce-3b89-49ec-a8c2-df3c5d03c3e0"}
5672025-03-23T06:09:26.632Z{"msg":"Transition from Reconcile to Active","v":0,"name":"crucible","level":30,"time":"2025-03-23T06:09:24.92064424Z","hostname":"w-01JQ0SETNSKZ27QMNBAK8ZTS6N","pid":1252,"client":"2","":"downstairs","session_id":"847f45ce-3b89-49ec-a8c2-df3c5d03c3e0"}
5682025-03-23T06:09:26.632Z{"msg":"All required reconciliation work is completed","v":0,"name":"crucible","level":30,"time":"2025-03-23T06:09:24.920679454Z","hostname":"w-01JQ0SETNSKZ27QMNBAK8ZTS6N","pid":1252,"session_id":"847f45ce-3b89-49ec-a8c2-df3c5d03c3e0"}
5692025-03-23T06:09:26.632Z{"msg":"Set Downstairs and Upstairs active after reconciliation","v":0,"name":"crucible","level":30,"time":"2025-03-23T06:09:24.92070933Z","hostname":"w-01JQ0SETNSKZ27QMNBAK8ZTS6N","pid":1252,"session_id":"847f45ce-3b89-49ec-a8c2-df3c5d03c3e0"}
5702025-03-23T06:09:26.632Z{"msg":"12880125-a621-4a99-a1da-fb04ca65dd48 is now active with session: 847f45ce-3b89-49ec-a8c2-df3c5d03c3e0","v":0,"name":"crucible","level":30,"time":"2025-03-23T06:09:24.920740055Z","hostname":"w-01JQ0SETNSKZ27QMNBAK8ZTS6N","pid":1252,"session_id":"847f45ce-3b89-49ec-a8c2-df3c5d03c3e0"}
5712025-03-23T06:09:26.632Z{"msg":"The guest has finished waiting for activation with:33","v":0,"name":"crucible","level":30,"time":"2025-03-23T06:09:24.9207714Z","hostname":"w-01JQ0SETNSKZ27QMNBAK8ZTS6N","pid":1252}
5722025-03-23T06:09:26.632Z{"msg":"Activated sub_volume 12880125-a621-4a99-a1da-fb04ca65dd48","v":0,"name":"crucible","level":30,"time":"2025-03-23T06:09:24.920796956Z","hostname":"w-01JQ0SETNSKZ27QMNBAK8ZTS6N","pid":1252}
5732025-03-23T06:09:26.632Z{"msg":"The guest has requested activation with gen:33","v":0,"name":"crucible","level":30,"time":"2025-03-23T06:09:24.920846328Z","hostname":"w-01JQ0SETNSKZ27QMNBAK8ZTS6N","pid":1252}
5742025-03-23T06:09:26.632Z{"msg":"12880125-a621-4a99-a1da-fb04ca65dd48 active request set","v":0,"name":"crucible","level":30,"time":"2025-03-23T06:09:24.920915797Z","hostname":"w-01JQ0SETNSKZ27QMNBAK8ZTS6N","pid":1252,"session_id":"4b99ffc6-dedc-4362-8783-3fbc086ec5b6"}
5752025-03-23T06:09:26.632Z{"msg":"sending connect oneshot to client","v":0,"name":"crucible","level":30,"time":"2025-03-23T06:09:24.920975328Z","hostname":"w-01JQ0SETNSKZ27QMNBAK8ZTS6N","pid":1252,"client":"0","":"downstairs","session_id":"4b99ffc6-dedc-4362-8783-3fbc086ec5b6"}
5762025-03-23T06:09:26.632Z{"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-23T06:09:24.921014222Z","hostname":"w-01JQ0SETNSKZ27QMNBAK8ZTS6N","pid":1252,"client":"0","":"downstairs","session_id":"4b99ffc6-dedc-4362-8783-3fbc086ec5b6"}
5772025-03-23T06:09:26.632Z{"msg":"sending connect oneshot to client","v":0,"name":"crucible","level":30,"time":"2025-03-23T06:09:24.921050366Z","hostname":"w-01JQ0SETNSKZ27QMNBAK8ZTS6N","pid":1252,"client":"1","":"downstairs","session_id":"4b99ffc6-dedc-4362-8783-3fbc086ec5b6"}
5782025-03-23T06:09:26.632Z{"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-23T06:09:24.921084281Z","hostname":"w-01JQ0SETNSKZ27QMNBAK8ZTS6N","pid":1252,"client":"1","":"downstairs","session_id":"4b99ffc6-dedc-4362-8783-3fbc086ec5b6"}
5792025-03-23T06:09:26.632Z{"msg":"sending connect oneshot to client","v":0,"name":"crucible","level":30,"time":"2025-03-23T06:09:24.921111097Z","hostname":"w-01JQ0SETNSKZ27QMNBAK8ZTS6N","pid":1252,"client":"2","":"downstairs","session_id":"4b99ffc6-dedc-4362-8783-3fbc086ec5b6"}
5802025-03-23T06:09:26.632Z{"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-23T06:09:24.92115241Z","hostname":"w-01JQ0SETNSKZ27QMNBAK8ZTS6N","pid":1252,"client":"2","":"downstairs","session_id":"4b99ffc6-dedc-4362-8783-3fbc086ec5b6"}
5812025-03-23T06:09:26.632Z{"msg":"connecting to 127.0.0.1:8860","v":0,"name":"crucible","level":30,"time":"2025-03-23T06:09:24.921188205Z","hostname":"w-01JQ0SETNSKZ27QMNBAK8ZTS6N","pid":1252,"":"io task","client":"2","":"downstairs","session_id":"4b99ffc6-dedc-4362-8783-3fbc086ec5b6"}
5822025-03-23T06:09:26.632Z{"msg":"connecting to 127.0.0.1:8840","v":0,"name":"crucible","level":30,"time":"2025-03-23T06:09:24.921213901Z","hostname":"w-01JQ0SETNSKZ27QMNBAK8ZTS6N","pid":1252,"":"io task","client":"0","":"downstairs","session_id":"4b99ffc6-dedc-4362-8783-3fbc086ec5b6"}
5832025-03-23T06:09:26.632Z{"msg":"connecting to 127.0.0.1:8850","v":0,"name":"crucible","level":30,"time":"2025-03-23T06:09:24.921240696Z","hostname":"w-01JQ0SETNSKZ27QMNBAK8ZTS6N","pid":1252,"":"io task","client":"1","":"downstairs","session_id":"4b99ffc6-dedc-4362-8783-3fbc086ec5b6"}
5842025-03-23T06:09:26.632Z{"msg":"ds_connection connected from Ok(127.0.0.1:52683)","v":0,"name":"crucible","level":30,"time":"2025-03-23T06:09:24.92128162Z","hostname":"w-01JQ0SETNSKZ27QMNBAK8ZTS6N","pid":1252,"":"io task","client":"2","":"downstairs","session_id":"4b99ffc6-dedc-4362-8783-3fbc086ec5b6"}
5852025-03-23T06:09:26.632Z{"msg":"ds_connection connected from Ok(127.0.0.1:63047)","v":0,"name":"crucible","level":30,"time":"2025-03-23T06:09:24.921307296Z","hostname":"w-01JQ0SETNSKZ27QMNBAK8ZTS6N","pid":1252,"":"io task","client":"0","":"downstairs","session_id":"4b99ffc6-dedc-4362-8783-3fbc086ec5b6"}
5862025-03-23T06:09:26.632Z{"msg":"ds_connection connected from Ok(127.0.0.1:33081)","v":0,"name":"crucible","level":30,"time":"2025-03-23T06:09:24.921329953Z","hostname":"w-01JQ0SETNSKZ27QMNBAK8ZTS6N","pid":1252,"":"io task","client":"1","":"downstairs","session_id":"4b99ffc6-dedc-4362-8783-3fbc086ec5b6"}
5872025-03-23T06:09:26.632Z{"msg":"version negotiation from state Connecting { state: WaitForPromote, mode: New }","v":0,"name":"crucible","level":30,"time":"2025-03-23T06:09:24.921359178Z","hostname":"w-01JQ0SETNSKZ27QMNBAK8ZTS6N","pid":1252,"client":"0","":"downstairs","session_id":"4b99ffc6-dedc-4362-8783-3fbc086ec5b6"}
5882025-03-23T06:09:26.632Z{"msg":"version negotiation from state Connecting { state: WaitForPromote, mode: New }","v":0,"name":"crucible","level":30,"time":"2025-03-23T06:09:24.921385684Z","hostname":"w-01JQ0SETNSKZ27QMNBAK8ZTS6N","pid":1252,"client":"2","":"downstairs","session_id":"4b99ffc6-dedc-4362-8783-3fbc086ec5b6"}
5892025-03-23T06:09:26.632Z{"msg":"version negotiation from state Connecting { state: WaitForPromote, mode: New }","v":0,"name":"crucible","level":30,"time":"2025-03-23T06:09:24.921592061Z","hostname":"w-01JQ0SETNSKZ27QMNBAK8ZTS6N","pid":1252,"client":"1","":"downstairs","session_id":"4b99ffc6-dedc-4362-8783-3fbc086ec5b6"}
5902025-03-23T06:09:26.632Z{"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-23T06:09:24.921911782Z","hostname":"w-01JQ0SETNSKZ27QMNBAK8ZTS6N","pid":1252,"client":"0","":"downstairs","session_id":"4b99ffc6-dedc-4362-8783-3fbc086ec5b6"}
5912025-03-23T06:09:26.632Z{"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-23T06:09:24.922070897Z","hostname":"w-01JQ0SETNSKZ27QMNBAK8ZTS6N","pid":1252,"client":"1","":"downstairs","session_id":"4b99ffc6-dedc-4362-8783-3fbc086ec5b6"}
5922025-03-23T06:09:26.632Z{"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-23T06:09:24.922100682Z","hostname":"w-01JQ0SETNSKZ27QMNBAK8ZTS6N","pid":1252,"client":"2","":"downstairs","session_id":"4b99ffc6-dedc-4362-8783-3fbc086ec5b6"}
5932025-03-23T06:09:26.632Z{"msg":"Waiting for more clients to be ready","v":0,"name":"crucible","level":30,"time":"2025-03-23T06:09:24.922320328Z","hostname":"w-01JQ0SETNSKZ27QMNBAK8ZTS6N","pid":1252,"session_id":"4b99ffc6-dedc-4362-8783-3fbc086ec5b6"}
5942025-03-23T06:09:26.633Z{"msg":"Waiting for more clients to be ready","v":0,"name":"crucible","level":30,"time":"2025-03-23T06:09:24.922413093Z","hostname":"w-01JQ0SETNSKZ27QMNBAK8ZTS6N","pid":1252,"session_id":"4b99ffc6-dedc-4362-8783-3fbc086ec5b6"}
5952025-03-23T06:09:26.633Z{"msg":"[0]R flush_numbers: [5318, 5318, 5318, 5318, 5318]","v":0,"name":"crucible","level":30,"time":"2025-03-23T06:09:24.922508288Z","hostname":"w-01JQ0SETNSKZ27QMNBAK8ZTS6N","pid":1252,"":"downstairs","":"downstairs","session_id":"4b99ffc6-dedc-4362-8783-3fbc086ec5b6"}
5962025-03-23T06:09:26.633Z{"msg":"[0]R generation: [32, 32, 32, 32, 32]","v":0,"name":"crucible","level":30,"time":"2025-03-23T06:09:24.922539173Z","hostname":"w-01JQ0SETNSKZ27QMNBAK8ZTS6N","pid":1252,"":"downstairs","":"downstairs","session_id":"4b99ffc6-dedc-4362-8783-3fbc086ec5b6"}
5972025-03-23T06:09:26.633Z{"msg":"[0]R dirty: [false, false, false, false, false]","v":0,"name":"crucible","level":30,"time":"2025-03-23T06:09:24.922572598Z","hostname":"w-01JQ0SETNSKZ27QMNBAK8ZTS6N","pid":1252,"":"downstairs","":"downstairs","session_id":"4b99ffc6-dedc-4362-8783-3fbc086ec5b6"}
5982025-03-23T06:09:26.633Z{"msg":"[1]R flush_numbers: [5318, 5318, 5318, 5318, 5318]","v":0,"name":"crucible","level":30,"time":"2025-03-23T06:09:24.922606123Z","hostname":"w-01JQ0SETNSKZ27QMNBAK8ZTS6N","pid":1252,"":"downstairs","":"downstairs","session_id":"4b99ffc6-dedc-4362-8783-3fbc086ec5b6"}
5992025-03-23T06:09:26.633Z{"msg":"[1]R generation: [32, 32, 32, 32, 32]","v":0,"name":"crucible","level":30,"time":"2025-03-23T06:09:24.922630429Z","hostname":"w-01JQ0SETNSKZ27QMNBAK8ZTS6N","pid":1252,"":"downstairs","":"downstairs","session_id":"4b99ffc6-dedc-4362-8783-3fbc086ec5b6"}
6002025-03-23T06:09:26.633Z{"msg":"[1]R dirty: [false, false, false, false, false]","v":0,"name":"crucible","level":30,"time":"2025-03-23T06:09:24.922660694Z","hostname":"w-01JQ0SETNSKZ27QMNBAK8ZTS6N","pid":1252,"":"downstairs","":"downstairs","session_id":"4b99ffc6-dedc-4362-8783-3fbc086ec5b6"}
6012025-03-23T06:09:26.633Z{"msg":"[2]R flush_numbers: [5318, 5318, 5318, 5318, 5318]","v":0,"name":"crucible","level":30,"time":"2025-03-23T06:09:24.922684601Z","hostname":"w-01JQ0SETNSKZ27QMNBAK8ZTS6N","Wait for a query_work_queue command to finish before sending IO
6022025-03-23T06:09:26.633Zpid":1252,"":"downstairs","":"downstairs","session_id":"4b99ffc6-dedc-4362-8783-3fbc086ec5b6"}
6032025-03-23T06:09:26.633Z{"msg":"[2]R generation: [32, 32, 32, 32, 32]","v":0,"name":"crucible","level":30,"time":"2025-03-23T06:09:24.922724824Z","hostname":"w-01JQ0SETNSKZ27QMNBAK8ZTS6N","pid":1252,"":"downstairs","":"downstairs","session_id":"4b99ffc6-dedc-4362-8783-3fbc086ec5b6"}
6042025-03-23T06:09:26.633Z{"msg":"[2]R dirty: [false, false, false, false, false]","v":0,"name":"crucible","level":30,"time":"2025-03-23T06:09:24.922749491Z","hostname":"w-01JQ0SETNSKZ27QMNBAK8ZTS6N","pid":1252,"":"downstairs","":"downstairs","session_id":"4b99ffc6-dedc-4362-8783-3fbc086ec5b6"}
6052025-03-23T06:09:26.633Z{"msg":"Max found gen is 33","v":0,"name":"crucible","level":30,"time":"2025-03-23T06:09:24.922771897Z","hostname":"w-01JQ0SETNSKZ27QMNBAK8ZTS6N","pid":1252,"":"downstairs","":"downstairs","session_id":"4b99ffc6-dedc-4362-8783-3fbc086ec5b6"}
6062025-03-23T06:09:26.633Z{"msg":"Generation requested: 33 >= found:33","v":0,"name":"crucible","level":30,"time":"2025-03-23T06:09:24.922811671Z","hostname":"w-01JQ0SETNSKZ27QMNBAK8ZTS6N","pid":1252,"":"downstairs","":"downstairs","session_id":"4b99ffc6-dedc-4362-8783-3fbc086ec5b6"}
6072025-03-23T06:09:26.633Z{"msg":"Next flush: 5319","v":0,"name":"crucible","level":30,"time":"2025-03-23T06:09:24.922845206Z","hostname":"w-01JQ0SETNSKZ27QMNBAK8ZTS6N","pid":1252,"":"downstairs","":"downstairs","session_id":"4b99ffc6-dedc-4362-8783-3fbc086ec5b6"}
6082025-03-23T06:09:26.633Z{"msg":"All extents match","v":0,"name":"crucible","level":30,"time":"2025-03-23T06:09:24.922868772Z","hostname":"w-01JQ0SETNSKZ27QMNBAK8ZTS6N","pid":1252,"":"downstairs","":"downstairs","session_id":"4b99ffc6-dedc-4362-8783-3fbc086ec5b6"}
6092025-03-23T06:09:26.633Z{"msg":"No downstairs reconciliation required","v":0,"name":"crucible","level":30,"time":"2025-03-23T06:09:24.922895898Z","hostname":"w-01JQ0SETNSKZ27QMNBAK8ZTS6N","pid":1252,"session_id":"4b99ffc6-dedc-4362-8783-3fbc086ec5b6"}
6102025-03-23T06:09:26.633Z{"msg":"Transition from WaitQuorum to Active","v":0,"name":"crucible","level":30,"time":"2025-03-23T06:09:24.922917634Z","hostname":"w-01JQ0SETNSKZ27QMNBAK8ZTS6N","pid":1252,"client":"0","":"downstairs","session_id":"4b99ffc6-dedc-4362-8783-3fbc086ec5b6"}
6112025-03-23T06:09:26.633Z{"msg":"Transition from WaitQuorum to Active","v":0,"name":"crucible","level":30,"time":"2025-03-23T06:09:24.92294526Z","hostname":"w-01JQ0SETNSKZ27QMNBAK8ZTS6N","pid":1252,"client":"1","":"downstairs","session_id":"4b99ffc6-dedc-4362-8783-3fbc086ec5b6"}
6122025-03-23T06:09:26.633Z{"msg":"Transition from WaitQuorum to Active","v":0,"name":"crucible","level":30,"time":"2025-03-23T06:09:24.922968316Z","hostname":"w-01JQ0SETNSKZ27QMNBAK8ZTS6N","pid":1252,"client":"2","":"downstairs","session_id":"4b99ffc6-dedc-4362-8783-3fbc086ec5b6"}
6132025-03-23T06:09:26.633Z{"msg":"All required reconciliation work is completed","v":0,"name":"crucible","level":30,"time":"2025-03-23T06:09:24.922994922Z","hostname":"w-01JQ0SETNSKZ27QMNBAK8ZTS6N","pid":1252,"session_id":"4b99ffc6-dedc-4362-8783-3fbc086ec5b6"}
6142025-03-23T06:09:26.633Z{"msg":"Set Downstairs and Upstairs active after reconciliation","v":0,"name":"crucible","level":30,"time":"2025-03-23T06:09:24.923016559Z","hostname":"w-01JQ0SETNSKZ27QMNBAK8ZTS6N","pid":1252,"session_id":"4b99ffc6-dedc-4362-8783-3fbc086ec5b6"}
6152025-03-23T06:09:26.633Z{"msg":"12880125-a621-4a99-a1da-fb04ca65dd48 is now active with session: 4b99ffc6-dedc-4362-8783-3fbc086ec5b6","v":0,"name":"crucible","level":30,"time":"2025-03-23T06:09:24.923043874Z","hostname":"w-01JQ0SETNSKZ27QMNBAK8ZTS6N","pid":1252,"session_id":"4b99ffc6-dedc-4362-8783-3fbc086ec5b6"}
6162025-03-23T06:09:26.633Z{"msg":"Set Active after no reconciliation","v":0,"name":"crucible","level":30,"time":"2025-03-23T06:09:24.923064921Z","hostname":"w-01JQ0SETNSKZ27QMNBAK8ZTS6N","pid":1252,"session_id":"4b99ffc6-dedc-4362-8783-3fbc086ec5b6"}
6172025-03-23T06:09:26.633Z{"msg":"The guest has finished waiting for activation with:33","v":0,"name":"crucible","level":30,"time":"2025-03-23T06:09:24.923091377Z","hostname":"w-01JQ0SETNSKZ27QMNBAK8ZTS6N","pid":1252}
6182025-03-23T06:09:26.633Z{"msg":"Activated sub_volume 12880125-a621-4a99-a1da-fb04ca65dd48","v":0,"name":"crucible","level":30,"time":"2025-03-23T06:09:24.923111134Z","hostname":"w-01JQ0SETNSKZ27QMNBAK8ZTS6N","pid":1252}
6192025-03-23T06:09:26.633ZDisk: sv:2 bs:4096 ts:409600 tb:100 max_io:100 or 409600
6202025-03-23T06:09:26.633ZLoading write count information from file "/var/tmp/test_up-build/verify_file"
6212025-03-23T06:09:26.633ZRead and Verify all blocks (0..100 range:true)
6222025-03-23T06:09:26.710ZWrote out file "/var/tmp/test_up-build/verify_file"
6232025-03-23T06:09:26.710ZVerify test completed
6242025-03-23T06:09:26.713ZWrote out file "/var/tmp/test_up-build/verify_file"
6252025-03-23T06:09:26.713ZCLIENT: Tests done. All submitted work has been ACK'd
6262025-03-23T06:09:26.713Z----------------------------------------------------------------
6272025-03-23T06:09:26.713Z Crucible gen:33 GIO:true work queues: Upstairs:0 downstairs:1
6282025-03-23T06:09:26.713ZStates: Active Active Active
6292025-03-23T06:09:26.713ZJOBID ACK TYPE BKS/EXT DS:0 DS:1 DS:2 REPLAY
6302025-03-23T06:09:26.713Z 1000 Acked Read 50 Done Done Done false
6312025-03-23T06:09:26.713Z STATES DS:0 DS:1 DS:2 TOTAL
6322025-03-23T06:09:26.713Z Sent 0 0 0 0
6332025-03-23T06:09:26.713Z Done 1 1 1 3
6342025-03-23T06:09:26.713Z Skipped 0 0 0 0
6352025-03-23T06:09:26.713Z Error 0 0 0 0
6362025-03-23T06:09:26.713ZLast Flush: None None None
6372025-03-23T06:09:26.713ZDownstairs last five completed:
6382025-03-23T06:09:26.713ZUpstairs last five completed: 1000
6392025-03-23T06:09:26.713Z----------------------------------------------------------------
6402025-03-23T06:09:26.713Z Crucible gen:33 GIO:true work queues: Upstairs:0 downstairs:1
6412025-03-23T06:09:26.713ZStates: Active Active Active
6422025-03-23T06:09:26.713ZJOBID ACK TYPE BKS/EXT DS:0 DS:1 DS:2 REPLAY
6432025-03-23T06:09:26.713Z 1000 Acked Read 50 Done Done Done false
6442025-03-23T06:09:26.713Z STATES DS:0 DS:1 DS:2 TOTAL
6452025-03-23T06:09:26.713Z Sent 0 0 0 0
6462025-03-23T06:09:26.713Z Done 1 1 1 3
6472025-03-23T06:09:26.714Z Skipped 0 0 0 0
6482025-03-23T06:09:26.714Z Error 0 0 0 0
6492025-03-23T06:09:26.714ZLast Flush: None None None
6502025-03-23T06:09:26.714ZDownstairs last five completed:
6512025-03-23T06:09:26.714ZUpstairs last five completed: 1000
6522025-03-23T06:09:26.714ZCLIENT: Up:0 ds:2 act:6
6532025-03-23T06:09:30.713Z----------------------------------------------------------------
6542025-03-23T06:09:30.713Z Crucible gen:33 GIO:true work queues: Upstairs:0 downstairs:0
6552025-03-23T06:09:30.713ZDownstairs last five completed: 1001 1000
6562025-03-23T06:09:30.713ZUpstairs last five completed: 1001 1000
6572025-03-23T06:09:30.717Z----------------------------------------------------------------
6582025-03-23T06:09:30.717Z Crucible gen:33 GIO:true work queues: Upstairs:0 downstairs:0
6592025-03-23T06:09:30.717ZDownstairs last five completed: 1001 1000
6602025-03-23T06:09:30.717ZUpstairs last five completed: 1001 1000
6612025-03-23T06:09:30.717ZCLIENT: Up:0 ds:0 act:6
6622025-03-23T06:09:30.717ZCLIENT: All crucible jobs finished, exiting program
6632025-03-23T06:09:30.717Z{"msg":"Guest handle has been dropped","v":0,"name":"crucible","level":40,"time":"2025-03-23T06:09:29.004884654Z","hostname":"w-01JQ0SETNSKZ27QMNBAK8ZTS6N","pid":1252}
6642025-03-23T06:09:30.720ZRepair part 2 passed
6652025-03-23T06:09:30.723Z/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-23T06:09:30.737ZEXT BLOCKS GEN0 GEN1 GEN2 FL0 FL1 FL2 D0 D1 D2 DIFF
6672025-03-23T06:09:30.741Z 0 000-009 32 32 32 3997 3997 3997 F F F
6682025-03-23T06:09:30.741Z 1 010-019 32 32 32 3997 3997 3997 F F F
6692025-03-23T06:09:30.741Z 2 020-029 32 32 32 3997 3997 3997 F F F
6702025-03-23T06:09:30.741Z 3 030-039 32 32 32 3997 3997 3997 F F F
6712025-03-23T06:09:30.741Z 4 040-049 32 32 32 3997 3997 3997 F F F
6722025-03-23T06:09:30.741ZMax gen: 32, Max flush: 3997
6732025-03-23T06:09:30.744Zdump test passed
6742025-03-23T06:09:30.744Z/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-23T06:09:30.758Z Extent 1
6762025-03-23T06:09:30.761ZGEN 32 32 32
6772025-03-23T06:09:30.761ZFLUSH_ID 3997 3997 3997
6782025-03-23T06:09:30.761ZDIRTY
6792025-03-23T06:09:30.761Z
6802025-03-23T06:09:30.761ZBLOCK D0 D1 D2 C0 C1 C2 DIFF
6812025-03-23T06:09:30.761Z010 A A A A A A
6822025-03-23T06:09:30.765Z011 A A A A A A
6832025-03-23T06:09:30.765Z012 A A A A A A
6842025-03-23T06:09:30.765Z013 A A A A A A
6852025-03-23T06:09:30.768Z014 A A A A A A
6862025-03-23T06:09:30.768Z015 A A A A A A
6872025-03-23T06:09:30.771Z016 A A A A A A
6882025-03-23T06:09:30.771Z017 A A A A A A
6892025-03-23T06:09:30.771Z018 A A A A A A
6902025-03-23T06:09:30.774Z019 A A A A A A
6912025-03-23T06:09:30.777Zdump extent test passed
6922025-03-23T06:09:30.777Z/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-23T06:09:30.793ZExtent 2 Block in extent 0 Actual block 20
6942025-03-23T06:09:30.793Z
6952025-03-23T06:09:30.796Z DATA SHA256 VER
6962025-03-23T06:09:30.797Z------ ---------------------------------------------------------------- ---
6972025-03-23T06:09:30.797Z 0 83942e49cdd9365722bd7cef5848c913f98dcb6974d81b5f38cd718ae996bba7 A
6982025-03-23T06:09:30.797Z 1 83942e49cdd9365722bd7cef5848c913f98dcb6974d81b5f38cd718ae996bba7 A
6992025-03-23T06:09:30.797Z 2 83942e49cdd9365722bd7cef5848c913f98dcb6974d81b5f38cd718ae996bba7 A
7002025-03-23T06:09:30.797Z
7012025-03-23T06:09:30.797ZNONCES 0 1 2 DIFF
7022025-03-23T06:09:30.797Z------ ------------------------ ------------------------ ------------------------ -----
7032025-03-23T06:09:30.797Z 0 91adcbf76aaf044ec7b5eb50 91adcbf76aaf044ec7b5eb50 91adcbf76aaf044ec7b5eb50
7042025-03-23T06:09:30.797Z
7052025-03-23T06:09:30.797Z TAGS 0 1 2 DIFF
7062025-03-23T06:09:30.797Z------ -------------------------------- -------------------------------- -------------------------------- -----
7072025-03-23T06:09:30.797Z 0 1817009ae9011e02b32fae71b3fb5ea5 1817009ae9011e02b32fae71b3fb5ea5 1817009ae9011e02b32fae71b3fb5ea5
7082025-03-23T06:09:30.797Z
7092025-03-23T06:09:30.797ZHASHES 0 1 2 DIFF
7102025-03-23T06:09:30.797Z------ ---------------- ---------------- ---------------- -----
7112025-03-23T06:09:30.797Z
7122025-03-23T06:09:30.800Zdump block test passed
7132025-03-23T06:09:30.800ZInitial upstairs tests have completed, stopping all downstairs
7142025-03-23T06:09:35.864ZCreating 7 larger downstairs regions
7152025-03-23T06:09:36.050ZStarting 7 downstairs
7162025-03-23T06:09:41.058Zdsc restarted at PID: 1268
7172025-03-23T06:09:41.438ZNow do the replace-reconcile test
7182025-03-23T06:09:41.491ZUsing 8870 for the replacement port
7192025-03-23T06:12:35.476ZCompleted test: replace-reconcile
7202025-03-23T06:12:35.476ZNow do the replace-before-active test
7212025-03-23T06:16:08.206ZCompleted test: replace-before-active
7222025-03-23T06:16:08.210ZAll tests have completed, stopping all downstairs
7232025-03-23T06:16:08.268Z
7242025-03-23T06:16:08.268ZAll Tests have passed
7252025-03-23T06:16:08.272Z13:38 Test duration
7262025-03-23T06:16:08.272Z
7272025-03-23T06:16:08.272Zreal 13:37.553910993
7282025-03-23T06:16:08.272Zuser 18:22.623000114
7292025-03-23T06:16:08.272Zsys 24.508920369
7302025-03-23T06:16:08.272Ztrap 0.520495273
7312025-03-23T06:16:08.272Ztflt 0.038838487
7322025-03-23T06:16:08.272Zdflt 0.037485120
7332025-03-23T06:16:08.272Zkflt 0.001098226
7342025-03-23T06:16:08.272Zlock 25:35:47.465498479
7352025-03-23T06:16:08.272Zslp 1:14:40.678741847
7362025-03-23T06:16:08.272Zlat 1:56.947047178
7372025-03-23T06:16:08.272Zstop 0.209706652
7382025-03-23T06:16:08.272Z+ echo 'test-up-2region-encrypted ends'
7392025-03-23T06:16:08.272Ztest-up-2region-encrypted ends
7402025-03-23T06:16:13.276Zprocess exited: duration 826007 ms, exit code 0
7412025-03-23T06:16:13.276Zexec warning: : stdio descriptors remain open after task exit; waiting 60 seconds for them to close
7422025-03-23T06:17:13.335Zexec warning: : stdout descriptor may be held open by a background process; giving up!
7432025-03-23T06:17:13.335Zexec warning: : stderr descriptor may be held open by a background process; giving up!
 
7442025-03-23T06:17:13.348Zfound 17 output files
7452025-03-23T06:17:13.348Zuploading: /tmp/test_up-build/dsc-out.txt (51739 bytes)
7462025-03-23T06:17:14.362Zuploaded: /tmp/test_up-build/dsc-out.txt
7472025-03-23T06:17:14.362Zuploading: /tmp/test_up-build/test_up_out.txt (8400889 bytes)
7482025-03-23T06:17:15.500Zuploaded: /tmp/test_up-build/test_up_out.txt
7492025-03-23T06:17:15.503Zuploading: /tmp/test_up-build/dsc/downstairs-8810.txt (147256 bytes)
7502025-03-23T06:17:16.521Zuploaded: /tmp/test_up-build/dsc/downstairs-8810.txt
7512025-03-23T06:17:16.521Zuploading: /tmp/test_up-build/dsc/downstairs-8820.txt (144647 bytes)
7522025-03-23T06:17:17.539Zuploaded: /tmp/test_up-build/dsc/downstairs-8820.txt
7532025-03-23T06:17:17.539Zuploading: /tmp/test_up-build/dsc/downstairs-8830.txt (251027 bytes)
7542025-03-23T06:17:18.560Zuploaded: /tmp/test_up-build/dsc/downstairs-8830.txt
7552025-03-23T06:17:18.561Zuploading: /tmp/test_up-build/dsc/downstairs-8840.txt (139422 bytes)
7562025-03-23T06:17:19.580Zuploaded: /tmp/test_up-build/dsc/downstairs-8840.txt
7572025-03-23T06:17:19.580Zuploading: /tmp/test_up-build/dsc/downstairs-8850.txt (2491 bytes)
7582025-03-23T06:17:20.590Zuploaded: /tmp/test_up-build/dsc/downstairs-8850.txt
7592025-03-23T06:17:20.590Zuploading: /tmp/test_up-build/dsc/downstairs-8860.txt (33786 bytes)
7602025-03-23T06:17:21.603Zuploaded: /tmp/test_up-build/dsc/downstairs-8860.txt
7612025-03-23T06:17:21.603Zuploading: /tmp/test_up-build/dsc/downstairs-8870.txt (844693 bytes)
7622025-03-23T06:17:22.641Zuploaded: /tmp/test_up-build/dsc/downstairs-8870.txt
7632025-03-23T06:17:22.641Zuploading: /tmp/debug/df.txt (1270 bytes)
7642025-03-23T06:17:23.652Zuploaded: /tmp/debug/df.txt
7652025-03-23T06:17:23.652Zuploading: /tmp/debug/dtrace.txt (946604 bytes)
7662025-03-23T06:17:24.696Zuploaded: /tmp/debug/dtrace.txt
7672025-03-23T06:17:24.699Zuploading: /tmp/debug/iostat.txt (263202 bytes)
7682025-03-23T06:17:24.715Zupload warning: file "/tmp/debug/iostat.txt" changed size mid upload: 263202 -> 266480
7692025-03-23T06:17:25.724Zuploaded: /tmp/debug/iostat.txt
7702025-03-23T06:17:25.724Zuploading: /tmp/debug/mpstat.txt (641956 bytes)
7712025-03-23T06:17:25.752Zupload warning: file "/tmp/debug/mpstat.txt" changed size mid upload: 641956 -> 651407
7722025-03-23T06:17:26.760Zuploaded: /tmp/debug/mpstat.txt
7732025-03-23T06:17:26.761Zuploading: /tmp/debug/paging.txt (113841 bytes)
7742025-03-23T06:17:26.772Zupload warning: file "/tmp/debug/paging.txt" changed size mid upload: 113841 -> 115581
7752025-03-23T06:17:27.779Zuploaded: /tmp/debug/paging.txt
7762025-03-23T06:17:27.779Zuploading: /tmp/debug/prstat.txt (1247277 bytes)
7772025-03-23T06:17:27.823Zupload warning: file "/tmp/debug/prstat.txt" changed size mid upload: 1247277 -> 1265366
7782025-03-23T06:17:28.830Zuploaded: /tmp/debug/prstat.txt
7792025-03-23T06:17:28.830Zuploading: /tmp/debug/psrinfo.txt (1528 bytes)
7802025-03-23T06:17:29.840Zuploaded: /tmp/debug/psrinfo.txt
7812025-03-23T06:17:29.840Zuploading: /tmp/debug/upstairs-info.txt (182710 bytes)
7822025-03-23T06:17:30.862Zuploaded: /tmp/debug/upstairs-info.txt