01JPK30R3F2K00Y5DBDEJM6WWD: 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: 01JPK31A5Y4WVETBPGK21BWZWZ

Tags:

Artefacts:

Output:

SEQ GLOBAL TIME DETAILS
12025-03-17T22:33:07.607Zjob dependencies complete; ready to run (waiting for 13 m 45 s)
22025-03-17T22:34:03.051Zjob assigned to worker 01JPK3TSG4GD7HGEZJP118DX4C [factory aws, i-0a8872ed1534dc233] (queued for 55 s)
32025-03-17T22:34:10.839Zdownloading input: /input/build/work/bins/crucible-downstairs.gz
42025-03-17T22:34:12.039Zdownloaded input: /input/build/work/bins/crucible-downstairs.gz
52025-03-17T22:34:12.039Zdownloading input: /input/build/work/bins/crucible-hammer.gz
62025-03-17T22:34:13.114Zdownloaded input: /input/build/work/bins/crucible-hammer.gz
72025-03-17T22:34:13.118Zdownloading input: /input/build/work/bins/crutest.gz
82025-03-17T22:34:14.284Zdownloaded input: /input/build/work/bins/crutest.gz
92025-03-17T22:34:14.284Zdownloading input: /input/build/work/bins/dsc.gz
102025-03-17T22:34:14.986Zdownloaded input: /input/build/work/bins/dsc.gz
112025-03-17T22:34:14.989Zdownloading input: /input/build/work/scripts/perf-downstairs-tick.d
122025-03-17T22:34:15.008Zdownloaded input: /input/build/work/scripts/perf-downstairs-tick.d
132025-03-17T22:34:15.009Zdownloading input: /input/build/work/scripts/test_ds.sh
142025-03-17T22:34:15.027Zdownloaded input: /input/build/work/scripts/test_ds.sh
152025-03-17T22:34:15.027Zdownloading input: /input/build/work/scripts/test_live_repair.sh
162025-03-17T22:34:15.047Zdownloaded input: /input/build/work/scripts/test_live_repair.sh
172025-03-17T22:34:15.047Zdownloading input: /input/build/work/scripts/test_repair.sh
182025-03-17T22:34:15.067Zdownloaded input: /input/build/work/scripts/test_repair.sh
192025-03-17T22:34:15.067Zdownloading input: /input/build/work/scripts/test_replay.sh
202025-03-17T22:34:15.085Zdownloaded input: /input/build/work/scripts/test_replay.sh
212025-03-17T22:34:15.085Zdownloading input: /input/build/work/scripts/test_up.sh
222025-03-17T22:34:15.104Zdownloaded input: /input/build/work/scripts/test_up.sh
232025-03-17T22:34:15.105Zdownloading input: /input/build/work/scripts/upstairs_info.d
242025-03-17T22:34:15.124Zdownloaded input: /input/build/work/scripts/upstairs_info.d
252025-03-17T22:34:15.127Zdownloading input: /input/build/tmp/cargo-test-out.log
262025-03-17T22:34:15.810Zdownloaded input: /input/build/tmp/cargo-test-out.log
 
272025-03-17T22:34:15.810Zstarting task 0: "setup"
282025-03-17T22:34:15.818Z++ uname -s
292025-03-17T22:34:15.821Z+ kern=SunOS
302025-03-17T22:34:15.821Z+ build_user=build
312025-03-17T22:34:15.821Z+ build_uid=12345
322025-03-17T22:34:15.822Z+ work_dir=/work
332025-03-17T22:34:15.822Z+ input_dir=/input
342025-03-17T22:34:15.822Z+ [[ 0 == 12345 ]]
352025-03-17T22:34:15.822Z+ case "$kern" in
362025-03-17T22:34:15.822Z+ groupadd -g 12345 build
372025-03-17T22:34:15.825Z+ useradd -u 12345 -g build -d /home/build -s /bin/bash -c build -P 'Primary Administrator' build
382025-03-17T22:34:17.831Z+ zfs create -o mountpoint=/work rpool/work
392025-03-17T22:34:18.061Z++ awk '$2 == "/home" { print $3 }' /etc/mnttab
402025-03-17T22:34:18.065Z+ home_fs=zfs
412025-03-17T22:34:18.065Z+ [[ zfs == autofs ]]
422025-03-17T22:34:18.065Z+ mkdir -p /home/build
432025-03-17T22:34:18.069Z+ chown build:build /home/build /work
442025-03-17T22:34:19.068Z+ chmod 0700 /home/build /work
452025-03-17T22:34:19.071Zprocess exited: duration 3259 ms, exit code 0
 
462025-03-17T22:34:19.078Zstarting task 1: "authentication"
472025-03-17T22:34:19.095Zprocess exited: duration 17 ms, exit code 0
 
482025-03-17T22:34:19.102Zstarting task 2: "build"
492025-03-17T22:34:19.107Z+ banner cores
502025-03-17T22:34:19.124Z
512025-03-17T22:34:19.124Z #### #### ##### ###### ####
522025-03-17T22:34:19.124Z # # # # # # # #
532025-03-17T22:34:19.124Z # # # # # ##### ####
542025-03-17T22:34:19.124Z # # # ##### # #
552025-03-17T22:34:19.124Z # # # # # # # # #
562025-03-17T22:34:19.124Z #### #### # # ###### ####
572025-03-17T22:34:19.124Z
582025-03-17T22:34:19.127Z+ pfexec coreadm -i /tmp/core.%f.%p -g /tmp/core.%f.%p -e global -e log -e proc-setid -e global-setid
592025-03-17T22:34:19.132Z+ banner unpack
602025-03-17T22:34:19.136Z
612025-03-17T22:34:19.136Z # # # # ##### ## #### # #
622025-03-17T22:34:19.136Z # # ## # # # # # # # # #
632025-03-17T22:34:19.136Z # # # # # # # # # # ####
642025-03-17T22:34:19.136Z # # # # # ##### ###### # # #
652025-03-17T22:34:19.136Z # # # ## # # # # # # #
662025-03-17T22:34:19.136Z #### # # # # # #### # #
672025-03-17T22:34:19.136Z
682025-03-17T22:34:19.136Z+ mkdir -p /var/tmp/bins
692025-03-17T22:34:19.139Z+ for t in "$input/bins/"*.gz
702025-03-17T22:34:19.139Z++ basename /input/build/work/bins/crucible-downstairs.gz
712025-03-17T22:34:19.139Z+ b=crucible-downstairs.gz
722025-03-17T22:34:19.139Z+ b=crucible-downstairs
732025-03-17T22:34:19.139Z+ gunzip
742025-03-17T22:34:21.564Z+ chmod +x /var/tmp/bins/crucible-downstairs
752025-03-17T22:34:21.567Z+ for t in "$input/bins/"*.gz
762025-03-17T22:34:21.570Z++ basename /input/build/work/bins/crucible-hammer.gz
772025-03-17T22:34:21.570Z+ b=crucible-hammer.gz
782025-03-17T22:34:21.570Z+ b=crucible-hammer
792025-03-17T22:34:21.570Z+ gunzip
802025-03-17T22:34:23.783Z+ chmod +x /var/tmp/bins/crucible-hammer
812025-03-17T22:34:23.786Z+ for t in "$input/bins/"*.gz
822025-03-17T22:34:23.789Z++ basename /input/build/work/bins/crutest.gz
832025-03-17T22:34:23.789Z+ b=crutest.gz
842025-03-17T22:34:23.789Z+ b=crutest
852025-03-17T22:34:23.789Z+ gunzip
862025-03-17T22:34:26.132Z+ chmod +x /var/tmp/bins/crutest
872025-03-17T22:34:26.136Z+ for t in "$input/bins/"*.gz
882025-03-17T22:34:26.136Z++ basename /input/build/work/bins/dsc.gz
892025-03-17T22:34:26.136Z+ b=dsc.gz
902025-03-17T22:34:26.136Z+ b=dsc
912025-03-17T22:34:26.136Z+ gunzip
922025-03-17T22:34:27.522Z+ chmod +x /var/tmp/bins/dsc
932025-03-17T22:34:27.527Z+ export BINDIR=/var/tmp/bins
942025-03-17T22:34:27.527Z+ BINDIR=/var/tmp/bins
952025-03-17T22:34:27.527Z+ jobpid=1147
962025-03-17T22:34:27.527Z+ echo 'Setup debug logging'
972025-03-17T22:34:27.527ZSetup debug logging
982025-03-17T22:34:27.527Z+ mkdir /tmp/debug
992025-03-17T22:34:27.527Z+ sleep 3600
1002025-03-17T22:34:27.532Z+ psrinfo -v
1012025-03-17T22:34:27.532Z+ df -h
1022025-03-17T22:34:27.549Z+ prstat -d d -mLc 1
1032025-03-17T22:34:27.554Z+ iostat -T d -xn 1
1042025-03-17T22:34:27.554Z+ mpstat -T d 1
1052025-03-17T22:34:27.555Z+ vmstat -T d -p 1
1062025-03-17T22:34:27.555Z+ pfexec dtrace -Z -s /input/build/work/scripts/perf-downstairs-tick.d
1072025-03-17T22:34:27.555Z+ banner test_up_2r_encrypted
1082025-03-17T22:34:27.555Z+ pfexec dtrace -Z -s /input/build/work/scripts/upstairs_info.d
1092025-03-17T22:34:27.555Z #####
1102025-03-17T22:34:27.555Z ##### ###### #### ##### # # ##### # # #####
1112025-03-17T22:34:27.555Z # # # # # # # # # # #
1122025-03-17T22:34:27.555Z # ##### #### # # # # # ##### # #
1132025-03-17T22:34:27.555Z # # # # # # ##### # #####
1142025-03-17T22:34:27.555Z # # # # # # # # # # #
1152025-03-17T22:34:27.555Z # ###### #### # ####### #### # ####### ####### # #
1162025-03-17T22:34:27.556Z
1172025-03-17T22:34:27.560Z+ ptime -m bash /input/build/work/scripts/test_up.sh -r 2 -N encrypted
1182025-03-17T22:34:27.567Z/input/build/work
1192025-03-17T22:34:27.589ZUsing 2 region sets
1202025-03-17T22:34:27.589ZTurn off color for downstairs dump
1212025-03-17T22:34:27.606ZUpstairs using key: iyNjT3xeuGYhhftr21OU3I2u+/KzkJyUMqiH19BBbu8=
1222025-03-17T22:34:27.612Zdsc output goes to /tmp/test_up-build/dsc-out.txt
1232025-03-17T22:34:27.612ZCreating 6 downstairs regions
1242025-03-17T22:34:27.957ZStarting 6 downstairs
1252025-03-17T22:34:27.961Zdsc started at PID: 1195
1262025-03-17T22:34:34.259ZDisable automatic restart on all downstairs
1272025-03-17T22:34:34.265Z
1282025-03-17T22:34:34.265ZBegin tests, output goes to /tmp/test_up-build/test_up_out.txt
1292025-03-17T22:34:34.265ZRunning test: span
1302025-03-17T22:34:37.512ZCompleted test: span
1312025-03-17T22:34:42.521ZRunning test: big
1322025-03-17T22:34:47.115ZCompleted test: big
1332025-03-17T22:34:52.123ZRunning test: dep
1342025-03-17T22:35:25.888ZCompleted test: dep
1352025-03-17T22:35:30.896ZRunning test: balloon
1362025-03-17T22:39:44.640ZCompleted test: balloon
1372025-03-17T22:39:49.647ZRunning test: deactivate
1382025-03-17T22:40:47.962ZCompleted test: deactivate
1392025-03-17T22:40:49.387ZRunning hammer
1402025-03-17T22:41:06.909ZRun repair tests
1412025-03-17T22:41:06.913Z/var/tmp/bins/crutest fill -g 31 -q --key iyNjT3xeuGYhhftr21OU3I2u+/KzkJyUMqiH19BBbu8= --dsc 127.0.0.1:9998 --verify-out /var/tmp/test_up-build/verify_file
1422025-03-17T22:41:06.969Z{"msg":"Use this region info from dsc: RegionExtentInfo { block_size: 4096, blocks_per_extent: 10, extent_count: 5 }","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:41:05.986507623Z","hostname":"w-01JPK3TSG4GD7HGEZJP118DX4C","pid":1238,"task":"crutest"}
1432025-03-17T22:41:06.973Z{"msg":"dsc has 6 regions. This means 2 sub_volumes","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:41:05.987053821Z","hostname":"w-01JPK3TSG4GD7HGEZJP118DX4C","pid":1238,"task":"crutest"}
1442025-03-17T22:41:06.973Z{"msg":"SV 0 has targets: [127.0.0.1:8810, 127.0.0.1:8820, 127.0.0.1:8830]","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:41:05.988796988Z","hostname":"w-01JPK3TSG4GD7HGEZJP118DX4C","pid":1238,"task":"crutest"}
1452025-03-17T22:41:06.973Z{"msg":"Upstairs starts","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:41:05.989009888Z","hostname":"w-01JPK3TSG4GD7HGEZJP118DX4C","pid":1238}
1462025-03-17T22:41:06.974Z{"msg":"Crucible Version: BuildInfo {\n version: \"0.0.1\",\n git_sha: \"45feeae3dd1bdcd88dce11a80acb5415f57b38bc\",\n git_commit_timestamp: \"2025-03-17T22:11:58.000000000Z\",\n git_branch: \"renovate/opentelemetry-0.x\",\n rustc_semver: \"1.84.0\",\n rustc_channel: \"stable\",\n rustc_host_triple: \"x86_64-unknown-illumos\",\n rustc_commit_sha: \"9fc6b43126469e3858e2fe86cafb4f0fd5068869\",\n cargo_triple: \"x86_64-unknown-illumos\",\n debug: true,\n opt_level: 0,\n}","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:41:05.98905617Z","hostname":"w-01JPK3TSG4GD7HGEZJP118DX4C","pid":1238}
1472025-03-17T22:41:06.974Z{"msg":"Upstairs <-> Downstairs Message Version: 13","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:41:05.989080785Z","hostname":"w-01JPK3TSG4GD7HGEZJP118DX4C","pid":1238}
1482025-03-17T22:41:06.974Z{"msg":"Using region definition RegionDefinition { block_size: 4096, extent_size: Block { value: 10, shift: 12 }, extent_count: 5, uuid: 00000000-0000-0000-0000-000000000000, encrypted: true, database_read_version: 1, database_write_version: 1 }","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:41:05.989096423Z","hostname":"w-01JPK3TSG4GD7HGEZJP118DX4C","pid":1238}
1492025-03-17T22:41:06.974Z{"msg":"Crucible dcf25989-6c95-4947-b73e-3f3b7e4422f7 has session id: c526d7ed-44dc-40a1-8fd1-435ebd0ab57f","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:41:05.989726546Z","hostname":"w-01JPK3TSG4GD7HGEZJP118DX4C","pid":1238,"session_id":"c526d7ed-44dc-40a1-8fd1-435ebd0ab57f"}
1502025-03-17T22:41:06.974Z{"msg":"Upstairs opts: Upstairs UUID: dcf25989-6c95-4947-b73e-3f3b7e4422f7, Targets: [127.0.0.1:8810, 127.0.0.1:8820, 127.0.0.1:8830], lossy: false, flush_timeout: None, key populated: true, cert_pem populated: false, key_pem populated: false, root_cert_pem populated: false, Control: None, read_only: false","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:41:05.989769727Z","hostname":"w-01JPK3TSG4GD7HGEZJP118DX4C","pid":1238,"session_id":"c526d7ed-44dc-40a1-8fd1-435ebd0ab57f"}
1512025-03-17T22:41:06.974Z{"msg":"Crucible stats registered with UUID: dcf25989-6c95-4947-b73e-3f3b7e4422f7","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:41:05.989788644Z","hostname":"w-01JPK3TSG4GD7HGEZJP118DX4C","pid":1238,"session_id":"c526d7ed-44dc-40a1-8fd1-435ebd0ab57f"}
1522025-03-17T22:41:06.974Z{"msg":"could not find Downstairs address for Nexus","v":0,"name":"crucible","level":40,"time":"2025-03-17T22:41:05.989804071Z","hostname":"w-01JPK3TSG4GD7HGEZJP118DX4C","pid":1238,"session_id":"c526d7ed-44dc-40a1-8fd1-435ebd0ab57f"}
1532025-03-17T22:41:06.979Z{"msg":"SV 1 has targets: [127.0.0.1:8840, 127.0.0.1:8850, 127.0.0.1:8860]","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:41:05.991831295Z","hostname":"w-01JPK3TSG4GD7HGEZJP118DX4C","pid":1238,"task":"crutest"}
1542025-03-17T22:41:06.979Z{"msg":"Upstairs starts","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:41:05.991937896Z","hostname":"w-01JPK3TSG4GD7HGEZJP118DX4C","pid":1238}
1552025-03-17T22:41:06.979Z{"msg":"Crucible Version: BuildInfo {\n version: \"0.0.1\",\n git_sha: \"45feeae3dd1bdcd88dce11a80acb5415f57b38bc\",\n git_commit_timestamp: \"2025-03-17T22:11:58.000000000Z\",\n git_branch: \"renovate/opentelemetry-0.x\",\n rustc_semver: \"1.84.0\",\n rustc_channel: \"stable\",\n rustc_host_triple: \"x86_64-unknown-illumos\",\n rustc_commit_sha: \"9fc6b43126469e3858e2fe86cafb4f0fd5068869\",\n cargo_triple: \"x86_64-unknown-illumos\",\n debug: true,\n opt_level: 0,\n}","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:41:05.991980708Z","hostname":"w-01JPK3TSG4GD7HGEZJP118DX4C","pid":1238}
1562025-03-17T22:41:06.979Z{"msg":"Upstairs <-> Downstairs Message Version: 13","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:41:05.992004963Z","hostname":"w-01JPK3TSG4GD7HGEZJP118DX4C","pid":1238}
1572025-03-17T22:41:06.979Z{"msg":"Using region definition RegionDefinition { block_size: 4096, extent_size: Block { value: 10, shift: 12 }, extent_count: 5, uuid: 00000000-0000-0000-0000-000000000000, encrypted: true, database_read_version: 1, database_write_version: 1 }","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:41:05.99202259Z","hostname":"w-01JPK3TSG4GD7HGEZJP118DX4C","pid":1238}
1582025-03-17T22:41:06.979Z{"msg":"Crucible dcf25989-6c95-4947-b73e-3f3b7e4422f7 has session id: 61c87861-9ffe-4444-b1f3-53c1d8ad78bf","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:41:05.992355468Z","hostname":"w-01JPK3TSG4GD7HGEZJP118DX4C","pid":1238,"session_id":"61c87861-9ffe-4444-b1f3-53c1d8ad78bf"}
1592025-03-17T22:41:06.979Z{"msg":"Upstairs opts: Upstairs UUID: dcf25989-6c95-4947-b73e-3f3b7e4422f7, Targets: [127.0.0.1:8840, 127.0.0.1:8850, 127.0.0.1:8860], lossy: false, flush_timeout: None, key populated: true, cert_pem populated: false, key_pem populated: false, root_cert_pem populated: false, Control: None, read_only: false","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:41:05.992402699Z","hostname":"w-01JPK3TSG4GD7HGEZJP118DX4C","pid":1238,"session_id":"61c87861-9ffe-4444-b1f3-53c1d8ad78bf"}
1602025-03-17T22:41:06.980Z{"msg":"Crucible stats registered with UUID: dcf25989-6c95-4947-b73e-3f3b7e4422f7","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:41:05.992446781Z","hostname":"w-01JPK3TSG4GD7HGEZJP118DX4C","pid":1238,"session_id":"61c87861-9ffe-4444-b1f3-53c1d8ad78bf"}
1612025-03-17T22:41:06.980Z{"msg":"could not find Downstairs address for Nexus","v":0,"name":"crucible","level":40,"time":"2025-03-17T22:41:05.992492283Z","hostname":"w-01JPK3TSG4GD7HGEZJP118DX4C","pid":1238,"session_id":"61c87861-9ffe-4444-b1f3-53c1d8ad78bf"}
1622025-03-17T22:41:06.980Z{"msg":"Downstairs in volume = 6","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:41:05.993122016Z","hostname":"w-01JPK3TSG4GD7HGEZJP118DX4C","pid":1238,"task":"crutest"}
1632025-03-17T22:41:06.980Z{"msg":"The guest has requested activation with gen:31","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:41:05.993165618Z","hostname":"w-01JPK3TSG4GD7HGEZJP118DX4C","pid":1238}
1642025-03-17T22:41:06.980Z{"msg":"dcf25989-6c95-4947-b73e-3f3b7e4422f7 active request set","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:41:05.993257571Z","hostname":"w-01JPK3TSG4GD7HGEZJP118DX4C","pid":1238,"session_id":"c526d7ed-44dc-40a1-8fd1-435ebd0ab57f"}
1652025-03-17T22:41:06.980Z{"msg":"sending connect oneshot to client","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:41:05.993286026Z","hostname":"w-01JPK3TSG4GD7HGEZJP118DX4C","pid":1238,"client":"0","":"downstairs","session_id":"c526d7ed-44dc-40a1-8fd1-435ebd0ab57f"}
1662025-03-17T22:41:06.980Z{"msg":"client set_active_request while in Connecting { state: Start { auto_promote: true }, mode: New }; waiting...","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:41:05.993334497Z","hostname":"w-01JPK3TSG4GD7HGEZJP118DX4C","pid":1238,"client":"0","":"downstairs","session_id":"c526d7ed-44dc-40a1-8fd1-435ebd0ab57f"}
1672025-03-17T22:41:06.980Z{"msg":"sending connect oneshot to client","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:41:05.993373219Z","hostname":"w-01JPK3TSG4GD7HGEZJP118DX4C","pid":1238,"client":"1","":"downstairs","session_id":"c526d7ed-44dc-40a1-8fd1-435ebd0ab57f"}
1682025-03-17T22:41:06.980Z{"msg":"client set_active_request while in Connecting { state: Start { auto_promote: true }, mode: New }; waiting...","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:41:05.993404544Z","hostname":"w-01JPK3TSG4GD7HGEZJP118DX4C","pid":1238,"client":"1","":"downstairs","session_id":"c526d7ed-44dc-40a1-8fd1-435ebd0ab57f"}
1692025-03-17T22:41:06.980Z{"msg":"sending connect oneshot to client","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:41:05.993464213Z","hostname":"w-01JPK3TSG4GD7HGEZJP118DX4C","pid":1238,"client":"2","":"downstairs","session_id":"c526d7ed-44dc-40a1-8fd1-435ebd0ab57f"}
1702025-03-17T22:41:06.980Z{"msg":"client set_active_request while in Connecting { state: Start { auto_promote: true }, mode: New }; waiting...","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:41:05.993498206Z","hostname":"w-01JPK3TSG4GD7HGEZJP118DX4C","pid":1238,"client":"2","":"downstairs","session_id":"c526d7ed-44dc-40a1-8fd1-435ebd0ab57f"}
1712025-03-17T22:41:06.980Z{"msg":"connecting to 127.0.0.1:8830","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:41:05.993522492Z","hostname":"w-01JPK3TSG4GD7HGEZJP118DX4C","pid":1238,"":"io task","client":"2","":"downstairs","session_id":"c526d7ed-44dc-40a1-8fd1-435ebd0ab57f"}
1722025-03-17T22:41:06.980Z{"msg":"connecting to 127.0.0.1:8810","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:41:05.993555146Z","hostname":"w-01JPK3TSG4GD7HGEZJP118DX4C","pid":1238,"":"io task","client":"0","":"downstairs","session_id":"c526d7ed-44dc-40a1-8fd1-435ebd0ab57f"}
1732025-03-17T22:41:06.980Z{"msg":"connecting to 127.0.0.1:8820","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:41:05.993577252Z","hostname":"w-01JPK3TSG4GD7HGEZJP118DX4C","pid":1238,"":"io task","client":"1","":"downstairs","session_id":"c526d7ed-44dc-40a1-8fd1-435ebd0ab57f"}
1742025-03-17T22:41:06.981Z{"msg":"ds_connection connected from Ok(127.0.0.1:64417)","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:41:05.993611375Z","hostname":"w-01JPK3TSG4GD7HGEZJP118DX4C","pid":1238,"":"io task","client":"2","":"downstairs","session_id":"c526d7ed-44dc-40a1-8fd1-435ebd0ab57f"}
1752025-03-17T22:41:06.981Z{"msg":"ds_connection connected from Ok(127.0.0.1:42206)","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:41:05.993647039Z","hostname":"w-01JPK3TSG4GD7HGEZJP118DX4C","pid":1238,"":"io task","client":"0","":"downstairs","session_id":"c526d7ed-44dc-40a1-8fd1-435ebd0ab57f"}
1762025-03-17T22:41:06.981Z{"msg":"ds_connection connected from Ok(127.0.0.1:65040)","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:41:05.993763997Z","hostname":"w-01JPK3TSG4GD7HGEZJP118DX4C","pid":1238,"":"io task","client":"1","":"downstairs","session_id":"c526d7ed-44dc-40a1-8fd1-435ebd0ab57f"}
1772025-03-17T22:41:06.981Z{"msg":"version negotiation from state Connecting { state: WaitForPromote, mode: New }","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:41:05.99439386Z","hostname":"w-01JPK3TSG4GD7HGEZJP118DX4C","pid":1238,"client":"1","":"downstairs","session_id":"c526d7ed-44dc-40a1-8fd1-435ebd0ab57f"}
1782025-03-17T22:41:06.981Z{"msg":"version negotiation from state Connecting { state: WaitForPromote, mode: New }","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:41:05.994431963Z","hostname":"w-01JPK3TSG4GD7HGEZJP118DX4C","pid":1238,"client":"2","":"downstairs","session_id":"c526d7ed-44dc-40a1-8fd1-435ebd0ab57f"}
1792025-03-17T22:41:06.981Z{"msg":"version negotiation from state Connecting { state: WaitForPromote, mode: New }","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:41:05.994478205Z","hostname":"w-01JPK3TSG4GD7HGEZJP118DX4C","pid":1238,"client":"0","":"downstairs","session_id":"c526d7ed-44dc-40a1-8fd1-435ebd0ab57f"}
1802025-03-17T22:41:06.981Z{"msg":"downstairs client at Some(127.0.0.1:8820) has region UUID 12345678-0000-0000-0000-000000008820","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:41:05.995050208Z","hostname":"w-01JPK3TSG4GD7HGEZJP118DX4C","pid":1238,"client":"1","":"downstairs","session_id":"c526d7ed-44dc-40a1-8fd1-435ebd0ab57f"}
1812025-03-17T22:41:06.981Z{"msg":"downstairs client at Some(127.0.0.1:8830) has region UUID 12345678-0000-0000-0000-000000008830","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:41:05.99509422Z","hostname":"w-01JPK3TSG4GD7HGEZJP118DX4C","pid":1238,"client":"2","":"downstairs","session_id":"c526d7ed-44dc-40a1-8fd1-435ebd0ab57f"}
1822025-03-17T22:41:06.981Z{"msg":"downstairs client at Some(127.0.0.1:8810) has region UUID 12345678-0000-0000-0000-000000008810","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:41:05.995115866Z","hostname":"w-01JPK3TSG4GD7HGEZJP118DX4C","pid":1238,"client":"0","":"downstairs","session_id":"c526d7ed-44dc-40a1-8fd1-435ebd0ab57f"}
1832025-03-17T22:41:06.981Z{"msg":"Waiting for more clients to be ready","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:41:05.995515592Z","hostname":"w-01JPK3TSG4GD7HGEZJP118DX4C","pid":1238,"session_id":"c526d7ed-44dc-40a1-8fd1-435ebd0ab57f"}
1842025-03-17T22:41:06.981Z{"msg":"Waiting for more clients to be ready","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:41:05.995554295Z","hostname":"w-01JPK3TSG4GD7HGEZJP118DX4C","pid":1238,"session_id":"c526d7ed-44dc-40a1-8fd1-435ebd0ab57f"}
1852025-03-17T22:41:06.988Z{"msg":"[0]R flush_numbers: [4000, 4000, 4000, 4000, 4000]","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:41:05.995626692Z","hostname":"w-01JPK3TSG4GD7HGEZJP118DX4C","pid":1238,"":"downstairs","":"downstairs","session_id":"c526d7ed-44dc-40a1-8fd1-435ebd0ab57f"}
1862025-03-17T22:41:06.988Z{"msg":"[0]R generation: [25, 25, 25, 25, 25]","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:41:05.995654806Z","hostname":"w-01JPK3TSG4GD7HGEZJP118DX4C","pid":1238,"":"downstairs","":"downstairs","session_id":"c526d7ed-44dc-40a1-8fd1-435ebd0ab57f"}
1872025-03-17T22:41:06.988Z{"msg":"[0]R dirty: [false, false, false, false, false]","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:41:05.995669664Z","hostname":"w-01JPK3TSG4GD7HGEZJP118DX4C","pid":1238,"":"downstairs","":"downstairs","session_id":"c526d7ed-44dc-40a1-8fd1-435ebd0ab57f"}
1882025-03-17T22:41:06.988Z{"msg":"[1]R flush_numbers: [4000, 4000, 4000, 4000, 4000]","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:41:05.995683221Z","hostname":"w-01JPK3TSG4GD7HGEZJP118DX4C","pid":1238,"":"downstairs","":"downstairs","session_id":"c526d7ed-44dc-40a1-8fd1-435ebd0ab57f"}
1892025-03-17T22:41:06.988Z{"msg":"[1]R generation: [25, 25, 25, 25, 25]","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:41:05.995703537Z","hostname":"w-01JPK3TSG4GD7HGEZJP118DX4C","pid":1238,"":"downstairs","":"downstairs","session_id":"c526d7ed-44dc-40a1-8fd1-435ebd0ab57f"}
1902025-03-17T22:41:06.988Z{"msg":"[1]R dirty: [false, false, false, false, false]","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:41:05.995718075Z","hostname":"w-01JPK3TSG4GD7HGEZJP118DX4C","pid":1238,"":"downstairs","":"downstairs","session_id":"c526d7ed-44dc-40a1-8fd1-435ebd0ab57f"}
1912025-03-17T22:41:06.988Z{"msg":"[2]R flush_numbers: [4000, 4000, 4000, 4000, 4000]","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:41:05.995738471Z","hostname":"w-01JPK3TSG4GD7HGEZJP118DX4C","pid":1238,"":"downstairs","":"downstairs","session_id":"c526d7ed-44dc-40a1-8fd1-435ebd0ab57f"}
1922025-03-17T22:41:06.988Z{"msg":"[2]R generation: [25, 25, 25, 25, 25]","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:41:05.995751968Z","hostname":"w-01JPK3TSG4GD7HGEZJP118DX4C","pid":1238,"":"downstairs","":"downstairs","session_id":"c526d7ed-44dc-40a1-8fd1-435ebd0ab57f"}
1932025-03-17T22:41:06.988Z{"msg":"[2]R dirty: [false, false, false, false, false]","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:41:05.995771735Z","hostname":"w-01JPK3TSG4GD7HGEZJP118DX4C","pid":1238,"":"downstairs","":"downstairs","session_id":"c526d7ed-44dc-40a1-8fd1-435ebd0ab57f"}
1942025-03-17T22:41:06.988Z{"msg":"Max found gen is 26","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:41:05.995784942Z","hostname":"w-01JPK3TSG4GD7HGEZJP118DX4C","pid":1238,"":"downstairs","":"downstairs","session_id":"c526d7ed-44dc-40a1-8fd1-435ebd0ab57f"}
1952025-03-17T22:41:06.989Z{"msg":"Generation requested: 31 >= found:26","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:41:05.995813437Z","hostname":"w-01JPK3TSG4GD7HGEZJP118DX4C","pid":1238,"":"downstairs","":"downstairs","session_id":"c526d7ed-44dc-40a1-8fd1-435ebd0ab57f"}
1962025-03-17T22:41:06.989Z{"msg":"Next flush: 4001","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:41:05.99585113Z","hostname":"w-01JPK3TSG4GD7HGEZJP118DX4C","pid":1238,"":"downstairs","":"downstairs","session_id":"c526d7ed-44dc-40a1-8fd1-435ebd0ab57f"}
1972025-03-17T22:41:06.989Z{"msg":"All extents match","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:41:05.995875586Z","hostname":"w-01JPK3TSG4GD7HGEZJP118DX4C","pid":1238,"":"downstairs","":"downstairs","session_id":"c526d7ed-44dc-40a1-8fd1-435ebd0ab57f"}
1982025-03-17T22:41:06.989Z{"msg":"No downstairs reconciliation required","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:41:05.99590471Z","hostname":"w-01JPK3TSG4GD7HGEZJP118DX4C","pid":1238,"session_id":"c526d7ed-44dc-40a1-8fd1-435ebd0ab57f"}
1992025-03-17T22:41:06.989Z{"msg":"Transition from WaitQuorum to Active","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:41:05.995926476Z","hostname":"w-01JPK3TSG4GD7HGEZJP118DX4C","pid":1238,"client":"0","":"downstairs","session_id":"c526d7ed-44dc-40a1-8fd1-435ebd0ab57f"}
2002025-03-17T22:41:06.989Z{"msg":"Transition from WaitQuorum to Active","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:41:05.99595781Z","hostname":"w-01JPK3TSG4GD7HGEZJP118DX4C","pid":1238,"client":"1","":"downstairs","session_id":"c526d7ed-44dc-40a1-8fd1-435ebd0ab57f"}
2012025-03-17T22:41:06.989Z{"msg":"Transition from WaitQuorum to Active","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:41:05.995980116Z","hostname":"w-01JPK3TSG4GD7HGEZJP118DX4C","pid":1238,"client":"2","":"downstairs","session_id":"c526d7ed-44dc-40a1-8fd1-435ebd0ab57f"}
2022025-03-17T22:41:06.989Z{"msg":"All required reconciliation work is completed","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:41:05.996015529Z","hostname":"w-01JPK3TSG4GD7HGEZJP118DX4C","pid":1238,"session_id":"c526d7ed-44dc-40a1-8fd1-435ebd0ab57f"}
2032025-03-17T22:41:06.989Z{"msg":"Set Downstairs and Upstairs active after reconciliation","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:41:05.996040015Z","hostname":"w-01JPK3TSG4GD7HGEZJP118DX4C","pid":1238,"session_id":"c526d7ed-44dc-40a1-8fd1-435ebd0ab57f"}
2042025-03-17T22:41:06.989Z{"msg":"dcf25989-6c95-4947-b73e-3f3b7e4422f7 is now active with session: c526d7ed-44dc-40a1-8fd1-435ebd0ab57f","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:41:05.996263794Z","hostname":"w-01JPK3TSG4GD7HGEZJP118DX4C","pid":1238,"session_id":"c526d7ed-44dc-40a1-8fd1-435ebd0ab57f"}
2052025-03-17T22:41:06.989Z{"msg":"Set Active after no reconciliation","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:41:05.996304696Z","hostname":"w-01JPK3TSG4GD7HGEZJP118DX4C","pid":1238,"session_id":"c526d7ed-44dc-40a1-8fd1-435ebd0ab57f"}
2062025-03-17T22:41:06.989Z{"msg":"The guest has finished waiting for activation with:31","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:41:05.996322752Z","hostname":"w-01JPK3TSG4GD7HGEZJP118DX4C","pid":1238}
2072025-03-17T22:41:06.989Z{"msg":"Activated sub_volume dcf25989-6c95-4947-b73e-3f3b7e4422f7","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:41:05.996341609Z","hostname":"w-01JPK3TSG4GD7HGEZJP118DX4C","pid":1238}
2082025-03-17T22:41:06.989Z{"msg":"dcf25989-6c95-4947-b73e-3f3b7e4422f7 active request set","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:41:05.996386191Z","hostname":"w-01JPK3TSG4GD7HGEZJP118DX4C","pid":1238,"session_id":"61c87861-9ffe-4444-b1f3-53c1d8ad78bf"}
2092025-03-17T22:41:06.989Z{"msg":"sending connect oneshot to client","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:41:05.996407747Z","hostname":"w-01JPK3TSG4GD7HGEZJP118DX4C","pid":1238,"client":"0","":"downstairs","session_id":"61c87861-9ffe-4444-b1f3-53c1d8ad78bf"}
2102025-03-17T22:41:06.989Z{"msg":"The guest has requested activation with gen:31","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:41:05.996441101Z","hostname":"w-01JPK3TSG4GD7HGEZJP118DX4C","pid":1238}
2112025-03-17T22:41:06.989Z{"msg":"client set_active_request while in Connecting { state: Start { auto_promote: true }, mode: New }; waiting...","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:41:05.996463326Z","hostname":"w-01JPK3TSG4GD7HGEZJP118DX4C","pid":1238,"client":"0","":"downstairs","session_id":"61c87861-9ffe-4444-b1f3-53c1d8ad78bf"}
2122025-03-17T22:41:06.989Z{"msg":"sending connect oneshot to client","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:41:05.996486982Z","hostname":"w-01JPK3TSG4GD7HGEZJP118DX4C","pid":1238,"client":"1","":"downstairs","session_id":"61c87861-9ffe-4444-b1f3-53c1d8ad78bf"}
2132025-03-17T22:41:06.989Z{"msg":"client set_active_request while in Connecting { state: Start { auto_promote: true }, mode: New }; waiting...","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:41:05.996512537Z","hostname":"w-01JPK3TSG4GD7HGEZJP118DX4C","pid":1238,"client":"1","":"downstairs","session_id":"61c87861-9ffe-4444-b1f3-53c1d8ad78bf"}
2142025-03-17T22:41:06.989Z{"msg":"sending connect oneshot to client","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:41:05.996533224Z","hostname":"w-01JPK3TSG4GD7HGEZJP118DX4C","pid":1238,"client":"2","":"downstairs","session_id":"61c87861-9ffe-4444-b1f3-53c1d8ad78bf"}
2152025-03-17T22:41:06.989Z{"msg":"client set_active_request while in Connecting { state: Start { auto_promote: true }, mode: New }; waiting...","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:41:05.996570526Z","hostname":"w-01JPK3TSG4GD7HGEZJP118DX4C","pid":1238,"client":"2","":"downstairs","session_id":"61c87861-9ffe-4444-b1f3-53c1d8ad78bf"}
2162025-03-17T22:41:06.989Z{"msg":"connecting to 127.0.0.1:8860","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:41:05.996596322Z","hostname":"w-01JPK3TSG4GD7HGEZJP118DX4C","pid":1238,"":"io task","client":"2","":"downstairs","session_id":"61c87861-9ffe-4444-b1f3-53c1d8ad78bf"}
2172025-03-17T22:41:06.989Z{"msg":"connecting to 127.0.0.1:8840","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:41:05.996620197Z","hostname":"w-01JPK3TSG4GD7HGEZJP118DX4C","pid":1238,"":"io task","client":"0","":"downstairs","session_id":"61c87861-9ffe-4444-b1f3-53c1d8ad78bf"}
2182025-03-17T22:41:06.989Z{"msg":"connecting to 127.0.0.1:8850","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:41:05.996642953Z","hostname":"w-01JPK3TSG4GD7HGEZJP118DX4C","pid":1238,"":"io task","client":"1","":"downstairs","session_id":"61c87861-9ffe-4444-b1f3-53c1d8ad78bf"}
2192025-03-17T22:41:06.989Z{"msg":"ds_connection connected from Ok(127.0.0.1:62501)","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:41:05.996680426Z","hostname":"w-01JPK3TSG4GD7HGEZJP118DX4C","pid":1238,"":"io task","client":"2","":"downstairs","session_id":"61c87861-9ffe-4444-b1f3-53c1d8ad78bf"}
2202025-03-17T22:41:06.989Z{"msg":"ds_connection connected from Ok(127.0.0.1:42011)","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:41:05.996707421Z","hostname":"w-01JPK3TSG4GD7HGEZJP118DX4C","pid":1238,"":"io task","client":"0","":"downstairs","session_id":"61c87861-9ffe-4444-b1f3-53c1d8ad78bf"}
2212025-03-17T22:41:06.989Z{"msg":"ds_connection connected from Ok(127.0.0.1:36030)","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:41:05.996749404Z","hostname":"w-01JPK3TSG4GD7HGEZJP118DX4C","pid":1238,"":"io task","client":"1","":"downstairs","session_id":"61c87861-9ffe-4444-b1f3-53c1d8ad78bf"}
2222025-03-17T22:41:06.989Z{"msg":"version negotiation from state Connecting { state: WaitForPromote, mode: New }","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:41:05.996782517Z","hostname":"w-01JPK3TSG4GD7HGEZJP118DX4C","pid":1238,"client":"1","":"downstairs","session_id":"61c87861-9ffe-4444-b1f3-53c1d8ad78bf"}
2232025-03-17T22:41:06.989Z{"msg":"version negotiation from state Connecting { state: WaitForPromote, mode: New }","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:41:05.996797955Z","hostname":"w-01JPK3TSG4GD7HGEZJP118DX4C","pid":1238,"client":"2","":"downstairs","session_id":"61c87861-9ffe-4444-b1f3-53c1d8ad78bf"}
2242025-03-17T22:41:06.989Z{"msg":"version negotiation from state Connecting { state: WaitForPromote, mode: New }","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:41:05.996826679Z","hostname":"w-01JPK3TSG4GD7HGEZJP118DX4C","pid":1238,"client":"0","":"downstairs","session_id":"61c87861-9ffe-4444-b1f3-53c1d8ad78bf"}
2252025-03-17T22:41:06.989Z{"msg":"downstairs client at Some(127.0.0.1:8850) has region UUID 12345678-0000-0000-0000-000000008850","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:41:05.997193981Z","hostname":"w-01JPK3TSG4GD7HGEZJP118DX4C","pid":1238,"client":"1","":"downstairs","session_id":"61c87861-9ffe-4444-b1f3-53c1d8ad78bf"}
2262025-03-17T22:41:06.989Z{"msg":"downstairs client at Some(127.0.0.1:8860) has region UUID 12345678-0000-0000-0000-000000008860","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:41:05.997266297Z","hostname":"w-01JPK3TSG4GD7HGEZJP118DX4C","pid":1238,"client":"2","":"downstairs","session_id":"61c87861-9ffe-4444-b1f3-53c1d8ad78bf"}
2272025-03-17T22:41:06.989Z{"msg":"downstairs client at Some(127.0.0.1:8840) has region UUID 12345678-0000-0000-0000-000000008840","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:41:05.99730782Z","hostname":"w-01JPK3TSG4GD7HGEZJP118DX4C","pid":1238,"client":"0","":"downstairs","session_id":"61c87861-9ffe-4444-b1f3-53c1d8ad78bf"}
2282025-03-17T22:41:06.989Z{"msg":"Waiting for more clients to be ready","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:41:05.997536098Z","hostname":"w-01JPK3TSG4GD7HGEZJP118DX4C","pid":1238,"session_id":"61c87861-9ffe-4444-b1f3-53c1d8ad78bf"}
2292025-03-17T22:41:06.989Z{"msg":"Waiting for more clients to be ready","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:41:05.997587988Z","hostname":"w-01JPK3TSG4GD7HGEZJP118DX4C","pid":1238,"session_id":"61c87861-9ffe-4444-b1f3-53c1d8ad78bf"}
2302025-03-17T22:41:06.989Z{"msg":"[0]R flush_numbers: [5319, 5319, 5319, 5318, 5318]","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:41:05.997660604Z","hostname":"w-01JPK3TSG4GD7HGEZJP118DX4C","pid":1238,"":"downstairs","":"downstairs","session_id":"61c87861-9ffe-4444-b1f3-53c1d8ad78bf"}
2312025-03-17T22:41:06.989Z{"msg":"[0]R generation: [14, 14, 14, 14, 14]","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:41:05.997696578Z","hostname":"w-01JPK3TSG4GD7HGEZJP118DX4C","pid":1238,"":"downstairs","":"downstairs","session_id":"61c87861-9ffe-4444-b1f3-53c1d8ad78bf"}
2322025-03-17T22:41:06.990Z{"msg":"[0]R dirty: [false, false, false, false, false]","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:41:05.997724533Z","hostname":"w-01JPK3TSG4GD7HGEZJP118DX4C","pid":1238,"":"downstairs","":"downstairs","session_id":"61c87861-9ffe-4444-b1f3-53c1d8ad78bf"}
2332025-03-17T22:41:06.990Z{"msg":"[1]R flush_numbers: [5319, 5319, 5319, 5318, 5318]","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:41:05.997746659Z","hostname":"w-01JPK3TSG4GD7HGEZJP118DX4C","pid":1238,"":"downstairs","":"downstairs","session_id":"61c87861-9ffe-4444-b1f3-53c1d8ad78bf"}
2342025-03-17T22:41:06.990Z{"msg":"[1]R generation: [14, 14, 14, 14, 14]","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:41:05.997770474Z","hostname":"w-01JPK3TSG4GD7HGEZJP118DX4C","pid":1238,"":"downstairs","":"downstairs","session_id":"61c87861-9ffe-4444-b1f3-53c1d8ad78bf"}
2352025-03-17T22:41:06.990Z{"msg":"[1]R dirty: [false, false, false, false, false]","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:41:05.99779261Z","hostname":"w-01JPK3TSG4GD7HGEZJP118DX4C","pid":1238,"":"downstairs","":"downstairs","session_id":"61c87861-9ffe-4444-b1f3-53c1d8ad78bf"}
2362025-03-17T22:41:06.990Z{"msg":"[2]R flush_numbers: [5319, 5319, 5319, 5318, 5318]","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:41:05.997815106ZWait for a query_work_queue command to finish before sending IO
2372025-03-17T22:41:06.990Z","hostname":"w-01JPK3TSG4GD7HGEZJP118DX4C","pid":1238,"":"downstairs","":"downstairs","session_id":"61c87861-9ffe-4444-b1f3-53c1d8ad78bf"}
2382025-03-17T22:41:06.990Z{"msg":"[2]R generation: [14, 14, 14, 14, 14]","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:41:05.997866406Z","hostname":"w-01JPK3TSG4GD7HGEZJP118DX4C","pid":1238,"":"downstairs","":"downstairs","session_id":"61c87861-9ffe-4444-b1f3-53c1d8ad78bf"}
2392025-03-17T22:41:06.990Z{"msg":"[2]R dirty: [false, false, false, false, false]","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:41:05.99789942Z","hostname":"w-01JPK3TSG4GD7HGEZJP118DX4C","pid":1238,"":"downstairs","":"downstairs","session_id":"61c87861-9ffe-4444-b1f3-53c1d8ad78bf"}
2402025-03-17T22:41:06.990Z{"msg":"Max found gen is 15","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:41:05.997930854Z","hostname":"w-01JPK3TSG4GD7HGEZJP118DX4C","pid":1238,"":"downstairs","":"downstairs","session_id":"61c87861-9ffe-4444-b1f3-53c1d8ad78bf"}
2412025-03-17T22:41:06.990Z{"msg":"Generation requested: 31 >= found:15","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:41:05.99795245Z","hostname":"w-01JPK3TSG4GD7HGEZJP118DX4C","pid":1238,"":"downstairs","":"downstairs","session_id":"61c87861-9ffe-4444-b1f3-53c1d8ad78bf"}
2422025-03-17T22:41:06.990Z{"msg":"Next flush: 5320","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:41:05.997982165Z","hostname":"w-01JPK3TSG4GD7HGEZJP118DX4C","pid":1238,"":"downstairs","":"downstairs","session_id":"61c87861-9ffe-4444-b1f3-53c1d8ad78bf"}
2432025-03-17T22:41:06.990Z{"msg":"All extents match","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:41:05.998005101Z","hostname":"w-01JPK3TSG4GD7HGEZJP118DX4C","pid":1238,"":"downstairs","":"downstairs","session_id":"61c87861-9ffe-4444-b1f3-53c1d8ad78bf"}
2442025-03-17T22:41:06.990Z{"msg":"No downstairs reconciliation required","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:41:05.998029836Z","hostname":"w-01JPK3TSG4GD7HGEZJP118DX4C","pid":1238,"session_id":"61c87861-9ffe-4444-b1f3-53c1d8ad78bf"}
2452025-03-17T22:41:06.990Z{"msg":"Transition from WaitQuorum to Active","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:41:05.998042564Z","hostname":"w-01JPK3TSG4GD7HGEZJP118DX4C","pid":1238,"client":"0","":"downstairs","session_id":"61c87861-9ffe-4444-b1f3-53c1d8ad78bf"}
2462025-03-17T22:41:06.990Z{"msg":"Transition from WaitQuorum to Active","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:41:05.99806264Z","hostname":"w-01JPK3TSG4GD7HGEZJP118DX4C","pid":1238,"client":"1","":"downstairs","session_id":"61c87861-9ffe-4444-b1f3-53c1d8ad78bf"}
2472025-03-17T22:41:06.990Z{"msg":"Transition from WaitQuorum to Active","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:41:05.998075798Z","hostname":"w-01JPK3TSG4GD7HGEZJP118DX4C","pid":1238,"client":"2","":"downstairs","session_id":"61c87861-9ffe-4444-b1f3-53c1d8ad78bf"}
2482025-03-17T22:41:06.990Z{"msg":"All required reconciliation work is completed","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:41:05.998096264Z","hostname":"w-01JPK3TSG4GD7HGEZJP118DX4C","pid":1238,"session_id":"61c87861-9ffe-4444-b1f3-53c1d8ad78bf"}
2492025-03-17T22:41:06.990Z{"msg":"Set Downstairs and Upstairs active after reconciliation","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:41:05.998108731Z","hostname":"w-01JPK3TSG4GD7HGEZJP118DX4C","pid":1238,"session_id":"61c87861-9ffe-4444-b1f3-53c1d8ad78bf"}
2502025-03-17T22:41:06.990Z{"msg":"dcf25989-6c95-4947-b73e-3f3b7e4422f7 is now active with session: 61c87861-9ffe-4444-b1f3-53c1d8ad78bf","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:41:05.998128078Z","hostname":"w-01JPK3TSG4GD7HGEZJP118DX4C","pid":1238,"session_id":"61c87861-9ffe-4444-b1f3-53c1d8ad78bf"}
2512025-03-17T22:41:06.990Z{"msg":"Set Active after no reconciliation","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:41:05.998140106Z","hostname":"w-01JPK3TSG4GD7HGEZJP118DX4C","pid":1238,"session_id":"61c87861-9ffe-4444-b1f3-53c1d8ad78bf"}
2522025-03-17T22:41:06.990Z{"msg":"The guest has finished waiting for activation with:31","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:41:05.998152143Z","hostname":"w-01JPK3TSG4GD7HGEZJP118DX4C","pid":1238}
2532025-03-17T22:41:06.990Z{"msg":"Activated sub_volume dcf25989-6c95-4947-b73e-3f3b7e4422f7","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:41:05.99817025Z","hostname":"w-01JPK3TSG4GD7HGEZJP118DX4C","pid":1238}
2542025-03-17T22:41:06.990ZDisk: sv:2 bs:4096 ts:409600 tb:100 max_io:100 or 409600
2552025-03-17T22:41:06.990ZFill test
2562025-03-17T22:41:07.024ZRead and Verify all blocks (0..100 range:false)
2572025-03-17T22:41:07.116ZWrote out file "/var/tmp/test_up-build/verify_file"
2582025-03-17T22:41:07.116ZCLIENT: Tests done. All submitted work has been ACK'd
2592025-03-17T22:41:07.120Z----------------------------------------------------------------
2602025-03-17T22:41:07.120Z Crucible gen:31 GIO:true work queues: Upstairs:0 downstairs:1
2612025-03-17T22:41:07.120ZStates: Active Active Active
2622025-03-17T22:41:07.120ZJOBID ACK TYPE BKS/EXT DS:0 DS:1 DS:2 REPLAY
2632025-03-17T22:41:07.120Z 1002 Acked Read 50 Done Done Done false
2642025-03-17T22:41:07.120Z STATES DS:0 DS:1 DS:2 TOTAL
2652025-03-17T22:41:07.121Z Sent 0 0 0 0
2662025-03-17T22:41:07.121Z Done 1 1 1 3
2672025-03-17T22:41:07.121Z Skipped 0 0 0 0
2682025-03-17T22:41:07.121Z Error 0 0 0 0
2692025-03-17T22:41:07.121ZLast Flush: Some(JobId(1001)) Some(JobId(1001)) Some(JobId(1001))
2702025-03-17T22:41:07.121ZDownstairs last five completed: 1001 1000
2712025-03-17T22:41:07.121ZUpstairs last five completed: 1002 1001 1000
2722025-03-17T22:41:07.121Z----------------------------------------------------------------
2732025-03-17T22:41:07.121Z Crucible gen:31 GIO:true work queues: Upstairs:0 downstairs:1
2742025-03-17T22:41:07.121ZStates: Active Active Active
2752025-03-17T22:41:07.121ZJOBID ACK TYPE BKS/EXT DS:0 DS:1 DS:2 REPLAY
2762025-03-17T22:41:07.121Z 1002 Acked Read 50 Done Done Done false
2772025-03-17T22:41:07.121Z STATES DS:0 DS:1 DS:2 TOTAL
2782025-03-17T22:41:07.121Z Sent 0 0 0 0
2792025-03-17T22:41:07.121Z Done 1 1 1 3
2802025-03-17T22:41:07.121Z Skipped 0 0 0 0
2812025-03-17T22:41:07.121Z Error 0 0 0 0
2822025-03-17T22:41:07.121ZLast Flush: Some(JobId(1001)) Some(JobId(1001)) Some(JobId(1001))
2832025-03-17T22:41:07.121ZDownstairs last five completed: 1001 1000
2842025-03-17T22:41:07.121ZUpstairs last five completed: 1002 1001 1000
2852025-03-17T22:41:07.121ZCLIENT: Up:0 ds:2 act:6
2862025-03-17T22:41:11.119Z----------------------------------------------------------------
2872025-03-17T22:41:11.119Z Crucible gen:31 GIO:true work queues: Upstairs:0 downstairs:0
2882025-03-17T22:41:11.119ZDownstairs last five completed: 1003 1002 1001 1000
2892025-03-17T22:41:11.119ZUpstairs last five completed: 1003 1002 1001 1000
2902025-03-17T22:41:11.123Z----------------------------------------------------------------
2912025-03-17T22:41:11.123Z Crucible gen:31 GIO:true work queues: Upstairs:0 downstairs:0
2922025-03-17T22:41:11.123ZDownstairs last five completed: 1003 1002 1001 1000
2932025-03-17T22:41:11.123ZUpstairs last five completed: 1003 1002 1001 1000
2942025-03-17T22:41:11.123ZCLIENT: Up:0 ds:0 act:6
2952025-03-17T22:41:11.123ZCLIENT: All crucible jobs finished, exiting program
2962025-03-17T22:41:11.123Z{"msg":"Guest handle has been dropped","v":0,"name":"crucible","level":40,"time":"2025-03-17T22:41:10.135581796Z","hostname":"w-01JPK3TSG4GD7HGEZJP118DX4C","pid":1238}
2972025-03-17T22:41:11.130ZRepair setup passed
2982025-03-17T22:41:11.134ZCopy the region for /var/tmp/test_up-build/8830
2992025-03-17T22:41:11.138Zcp -r /var/tmp/test_up-build/8830 /var/tmp/test_up-build/previous
3002025-03-17T22:41:11.138Z/var/tmp/bins/crutest fill -g 32 -q --key iyNjT3xeuGYhhftr21OU3I2u+/KzkJyUMqiH19BBbu8= --dsc 127.0.0.1:9998 --verify-out /var/tmp/test_up-build/verify_file --verify-in /var/tmp/test_up-build/verify_file
3012025-03-17T22:41:11.195Z{"msg":"Use this region info from dsc: RegionExtentInfo { block_size: 4096, blocks_per_extent: 10, extent_count: 5 }","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:41:10.211507478Z","hostname":"w-01JPK3TSG4GD7HGEZJP118DX4C","pid":1244,"task":"crutest"}
3022025-03-17T22:41:11.200Z{"msg":"dsc has 6 regions. This means 2 sub_volumes","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:41:10.212080822Z","hostname":"w-01JPK3TSG4GD7HGEZJP118DX4C","pid":1244,"task":"crutest"}
3032025-03-17T22:41:11.200Z{"msg":"SV 0 has targets: [127.0.0.1:8810, 127.0.0.1:8820, 127.0.0.1:8830]","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:41:10.213769359Z","hostname":"w-01JPK3TSG4GD7HGEZJP118DX4C","pid":1244,"task":"crutest"}
3042025-03-17T22:41:11.200Z{"msg":"Upstairs starts","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:41:10.214008504Z","hostname":"w-01JPK3TSG4GD7HGEZJP118DX4C","pid":1244}
3052025-03-17T22:41:11.200Z{"msg":"Crucible Version: BuildInfo {\n version: \"0.0.1\",\n git_sha: \"45feeae3dd1bdcd88dce11a80acb5415f57b38bc\",\n git_commit_timestamp: \"2025-03-17T22:11:58.000000000Z\",\n git_branch: \"renovate/opentelemetry-0.x\",\n rustc_semver: \"1.84.0\",\n rustc_channel: \"stable\",\n rustc_host_triple: \"x86_64-unknown-illumos\",\n rustc_commit_sha: \"9fc6b43126469e3858e2fe86cafb4f0fd5068869\",\n cargo_triple: \"x86_64-unknown-illumos\",\n debug: true,\n opt_level: 0,\n}","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:41:10.214054366Z","hostname":"w-01JPK3TSG4GD7HGEZJP118DX4C","pid":1244}
3062025-03-17T22:41:11.200Z{"msg":"Upstairs <-> Downstairs Message Version: 13","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:41:10.214078111Z","hostname":"w-01JPK3TSG4GD7HGEZJP118DX4C","pid":1244}
3072025-03-17T22:41:11.200Z{"msg":"Using region definition RegionDefinition { block_size: 4096, extent_size: Block { value: 10, shift: 12 }, extent_count: 5, uuid: 00000000-0000-0000-0000-000000000000, encrypted: true, database_read_version: 1, database_write_version: 1 }","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:41:10.214093519Z","hostname":"w-01JPK3TSG4GD7HGEZJP118DX4C","pid":1244}
3082025-03-17T22:41:11.200Z{"msg":"Crucible 9d0f65c4-d9d6-4412-9ac0-1bf0c5936055 has session id: 392e48e4-5249-4223-ad86-1eec05b242ec","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:41:10.214606933Z","hostname":"w-01JPK3TSG4GD7HGEZJP118DX4C","pid":1244,"session_id":"392e48e4-5249-4223-ad86-1eec05b242ec"}
3092025-03-17T22:41:11.200Z{"msg":"Upstairs opts: Upstairs UUID: 9d0f65c4-d9d6-4412-9ac0-1bf0c5936055, Targets: [127.0.0.1:8810, 127.0.0.1:8820, 127.0.0.1:8830], lossy: false, flush_timeout: None, key populated: true, cert_pem populated: false, key_pem populated: false, root_cert_pem populated: false, Control: None, read_only: false","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:41:10.214694237Z","hostname":"w-01JPK3TSG4GD7HGEZJP118DX4C","pid":1244,"session_id":"392e48e4-5249-4223-ad86-1eec05b242ec"}
3102025-03-17T22:41:11.200Z{"msg":"Crucible stats registered with UUID: 9d0f65c4-d9d6-4412-9ac0-1bf0c5936055","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:41:10.21473238Z","hostname":"w-01JPK3TSG4GD7HGEZJP118DX4C","pid":1244,"session_id":"392e48e4-5249-4223-ad86-1eec05b242ec"}
3112025-03-17T22:41:11.200Z{"msg":"could not find Downstairs address for Nexus","v":0,"name":"crucible","level":40,"time":"2025-03-17T22:41:10.214767854Z","hostname":"w-01JPK3TSG4GD7HGEZJP118DX4C","pid":1244,"session_id":"392e48e4-5249-4223-ad86-1eec05b242ec"}
3122025-03-17T22:41:11.204Z{"msg":"SV 1 has targets: [127.0.0.1:8840, 127.0.0.1:8850, 127.0.0.1:8860]","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:41:10.216714733Z","hostname":"w-01JPK3TSG4GD7HGEZJP118DX4C","pid":1244,"task":"crutest"}
3132025-03-17T22:41:11.204Z{"msg":"Upstairs starts","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:41:10.216803746Z","hostname":"w-01JPK3TSG4GD7HGEZJP118DX4C","pid":1244}
3142025-03-17T22:41:11.204Z{"msg":"Crucible Version: BuildInfo {\n version: \"0.0.1\",\n git_sha: \"45feeae3dd1bdcd88dce11a80acb5415f57b38bc\",\n git_commit_timestamp: \"2025-03-17T22:11:58.000000000Z\",\n git_branch: \"renovate/opentelemetry-0.x\",\n rustc_semver: \"1.84.0\",\n rustc_channel: \"stable\",\n rustc_host_triple: \"x86_64-unknown-illumos\",\n rustc_commit_sha: \"9fc6b43126469e3858e2fe86cafb4f0fd5068869\",\n cargo_triple: \"x86_64-unknown-illumos\",\n debug: true,\n opt_level: 0,\n}","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:41:10.216840169Z","hostname":"w-01JPK3TSG4GD7HGEZJP118DX4C","pid":1244}
3152025-03-17T22:41:11.204Z{"msg":"Upstairs <-> Downstairs Message Version: 13","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:41:10.216854127Z","hostname":"w-01JPK3TSG4GD7HGEZJP118DX4C","pid":1244}
3162025-03-17T22:41:11.204Z{"msg":"Using region definition RegionDefinition { block_size: 4096, extent_size: Block { value: 10, shift: 12 }, extent_count: 5, uuid: 00000000-0000-0000-0000-000000000000, encrypted: true, database_read_version: 1, database_write_version: 1 }","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:41:10.216868484Z","hostname":"w-01JPK3TSG4GD7HGEZJP118DX4C","pid":1244}
3172025-03-17T22:41:11.204Z{"msg":"Crucible 9d0f65c4-d9d6-4412-9ac0-1bf0c5936055 has session id: 802dea9a-2e19-4e6b-b28f-4220eca0b544","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:41:10.21726452Z","hostname":"w-01JPK3TSG4GD7HGEZJP118DX4C","pid":1244,"session_id":"802dea9a-2e19-4e6b-b28f-4220eca0b544"}
3182025-03-17T22:41:11.204Z{"msg":"Upstairs opts: Upstairs UUID: 9d0f65c4-d9d6-4412-9ac0-1bf0c5936055, Targets: [127.0.0.1:8840, 127.0.0.1:8850, 127.0.0.1:8860], lossy: false, flush_timeout: None, key populated: true, cert_pem populated: false, key_pem populated: false, root_cert_pem populated: false, Control: None, read_only: false","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:41:10.217292495Z","hostname":"w-01JPK3TSG4GD7HGEZJP118DX4C","pid":1244,"session_id":"802dea9a-2e19-4e6b-b28f-4220eca0b544"}
3192025-03-17T22:41:11.204Z{"msg":"Crucible stats registered with UUID: 9d0f65c4-d9d6-4412-9ac0-1bf0c5936055","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:41:10.217307292Z","hostname":"w-01JPK3TSG4GD7HGEZJP118DX4C","pid":1244,"session_id":"802dea9a-2e19-4e6b-b28f-4220eca0b544"}
3202025-03-17T22:41:11.204Z{"msg":"could not find Downstairs address for Nexus","v":0,"name":"crucible","level":40,"time":"2025-03-17T22:41:10.21732242Z","hostname":"w-01JPK3TSG4GD7HGEZJP118DX4C","pid":1244,"session_id":"802dea9a-2e19-4e6b-b28f-4220eca0b544"}
3212025-03-17T22:41:11.204Z{"msg":"Downstairs in volume = 6","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:41:10.217984947Z","hostname":"w-01JPK3TSG4GD7HGEZJP118DX4C","pid":1244,"task":"crutest"}
3222025-03-17T22:41:11.205Z{"msg":"The guest has requested activation with gen:32","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:41:10.218029849Z","hostname":"w-01JPK3TSG4GD7HGEZJP118DX4C","pid":1244}
3232025-03-17T22:41:11.205Z{"msg":"9d0f65c4-d9d6-4412-9ac0-1bf0c5936055 active request set","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:41:10.218116173Z","hostname":"w-01JPK3TSG4GD7HGEZJP118DX4C","pid":1244,"session_id":"392e48e4-5249-4223-ad86-1eec05b242ec"}
3242025-03-17T22:41:11.205Z{"msg":"sending connect oneshot to client","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:41:10.218176631Z","hostname":"w-01JPK3TSG4GD7HGEZJP118DX4C","pid":1244,"client":"0","":"downstairs","session_id":"392e48e4-5249-4223-ad86-1eec05b242ec"}
3252025-03-17T22:41:11.205Z{"msg":"client set_active_request while in Connecting { state: Start { auto_promote: true }, mode: New }; waiting...","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:41:10.218235751Z","hostname":"w-01JPK3TSG4GD7HGEZJP118DX4C","pid":1244,"client":"0","":"downstairs","session_id":"392e48e4-5249-4223-ad86-1eec05b242ec"}
3262025-03-17T22:41:11.205Z{"msg":"sending connect oneshot to client","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:41:10.218266555Z","hostname":"w-01JPK3TSG4GD7HGEZJP118DX4C","pid":1244,"client":"1","":"downstairs","session_id":"392e48e4-5249-4223-ad86-1eec05b242ec"}
3272025-03-17T22:41:11.205Z{"msg":"client set_active_request while in Connecting { state: Start { auto_promote: true }, mode: New }; waiting...","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:41:10.218308737Z","hostname":"w-01JPK3TSG4GD7HGEZJP118DX4C","pid":1244,"client":"1","":"downstairs","session_id":"392e48e4-5249-4223-ad86-1eec05b242ec"}
3282025-03-17T22:41:11.205Z{"msg":"sending connect oneshot to client","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:41:10.21834793Z","hostname":"w-01JPK3TSG4GD7HGEZJP118DX4C","pid":1244,"client":"2","":"downstairs","session_id":"392e48e4-5249-4223-ad86-1eec05b242ec"}
3292025-03-17T22:41:11.205Z{"msg":"client set_active_request while in Connecting { state: Start { auto_promote: true }, mode: New }; waiting...","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:41:10.218376514Z","hostname":"w-01JPK3TSG4GD7HGEZJP118DX4C","pid":1244,"client":"2","":"downstairs","session_id":"392e48e4-5249-4223-ad86-1eec05b242ec"}
3302025-03-17T22:41:11.205Z{"msg":"connecting to 127.0.0.1:8830","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:41:10.218413327Z","hostname":"w-01JPK3TSG4GD7HGEZJP118DX4C","pid":1244,"":"io task","client":"2","":"downstairs","session_id":"392e48e4-5249-4223-ad86-1eec05b242ec"}
3312025-03-17T22:41:11.205Z{"msg":"connecting to 127.0.0.1:8810","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:41:10.218472227Z","hostname":"w-01JPK3TSG4GD7HGEZJP118DX4C","pid":1244,"":"io task","client":"0","":"downstairs","session_id":"392e48e4-5249-4223-ad86-1eec05b242ec"}
3322025-03-17T22:41:11.205Z{"msg":"connecting to 127.0.0.1:8820","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:41:10.218687527Z","hostname":"w-01JPK3TSG4GD7HGEZJP118DX4C","pid":1244,"":"io task","client":"1","":"downstairs","session_id":"392e48e4-5249-4223-ad86-1eec05b242ec"}
3332025-03-17T22:41:11.205Z{"msg":"ds_connection connected from Ok(127.0.0.1:41295)","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:41:10.218734808Z","hostname":"w-01JPK3TSG4GD7HGEZJP118DX4C","pid":1244,"":"io task","client":"2","":"downstairs","session_id":"392e48e4-5249-4223-ad86-1eec05b242ec"}
3342025-03-17T22:41:11.205Z{"msg":"ds_connection connected from Ok(127.0.0.1:47681)","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:41:10.218768462Z","hostname":"w-01JPK3TSG4GD7HGEZJP118DX4C","pid":1244,"":"io task","client":"0","":"downstairs","session_id":"392e48e4-5249-4223-ad86-1eec05b242ec"}
3352025-03-17T22:41:11.205Z{"msg":"ds_connection connected from Ok(127.0.0.1:42545)","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:41:10.218806634Z","hostname":"w-01JPK3TSG4GD7HGEZJP118DX4C","pid":1244,"":"io task","client":"1","":"downstairs","session_id":"392e48e4-5249-4223-ad86-1eec05b242ec"}
3362025-03-17T22:41:11.205Z{"msg":"version negotiation from state Connecting { state: WaitForPromote, mode: New }","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:41:10.219089482Z","hostname":"w-01JPK3TSG4GD7HGEZJP118DX4C","pid":1244,"client":"1","":"downstairs","session_id":"392e48e4-5249-4223-ad86-1eec05b242ec"}
3372025-03-17T22:41:11.205Z{"msg":"version negotiation from state Connecting { state: WaitForPromote, mode: New }","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:41:10.219127335Z","hostname":"w-01JPK3TSG4GD7HGEZJP118DX4C","pid":1244,"client":"0","":"downstairs","session_id":"392e48e4-5249-4223-ad86-1eec05b242ec"}
3382025-03-17T22:41:11.205Z{"msg":"version negotiation from state Connecting { state: WaitForPromote, mode: New }","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:41:10.219144752Z","hostname":"w-01JPK3TSG4GD7HGEZJP118DX4C","pid":1244,"client":"2","":"downstairs","session_id":"392e48e4-5249-4223-ad86-1eec05b242ec"}
3392025-03-17T22:41:11.206Z{"msg":"downstairs client at Some(127.0.0.1:8810) has region UUID 12345678-0000-0000-0000-000000008810","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:41:10.219752689Z","hostname":"w-01JPK3TSG4GD7HGEZJP118DX4C","pid":1244,"client":"0","":"downstairs","session_id":"392e48e4-5249-4223-ad86-1eec05b242ec"}
3402025-03-17T22:41:11.206Z{"msg":"downstairs client at Some(127.0.0.1:8830) has region UUID 12345678-0000-0000-0000-000000008830","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:41:10.219825506Z","hostname":"w-01JPK3TSG4GD7HGEZJP118DX4C","pid":1244,"client":"2","":"downstairs","session_id":"392e48e4-5249-4223-ad86-1eec05b242ec"}
3412025-03-17T22:41:11.206Z{"msg":"downstairs client at Some(127.0.0.1:8820) has region UUID 12345678-0000-0000-0000-000000008820","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:41:10.219861369Z","hostname":"w-01JPK3TSG4GD7HGEZJP118DX4C","pid":1244,"client":"1","":"downstairs","session_id":"392e48e4-5249-4223-ad86-1eec05b242ec"}
3422025-03-17T22:41:11.206Z{"msg":"Waiting for more clients to be ready","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:41:10.220255846Z","hostname":"w-01JPK3TSG4GD7HGEZJP118DX4C","pid":1244,"session_id":"392e48e4-5249-4223-ad86-1eec05b242ec"}
3432025-03-17T22:41:11.206Z{"msg":"Waiting for more clients to be ready","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:41:10.220289899Z","hostname":"w-01JPK3TSG4GD7HGEZJP118DX4C","pid":1244,"session_id":"392e48e4-5249-4223-ad86-1eec05b242ec"}
3442025-03-17T22:41:11.206Z{"msg":"[0]R flush_numbers: [4001, 4001, 4001, 4001, 4001]","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:41:10.220304567Z","hostname":"w-01JPK3TSG4GD7HGEZJP118DX4C","pid":1244,"":"downstairs","":"downstairs","session_id":"392e48e4-5249-4223-ad86-1eec05b242ec"}
3452025-03-17T22:41:11.206Z{"msg":"[0]R generation: [31, 31, 31, 31, 31]","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:41:10.220336631Z","hostname":"w-01JPK3TSG4GD7HGEZJP118DX4C","pid":1244,"":"downstairs","":"downstairs","session_id":"392e48e4-5249-4223-ad86-1eec05b242ec"}
3462025-03-17T22:41:11.206Z{"msg":"[0]R dirty: [false, false, false, false, false]","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:41:10.220354238Z","hostname":"w-01JPK3TSG4GD7HGEZJP118DX4C","pid":1244,"":"downstairs","":"downstairs","session_id":"392e48e4-5249-4223-ad86-1eec05b242ec"}
3472025-03-17T22:41:11.212Z{"msg":"[1]R flush_numbers: [4001, 4001, 4001, 4001, 4001]","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:41:10.220370145Z","hostname":"w-01JPK3TSG4GD7HGEZJP118DX4C","pid":1244,"":"downstairs","":"downstairs","session_id":"392e48e4-5249-4223-ad86-1eec05b242ec"}
3482025-03-17T22:41:11.212Z{"msg":"[1]R generation: [31, 31, 31, 31, 31]","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:41:10.220405348Z","hostname":"w-01JPK3TSG4GD7HGEZJP118DX4C","pid":1244,"":"downstairs","":"downstairs","session_id":"392e48e4-5249-4223-ad86-1eec05b242ec"}
3492025-03-17T22:41:11.212Z{"msg":"[1]R dirty: [false, false, false, false, false]","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:41:10.220420635Z","hostname":"w-01JPK3TSG4GD7HGEZJP118DX4C","pid":1244,"":"downstairs","":"downstairs","session_id":"392e48e4-5249-4223-ad86-1eec05b242ec"}
3502025-03-17T22:41:11.212Z{"msg":"[2]R flush_numbers: [4001, 4001, 4001, 4001, 4001]","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:41:10.220433623Z","hostname":"w-01JPK3TSG4GD7HGEZJP118DX4C","pid":1244,"":"downstairs","":"downstairs","session_id":"392e48e4-5249-4223-ad86-1eec05b242ec"}
3512025-03-17T22:41:11.212Z{"msg":"[2]R generation: [31, 31, 31, 31, 31]","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:41:10.220454499Z","hostname":"w-01JPK3TSG4GD7HGEZJP118DX4C","pid":1244,"":"downstairs","":"downstairs","session_id":"392e48e4-5249-4223-ad86-1eec05b242ec"}
3522025-03-17T22:41:11.212Z{"msg":"[2]R dirty: [false, false, false, false, false]","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:41:10.220484374Z","hostname":"w-01JPK3TSG4GD7HGEZJP118DX4C","pid":1244,"":"downstairs","":"downstairs","session_id":"392e48e4-5249-4223-ad86-1eec05b242ec"}
3532025-03-17T22:41:11.212Z{"msg":"Max found gen is 32","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:41:10.220498771Z","hostname":"w-01JPK3TSG4GD7HGEZJP118DX4C","pid":1244,"":"downstairs","":"downstairs","session_id":"392e48e4-5249-4223-ad86-1eec05b242ec"}
3542025-03-17T22:41:11.212Z{"msg":"Generation requested: 32 >= found:32","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:41:10.220516748Z","hostname":"w-01JPK3TSG4GD7HGEZJP118DX4C","pid":1244,"":"downstairs","":"downstairs","session_id":"392e48e4-5249-4223-ad86-1eec05b242ec"}
3552025-03-17T22:41:11.212Z{"msg":"Next flush: 4002","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:41:10.220545402Z","hostname":"w-01JPK3TSG4GD7HGEZJP118DX4C","pid":1244,"":"downstairs","":"downstairs","session_id":"392e48e4-5249-4223-ad86-1eec05b242ec"}
3562025-03-17T22:41:11.212Z{"msg":"All extents match","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:41:10.22056026Z","hostname":"w-01JPK3TSG4GD7HGEZJP118DX4C","pid":1244,"":"downstairs","":"downstairs","session_id":"392e48e4-5249-4223-ad86-1eec05b242ec"}
3572025-03-17T22:41:11.212Z{"msg":"No downstairs reconciliation required","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:41:10.220577876Z","hostname":"w-01JPK3TSG4GD7HGEZJP118DX4C","pid":1244,"session_id":"392e48e4-5249-4223-ad86-1eec05b242ec"}
3582025-03-17T22:41:11.213Z{"msg":"Transition from WaitQuorum to Active","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:41:10.220605011Z","hostname":"w-01JPK3TSG4GD7HGEZJP118DX4C","pid":1244,"client":"0","":"downstairs","session_id":"392e48e4-5249-4223-ad86-1eec05b242ec"}
3592025-03-17T22:41:11.213Z{"msg":"Transition from WaitQuorum to Active","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:41:10.220619469Z","hostname":"w-01JPK3TSG4GD7HGEZJP118DX4C","pid":1244,"client":"1","":"downstairs","session_id":"392e48e4-5249-4223-ad86-1eec05b242ec"}
3602025-03-17T22:41:11.213Z{"msg":"Transition from WaitQuorum to Active","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:41:10.220636245Z","hostname":"w-01JPK3TSG4GD7HGEZJP118DX4C","pid":1244,"client":"2","":"downstairs","session_id":"392e48e4-5249-4223-ad86-1eec05b242ec"}
3612025-03-17T22:41:11.213Z{"msg":"All required reconciliation work is completed","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:41:10.220659841Z","hostname":"w-01JPK3TSG4GD7HGEZJP118DX4C","pid":1244,"session_id":"392e48e4-5249-4223-ad86-1eec05b242ec"}
3622025-03-17T22:41:11.213Z{"msg":"Set Downstairs and Upstairs active after reconciliation","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:41:10.220682577Z","hostname":"w-01JPK3TSG4GD7HGEZJP118DX4C","pid":1244,"session_id":"392e48e4-5249-4223-ad86-1eec05b242ec"}
3632025-03-17T22:41:11.213Z{"msg":"9d0f65c4-d9d6-4412-9ac0-1bf0c5936055 is now active with session: 392e48e4-5249-4223-ad86-1eec05b242ec","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:41:10.220706902Z","hostname":"w-01JPK3TSG4GD7HGEZJP118DX4C","pid":1244,"session_id":"392e48e4-5249-4223-ad86-1eec05b242ec"}
3642025-03-17T22:41:11.213Z{"msg":"Set Active after no reconciliation","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:41:10.220739066Z","hostname":"w-01JPK3TSG4GD7HGEZJP118DX4C","pid":1244,"session_id":"392e48e4-5249-4223-ad86-1eec05b242ec"}
3652025-03-17T22:41:11.213Z{"msg":"The guest has finished waiting for activation with:32","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:41:10.220764802Z","hostname":"w-01JPK3TSG4GD7HGEZJP118DX4C","pid":1244}
3662025-03-17T22:41:11.213Z{"msg":"Activated sub_volume 9d0f65c4-d9d6-4412-9ac0-1bf0c5936055","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:41:10.220919643Z","hostname":"w-01JPK3TSG4GD7HGEZJP118DX4C","pid":1244}
3672025-03-17T22:41:11.213Z{"msg":"The guest has requested activation with gen:32","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:41:10.220982701Z","hostname":"w-01JPK3TSG4GD7HGEZJP118DX4C","pid":1244}
3682025-03-17T22:41:11.213Z{"msg":"9d0f65c4-d9d6-4412-9ac0-1bf0c5936055 active request set","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:41:10.221009636Z","hostname":"w-01JPK3TSG4GD7HGEZJP118DX4C","pid":1244,"session_id":"802dea9a-2e19-4e6b-b28f-4220eca0b544"}
3692025-03-17T22:41:11.213Z{"msg":"sending connect oneshot to client","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:41:10.221035371Z","hostname":"w-01JPK3TSG4GD7HGEZJP118DX4C","pid":1244,"client":"0","":"downstairs","session_id":"802dea9a-2e19-4e6b-b28f-4220eca0b544"}
3702025-03-17T22:41:11.213Z{"msg":"client set_active_request while in Connecting { state: Start { auto_promote: true }, mode: New }; waiting...","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:41:10.221073884Z","hostname":"w-01JPK3TSG4GD7HGEZJP118DX4C","pid":1244,"client":"0","":"downstairs","session_id":"802dea9a-2e19-4e6b-b28f-4220eca0b544"}
3712025-03-17T22:41:11.213Z{"msg":"sending connect oneshot to client","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:41:10.22109806Z","hostname":"w-01JPK3TSG4GD7HGEZJP118DX4C","pid":1244,"client":"1","":"downstairs","session_id":"802dea9a-2e19-4e6b-b28f-4220eca0b544"}
3722025-03-17T22:41:11.213Z{"msg":"client set_active_request while in Connecting { state: Start { auto_promote: true }, mode: New }; waiting...","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:41:10.221119536Z","hostname":"w-01JPK3TSG4GD7HGEZJP118DX4C","pid":1244,"client":"1","":"downstairs","session_id":"802dea9a-2e19-4e6b-b28f-4220eca0b544"}
3732025-03-17T22:41:11.213Z{"msg":"sending connect oneshot to client","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:41:10.221147591Z","hostname":"w-01JPK3TSG4GD7HGEZJP118DX4C","pid":1244,"client":"2","":"downstairs","session_id":"802dea9a-2e19-4e6b-b28f-4220eca0b544"}
3742025-03-17T22:41:11.214Z{"msg":"client set_active_request while in Connecting { state: Start { auto_promote: true }, mode: New }; waiting...","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:41:10.221176425Z","hostname":"w-01JPK3TSG4GD7HGEZJP118DX4C","pid":1244,"client":"2","":"downstairs","session_id":"802dea9a-2e19-4e6b-b28f-4220eca0b544"}
3752025-03-17T22:41:11.214Z{"msg":"connecting to 127.0.0.1:8860","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:41:10.221284215Z","hostname":"w-01JPK3TSG4GD7HGEZJP118DX4C","pid":1244,"":"io task","client":"2","":"downstairs","session_id":"802dea9a-2e19-4e6b-b28f-4220eca0b544"}
3762025-03-17T22:41:11.214Z{"msg":"connecting to 127.0.0.1:8840","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:41:10.221353232Z","hostname":"w-01JPK3TSG4GD7HGEZJP118DX4C","pid":1244,"":"io task","client":"0","":"downstairs","session_id":"802dea9a-2e19-4e6b-b28f-4220eca0b544"}
3772025-03-17T22:41:11.214Z{"msg":"connecting to 127.0.0.1:8850","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:41:10.221389726Z","hostname":"w-01JPK3TSG4GD7HGEZJP118DX4C","pid":1244,"":"io task","client":"1","":"downstairs","session_id":"802dea9a-2e19-4e6b-b28f-4220eca0b544"}
3782025-03-17T22:41:11.214Z{"msg":"ds_connection connected from Ok(127.0.0.1:43580)","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:41:10.221407322Z","hostname":"w-01JPK3TSG4GD7HGEZJP118DX4C","pid":1244,"":"io task","client":"0","":"downstairs","session_id":"802dea9a-2e19-4e6b-b28f-4220eca0b544"}
3792025-03-17T22:41:11.214Z{"msg":"ds_connection connected from Ok(127.0.0.1:49416)","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:41:10.221435837Z","hostname":"w-01JPK3TSG4GD7HGEZJP118DX4C","pid":1244,"":"io task","client":"2","":"downstairs","session_id":"802dea9a-2e19-4e6b-b28f-4220eca0b544"}
3802025-03-17T22:41:11.214Z{"msg":"ds_connection connected from Ok(127.0.0.1:61697)","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:41:10.221456293Z","hostname":"w-01JPK3TSG4GD7HGEZJP118DX4C","pid":1244,"":"io task","client":"1","":"downstairs","session_id":"802dea9a-2e19-4e6b-b28f-4220eca0b544"}
3812025-03-17T22:41:11.214Z{"msg":"version negotiation from state Connecting { state: WaitForPromote, mode: New }","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:41:10.221491767Z","hostname":"w-01JPK3TSG4GD7HGEZJP118DX4C","pid":1244,"client":"1","":"downstairs","session_id":"802dea9a-2e19-4e6b-b28f-4220eca0b544"}
3822025-03-17T22:41:11.214Z{"msg":"version negotiation from state Connecting { state: WaitForPromote, mode: New }","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:41:10.221518202Z","hostname":"w-01JPK3TSG4GD7HGEZJP118DX4C","pid":1244,"client":"2","":"downstairs","session_id":"802dea9a-2e19-4e6b-b28f-4220eca0b544"}
3832025-03-17T22:41:11.214Z{"msg":"version negotiation from state Connecting { state: WaitForPromote, mode: New }","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:41:10.221542647Z","hostname":"w-01JPK3TSG4GD7HGEZJP118DX4C","pid":1244,"client":"0","":"downstairs","session_id":"802dea9a-2e19-4e6b-b28f-4220eca0b544"}
3842025-03-17T22:41:11.214Z{"msg":"downstairs client at Some(127.0.0.1:8850) has region UUID 12345678-0000-0000-0000-000000008850","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:41:10.221941013Z","hostname":"w-01JPK3TSG4GD7HGEZJP118DX4C","pid":1244,"client":"1","":"downstairs","session_id":"802dea9a-2e19-4e6b-b28f-4220eca0b544"}
3852025-03-17T22:41:11.214Z{"msg":"downstairs client at Some(127.0.0.1:8840) has region UUID 12345678-0000-0000-0000-000000008840","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:41:10.221988675Z","hostname":"w-01JPK3TSG4GD7HGEZJP118DX4C","pid":1244,"client":"0","":"downstairs","session_id":"802dea9a-2e19-4e6b-b28f-4220eca0b544"}
3862025-03-17T22:41:11.214Z{"msg":"downstairs client at Some(127.0.0.1:8860) has region UUID 12345678-0000-0000-0000-000000008860","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:41:10.222096735Z","hostname":"w-01JPK3TSG4GD7HGEZJP118DX4C","pid":1244,"client":"2","":"downstairs","session_id":"802dea9a-2e19-4e6b-b28f-4220eca0b544"}
3872025-03-17T22:41:11.214Z{"msg":"Waiting for more clients to be ready","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:41:10.222271482Z","hostname":"w-01JPK3TSG4GD7HGEZJP118DX4C","pid":1244,"session_id":"802dea9a-2e19-4e6b-b28f-4220eca0b544"}
3882025-03-17T22:41:11.214Z{"msg":"Waiting for more clients to be ready","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:41:10.222350908Z","hostname":"w-01JPK3TSG4GD7HGEZJP118DX4C","pid":1244,"session_id":"802dea9a-2e19-4e6b-b28f-4220eca0b544"}
3892025-03-17T22:41:11.214Z{"msg":"[0]R flush_numbers: [5320, 5320, 5320, 5320, 5320]","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:41:10.22244635Z","hostname":"w-01JPK3TSG4GD7HGEZJP118DX4C","pid":1244,"":"downstairs","":"downstairs","session_id":"802dea9a-2e19-4e6b-b28f-4220eca0b544"}
3902025-03-17T22:41:11.215Z{"msg":"[0]R generation: [31, 31, 31, 31, 31]","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:41:10.222474525Z","hostname":"w-01JPK3TSG4GD7HGEZJP118DX4C","pid":1244,"":"downstairs","":"downstairs","session_id":"802dea9a-2e19-4e6b-b28f-4220eca0b544"}
3912025-03-17T22:41:11.215Z{"msg":"[0]R dirty: [false, false, false, false, false]","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:41:10.222489572Z","hostname":"w-01JPK3TSG4GD7HGEZJP118DX4C","pid":1244,"":"downstairs","":"downstairs","session_id":"802dea9a-2e19-4e6b-b28f-4220eca0b544"}
3922025-03-17T22:41:11.215Z{"msg":"[1]R flush_numbers: [5320, 5320, 5320, 5320, 5320]","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:41:10.222510088Z","hostname":"w-01JPK3TSG4GD7HGEZJP118DX4C","pid":1244,"":"downstairs","":"downstairs","session_id":"802dea9a-2e19-4e6b-b28f-4220eca0b544"}
3932025-03-17T22:41:11.215Z{"msg":"[1]R generation: [31, 31, 31, 31, 31]","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:41:10.222523016Z","hostname":"w-01JPK3TSG4GD7HGEZJP118DX4C","pid":1244,"":"downstairs","":"downstairs","session_id":"802dea9a-2e19-4e6b-b28f-4220eca0b544"}
3942025-03-17T22:41:11.215Z{"msg":"[1]R dirty: [false, false, false, false, false]","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:41:10.222542672Z","hostname":"w-01JPK3TSG4GD7HGEZJP118DX4C","pid":1244,"":"downstairs","":"downstairs","session_id":"802dea9a-2e19-4e6b-b28f-4220eca0b544"}
3952025-03-17T22:41:11.215Z{"msg":"[2]R flush_numbers: [5320, 5320, 5320, 5320, 5320]","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:41:10.222555949Z","hostname":"w-01JPK3TSG4GD7HGEZJP118DX4C","pid":1244,"":"downstairs","":"downstairs","session_id":"802dea9a-2e19-4e6b-b28f-4220eca0b544"}
3962025-03-17T22:41:11.215Z{"msg":"[2]R generation: [31, 31, 31, 31, 31]","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:41:10.222575236Z","hostname":"w-01JPK3TSG4GD7HGEZJP118DX4C","pid":1244,"":"downstairs","":"downstairs","session_id":"802dea9a-2e19-4e6b-b28f-4220eca0b544"}
3972025-03-17T22:41:11.215Z{"msg":"[2]R dirty: [false, false, false, false, false]","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:41:10.222588533Z","hostname":"w-01JPK3TSG4GD7HGEZJP118DX4C","pid":1244,"":"downstairs","":"downstairs","session_id":"802dea9a-2e19-4e6b-b28f-4220eca0b544"}
3982025-03-17T22:41:11.215Z{"msg":"Max found gen is 32","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:41:10.22260828Z","hostname":"w-01JPK3TSG4GD7HGEZJP118DX4C","pid":1244,"":"downstairs","":"downstairs","session_id":"802dea9a-2e19-4e6b-b28f-4220eca0b544"}
3992025-03-17T22:41:11.215Z{"msg":"Generation requested: 32 >= found:32","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:41:10.222622807Z","hostname":"w-01JPK3TSG4GD7HGEZJP118DX4C","pid":1244,"":"downstairs","":"downstairs","session_id":"802dea9a-2e19-4e6b-b28f-4220eca0b544"}
4002025-03-17T22:41:11.215Z{"msg":"Next flush: 5321","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:41:10.222643523Z","hostname":"w-01JPK3TSG4GD7HGEZJP118DX4C","pid":1244,"":"downstairs","":"downstairs","session_id":"802dea9a-2e19-4e6b-b28f-4220eca0b544"}
4012025-03-17T22:41:11.215Z{"msg":"All extents match","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:41:10.222656791Z","hostname":"w-01JPK3TSG4GD7HGEZJP118DX4C","pid":1244,"":"downstairs","":"downstairs","session_id":"802dea9a-2e19-4e6b-b28f-4220eca0b544"}
4022025-03-17T22:41:11.215Z{"msg":"No downstairs reconciliation required","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:41:10.222676837Z","hostname":"w-01JPK3TSG4GD7HGEZJP118DX4C","pid":1244,"session_id":"802dea9a-2e19-4e6b-b28f-4220eca0b544"}
4032025-03-17T22:41:11.215ZWait for a query_work_queue command to finish before sending IO
4042025-03-17T22:41:11.215Z{"msg":"Transition from WaitQuorum to Active","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:41:10.222695133Z","hostname":"w-01JPK3TSG4GD7HGEZJP118DX4C","pid":1244,"client":"0","":"downstairs","session_id":"802dea9a-2e19-4e6b-b28f-4220eca0b544"}
4052025-03-17T22:41:11.216Z{"msg":"Transition from WaitQuorum to Active","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:41:10.222708941Z","hostname":"w-01JPK3TSG4GD7HGEZJP118DX4C","pid":1244,"client":"1","":"downstairs","session_id":"802dea9a-2e19-4e6b-b28f-4220eca0b544"}
4062025-03-17T22:41:11.216Z{"msg":"Transition from WaitQuorum to Active","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:41:10.222721659Z","hostname":"w-01JPK3TSG4GD7HGEZJP118DX4C","pid":1244,"client":"2","":"downstairs","session_id":"802dea9a-2e19-4e6b-b28f-4220eca0b544"}
4072025-03-17T22:41:11.216Z{"msg":"All required reconciliation work is completed","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:41:10.222741355Z","hostname":"w-01JPK3TSG4GD7HGEZJP118DX4C","pid":1244,"session_id":"802dea9a-2e19-4e6b-b28f-4220eca0b544"}
4082025-03-17T22:41:11.216Z{"msg":"Set Downstairs and Upstairs active after reconciliation","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:41:10.222753663Z","hostname":"w-01JPK3TSG4GD7HGEZJP118DX4C","pid":1244,"session_id":"802dea9a-2e19-4e6b-b28f-4220eca0b544"}
4092025-03-17T22:41:11.216Z{"msg":"9d0f65c4-d9d6-4412-9ac0-1bf0c5936055 is now active with session: 802dea9a-2e19-4e6b-b28f-4220eca0b544","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:41:10.22276706Z","hostname":"w-01JPK3TSG4GD7HGEZJP118DX4C","pid":1244,"session_id":"802dea9a-2e19-4e6b-b28f-4220eca0b544"}
4102025-03-17T22:41:11.216Z{"msg":"Set Active after no reconciliation","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:41:10.222785897Z","hostname":"w-01JPK3TSG4GD7HGEZJP118DX4C","pid":1244,"session_id":"802dea9a-2e19-4e6b-b28f-4220eca0b544"}
4112025-03-17T22:41:11.216Z{"msg":"The guest has finished waiting for activation with:32","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:41:10.222798105Z","hostname":"w-01JPK3TSG4GD7HGEZJP118DX4C","pid":1244}
4122025-03-17T22:41:11.216Z{"msg":"Activated sub_volume 9d0f65c4-d9d6-4412-9ac0-1bf0c5936055","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:41:10.222809642Z","hostname":"w-01JPK3TSG4GD7HGEZJP118DX4C","pid":1244}
4132025-03-17T22:41:11.216ZDisk: sv:2 bs:4096 ts:409600 tb:100 max_io:100 or 409600
4142025-03-17T22:41:11.216ZLoading write count information from file "/var/tmp/test_up-build/verify_file"
4152025-03-17T22:41:11.216ZFill test
4162025-03-17T22:41:11.249ZRead and Verify all blocks (0..100 range:false)
4172025-03-17T22:41:11.328ZWrote out file "/var/tmp/test_up-build/verify_file"
4182025-03-17T22:41:11.328ZCLIENT: Tests done. All submitted work has been ACK'd
4192025-03-17T22:41:11.329Z----------------------------------------------------------------
4202025-03-17T22:41:11.329Z Crucible gen:32 GIO:true work queues: Upstairs:0 downstairs:1
4212025-03-17T22:41:11.329ZStates: Active Active Active
4222025-03-17T22:41:11.329ZJOBID ACK TYPE BKS/EXT DS:0 DS:1 DS:2 REPLAY
4232025-03-17T22:41:11.332Z 1002 Acked Read 50 Done Done Done false
4242025-03-17T22:41:11.332Z STATES DS:0 DS:1 DS:2 TOTAL
4252025-03-17T22:41:11.332Z Sent 0 0 0 0
4262025-03-17T22:41:11.333Z Done 1 1 1 3
4272025-03-17T22:41:11.333Z Skipped 0 0 0 0
4282025-03-17T22:41:11.333Z Error 0 0 0 0
4292025-03-17T22:41:11.333ZLast Flush: Some(JobId(1001)) Some(JobId(1001)) Some(JobId(1001))
4302025-03-17T22:41:11.333ZDownstairs last five completed: 1001 1000
4312025-03-17T22:41:11.333ZUpstairs last five completed: 1002 1001 1000
4322025-03-17T22:41:11.333Z----------------------------------------------------------------
4332025-03-17T22:41:11.333Z Crucible gen:32 GIO:true work queues: Upstairs:0 downstairs:1
4342025-03-17T22:41:11.333ZStates: Active Active Active
4352025-03-17T22:41:11.333ZJOBID ACK TYPE BKS/EXT DS:0 DS:1 DS:2 REPLAY
4362025-03-17T22:41:11.334Z 1002 Acked Read 50 Sent Sent Done false
4372025-03-17T22:41:11.334Z STATES DS:0 DS:1 DS:2 TOTAL
4382025-03-17T22:41:11.334Z Sent 1 1 0 2
4392025-03-17T22:41:11.334Z Done 0 0 1 1
4402025-03-17T22:41:11.334Z Skipped 0 0 0 0
4412025-03-17T22:41:11.334Z Error 0 0 0 0
4422025-03-17T22:41:11.334ZLast Flush: Some(JobId(1001)) Some(JobId(1001)) Some(JobId(1001))
4432025-03-17T22:41:11.334ZDownstairs last five completed: 1001 1000
4442025-03-17T22:41:11.334ZUpstairs last five completed: 1002 1001 1000
4452025-03-17T22:41:11.334ZCLIENT: Up:0 ds:2 act:6
4462025-03-17T22:41:15.329Z----------------------------------------------------------------
4472025-03-17T22:41:15.329Z Crucible gen:32 GIO:true work queues: Upstairs:0 downstairs:0
4482025-03-17T22:41:15.329ZDownstairs last five completed: 1003 1002 1001 1000
4492025-03-17T22:41:15.329ZUpstairs last five completed: 1003 1002 1001 1000
4502025-03-17T22:41:15.333Z----------------------------------------------------------------
4512025-03-17T22:41:15.333Z Crucible gen:32 GIO:true work queues: Upstairs:0 downstairs:0
4522025-03-17T22:41:15.333ZDownstairs last five completed: 1003 1002 1001 1000
4532025-03-17T22:41:15.333ZUpstairs last five completed: 1003 1002 1001 1000
4542025-03-17T22:41:15.333ZCLIENT: Up:0 ds:0 act:6
4552025-03-17T22:41:15.333ZCLIENT: All crucible jobs finished, exiting program
4562025-03-17T22:41:15.333Z{"msg":"Guest handle has been dropped","v":0,"name":"crucible","level":40,"time":"2025-03-17T22:41:14.344919876Z","hostname":"w-01JPK3TSG4GD7HGEZJP118DX4C","pid":1244}
4572025-03-17T22:41:15.337ZRepair part 1 passed
4582025-03-17T22:41:15.337Z
4592025-03-17T22:41:15.337ZKill the current downstairs
4602025-03-17T22:41:15.508ZDownstairs 2 stopped
4612025-03-17T22:41:15.508Zmv /var/tmp/test_up-build/8830 /var/tmp/test_up-build/new
4622025-03-17T22:41:15.512ZNow put back the original so we have a mismatch
4632025-03-17T22:41:15.512Zmv /var/tmp/test_up-build/previous /var/tmp/test_up-build/8830
4642025-03-17T22:41:15.515ZRestart downstairs with old directory
4652025-03-17T22:41:15.568Z/var/tmp/bins/crucible-downstairs dump --no-color -d /var/tmp/test_up-build/8810 -d /var/tmp/test_up-build/8820 -d /var/tmp/test_up-build/8830
4662025-03-17T22:41:15.585ZEXT BLOCKS GEN0 GEN1 GEN2 FL0 FL1 FL2 D0 D1 D2 DIFF
4672025-03-17T22:41:15.588Z 0 000-009 32 32 31 4002 4002 4001 F F F <---
4682025-03-17T22:41:15.588Z 1 010-019 32 32 31 4002 4002 4001 F F F <---
4692025-03-17T22:41:15.588Z 2 020-029 32 32 31 4002 4002 4001 F F F <---
4702025-03-17T22:41:15.588Z 3 030-039 32 32 31 4002 4002 4001 F F F <---
4712025-03-17T22:41:15.588Z 4 040-049 32 32 31 4002 4002 4001 F F F <---
4722025-03-17T22:41:15.589ZMax gen: 32, Max flush: 4002
4732025-03-17T22:41:15.589ZError: Difference in extent metadata found!
4742025-03-17T22:41:15.592Zdump test found error as expected
4752025-03-17T22:41:15.593Z
4762025-03-17T22:41:15.593Z
4772025-03-17T22:41:15.593Z/var/tmp/bins/crutest verify --range -g 33 -q --key iyNjT3xeuGYhhftr21OU3I2u+/KzkJyUMqiH19BBbu8= --dsc 127.0.0.1:9998 --verify-out /var/tmp/test_up-build/verify_file --verify-in /var/tmp/test_up-build/verify_file
4782025-03-17T22:41:15.749Z{"msg":"Use this region info from dsc: RegionExtentInfo { block_size: 4096, blocks_per_extent: 10, extent_count: 5 }","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:41:14.661764168Z","hostname":"w-01JPK3TSG4GD7HGEZJP118DX4C","pid":1252,"task":"crutest"}
4792025-03-17T22:41:15.754Z{"msg":"dsc has 6 regions. This means 2 sub_volumes","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:41:14.662348959Z","hostname":"w-01JPK3TSG4GD7HGEZJP118DX4C","pid":1252,"task":"crutest"}
4802025-03-17T22:41:15.754Z{"msg":"SV 0 has targets: [127.0.0.1:8810, 127.0.0.1:8820, 127.0.0.1:8830]","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:41:14.664083418Z","hostname":"w-01JPK3TSG4GD7HGEZJP118DX4C","pid":1252,"task":"crutest"}
4812025-03-17T22:41:15.754Z{"msg":"Upstairs starts","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:41:14.664278461Z","hostname":"w-01JPK3TSG4GD7HGEZJP118DX4C","pid":1252}
4822025-03-17T22:41:15.754Z{"msg":"Crucible Version: BuildInfo {\n version: \"0.0.1\",\n git_sha: \"45feeae3dd1bdcd88dce11a80acb5415f57b38bc\",\n git_commit_timestamp: \"2025-03-17T22:11:58.000000000Z\",\n git_branch: \"renovate/opentelemetry-0.x\",\n rustc_semver: \"1.84.0\",\n rustc_channel: \"stable\",\n rustc_host_triple: \"x86_64-unknown-illumos\",\n rustc_commit_sha: \"9fc6b43126469e3858e2fe86cafb4f0fd5068869\",\n cargo_triple: \"x86_64-unknown-illumos\",\n debug: true,\n opt_level: 0,\n}","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:41:14.664325973Z","hostname":"w-01JPK3TSG4GD7HGEZJP118DX4C","pid":1252}
4832025-03-17T22:41:15.754Z{"msg":"Upstairs <-> Downstairs Message Version: 13","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:41:14.664350238Z","hostname":"w-01JPK3TSG4GD7HGEZJP118DX4C","pid":1252}
4842025-03-17T22:41:15.754Z{"msg":"Using region definition RegionDefinition { block_size: 4096, extent_size: Block { value: 10, shift: 12 }, extent_count: 5, uuid: 00000000-0000-0000-0000-000000000000, encrypted: true, database_read_version: 1, database_write_version: 1 }","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:41:14.664366165Z","hostname":"w-01JPK3TSG4GD7HGEZJP118DX4C","pid":1252}
4852025-03-17T22:41:15.754Z{"msg":"Crucible 377c2fa4-f907-47c0-80b8-c36ee865be25 has session id: 23d314cc-bbbd-4b93-8668-2fb4e270d8bc","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:41:14.664961005Z","hostname":"w-01JPK3TSG4GD7HGEZJP118DX4C","pid":1252,"session_id":"23d314cc-bbbd-4b93-8668-2fb4e270d8bc"}
4862025-03-17T22:41:15.754Z{"msg":"Upstairs opts: Upstairs UUID: 377c2fa4-f907-47c0-80b8-c36ee865be25, Targets: [127.0.0.1:8810, 127.0.0.1:8820, 127.0.0.1:8830], lossy: false, flush_timeout: None, key populated: true, cert_pem populated: false, key_pem populated: false, root_cert_pem populated: false, Control: None, read_only: false","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:41:14.665024983Z","hostname":"w-01JPK3TSG4GD7HGEZJP118DX4C","pid":1252,"session_id":"23d314cc-bbbd-4b93-8668-2fb4e270d8bc"}
4872025-03-17T22:41:15.754Z{"msg":"Crucible stats registered with UUID: 377c2fa4-f907-47c0-80b8-c36ee865be25","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:41:14.665065875Z","hostname":"w-01JPK3TSG4GD7HGEZJP118DX4C","pid":1252,"session_id":"23d314cc-bbbd-4b93-8668-2fb4e270d8bc"}
4882025-03-17T22:41:15.754Z{"msg":"could not find Downstairs address for Nexus","v":0,"name":"crucible","level":40,"time":"2025-03-17T22:41:14.665110757Z","hostname":"w-01JPK3TSG4GD7HGEZJP118DX4C","pid":1252,"session_id":"23d314cc-bbbd-4b93-8668-2fb4e270d8bc"}
4892025-03-17T22:41:15.755Z{"msg":"SV 1 has targets: [127.0.0.1:8840, 127.0.0.1:8850, 127.0.0.1:8860]","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:41:14.667085761Z","hostname":"w-01JPK3TSG4GD7HGEZJP118DX4C","pid":1252,"task":"crutest"}
4902025-03-17T22:41:15.755Z{"msg":"Upstairs starts","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:41:14.667163136Z","hostname":"w-01JPK3TSG4GD7HGEZJP118DX4C","pid":1252}
4912025-03-17T22:41:15.755Z{"msg":"Crucible Version: BuildInfo {\n version: \"0.0.1\",\n git_sha: \"45feeae3dd1bdcd88dce11a80acb5415f57b38bc\",\n git_commit_timestamp: \"2025-03-17T22:11:58.000000000Z\",\n git_branch: \"renovate/opentelemetry-0.x\",\n rustc_semver: \"1.84.0\",\n rustc_channel: \"stable\",\n rustc_host_triple: \"x86_64-unknown-illumos\",\n rustc_commit_sha: \"9fc6b43126469e3858e2fe86cafb4f0fd5068869\",\n cargo_triple: \"x86_64-unknown-illumos\",\n debug: true,\n opt_level: 0,\n}","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:41:14.667205789Z","hostname":"w-01JPK3TSG4GD7HGEZJP118DX4C","pid":1252}
4922025-03-17T22:41:15.755Z{"msg":"Upstairs <-> Downstairs Message Version: 13","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:41:14.667221586Z","hostname":"w-01JPK3TSG4GD7HGEZJP118DX4C","pid":1252}
4932025-03-17T22:41:15.755Z{"msg":"Using region definition RegionDefinition { block_size: 4096, extent_size: Block { value: 10, shift: 12 }, extent_count: 5, uuid: 00000000-0000-0000-0000-000000000000, encrypted: true, database_read_version: 1, database_write_version: 1 }","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:41:14.667235953Z","hostname":"w-01JPK3TSG4GD7HGEZJP118DX4C","pid":1252}
4942025-03-17T22:41:15.755Z{"msg":"Crucible 377c2fa4-f907-47c0-80b8-c36ee865be25 has session id: c1edb294-a874-4445-8479-711e355ed25f","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:41:14.667569771Z","hostname":"w-01JPK3TSG4GD7HGEZJP118DX4C","pid":1252,"session_id":"c1edb294-a874-4445-8479-711e355ed25f"}
4952025-03-17T22:41:15.755Z{"msg":"Upstairs opts: Upstairs UUID: 377c2fa4-f907-47c0-80b8-c36ee865be25, Targets: [127.0.0.1:8840, 127.0.0.1:8850, 127.0.0.1:8860], lossy: false, flush_timeout: None, key populated: true, cert_pem populated: false, key_pem populated: false, root_cert_pem populated: false, Control: None, read_only: false","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:41:14.667617572Z","hostname":"w-01JPK3TSG4GD7HGEZJP118DX4C","pid":1252,"session_id":"c1edb294-a874-4445-8479-711e355ed25f"}
4962025-03-17T22:41:15.755Z{"msg":"Crucible stats registered with UUID: 377c2fa4-f907-47c0-80b8-c36ee865be25","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:41:14.667654655Z","hostname":"w-01JPK3TSG4GD7HGEZJP118DX4C","pid":1252,"session_id":"c1edb294-a874-4445-8479-711e355ed25f"}
4972025-03-17T22:41:15.755Z{"msg":"could not find Downstairs address for Nexus","v":0,"name":"crucible","level":40,"time":"2025-03-17T22:41:14.667677751Z","hostname":"w-01JPK3TSG4GD7HGEZJP118DX4C","pid":1252,"session_id":"c1edb294-a874-4445-8479-711e355ed25f"}
4982025-03-17T22:41:15.755Z{"msg":"Downstairs in volume = 6","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:41:14.668327111Z","hostname":"w-01JPK3TSG4GD7HGEZJP118DX4C","pid":1252,"task":"crutest"}
4992025-03-17T22:41:15.755Z{"msg":"The guest has requested activation with gen:33","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:41:14.668375172Z","hostname":"w-01JPK3TSG4GD7HGEZJP118DX4C","pid":1252}
5002025-03-17T22:41:15.755Z{"msg":"377c2fa4-f907-47c0-80b8-c36ee865be25 active request set","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:41:14.668402427Z","hostname":"w-01JPK3TSG4GD7HGEZJP118DX4C","pid":1252,"session_id":"23d314cc-bbbd-4b93-8668-2fb4e270d8bc"}
5012025-03-17T22:41:15.755Z{"msg":"sending connect oneshot to client","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:41:14.668427562Z","hostname":"w-01JPK3TSG4GD7HGEZJP118DX4C","pid":1252,"client":"0","":"downstairs","session_id":"23d314cc-bbbd-4b93-8668-2fb4e270d8bc"}
5022025-03-17T22:41:15.755Z{"msg":"client set_active_request while in Connecting { state: Start { auto_promote: true }, mode: New }; waiting...","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:41:14.668481912Z","hostname":"w-01JPK3TSG4GD7HGEZJP118DX4C","pid":1252,"client":"0","":"downstairs","session_id":"23d314cc-bbbd-4b93-8668-2fb4e270d8bc"}
5032025-03-17T22:41:15.755Z{"msg":"sending connect oneshot to client","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:41:14.668528423Z","hostname":"w-01JPK3TSG4GD7HGEZJP118DX4C","pid":1252,"client":"1","":"downstairs","session_id":"23d314cc-bbbd-4b93-8668-2fb4e270d8bc"}
5042025-03-17T22:41:15.755Z{"msg":"client set_active_request while in Connecting { state: Start { auto_promote: true }, mode: New }; waiting...","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:41:14.668571625Z","hostname":"w-01JPK3TSG4GD7HGEZJP118DX4C","pid":1252,"client":"1","":"downstairs","session_id":"23d314cc-bbbd-4b93-8668-2fb4e270d8bc"}
5052025-03-17T22:41:15.755Z{"msg":"sending connect oneshot to client","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:41:14.668590182Z","hostname":"w-01JPK3TSG4GD7HGEZJP118DX4C","pid":1252,"client":"2","":"downstairs","session_id":"23d314cc-bbbd-4b93-8668-2fb4e270d8bc"}
5062025-03-17T22:41:15.755Z{"msg":"client set_active_request while in Connecting { state: Start { auto_promote: true }, mode: New }; waiting...","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:41:14.668607429Z","hostname":"w-01JPK3TSG4GD7HGEZJP118DX4C","pid":1252,"client":"2","":"downstairs","session_id":"23d314cc-bbbd-4b93-8668-2fb4e270d8bc"}
5072025-03-17T22:41:15.755Z{"msg":"connecting to 127.0.0.1:8830","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:41:14.668634514Z","hostname":"w-01JPK3TSG4GD7HGEZJP118DX4C","pid":1252,"":"io task","client":"2","":"downstairs","session_id":"23d314cc-bbbd-4b93-8668-2fb4e270d8bc"}
5082025-03-17T22:41:15.755Z{"msg":"connecting to 127.0.0.1:8810","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:41:14.668651301Z","hostname":"w-01JPK3TSG4GD7HGEZJP118DX4C","pid":1252,"":"io task","client":"0","":"downstairs","session_id":"23d314cc-bbbd-4b93-8668-2fb4e270d8bc"}
5092025-03-17T22:41:15.755Z{"msg":"connecting to 127.0.0.1:8820","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:41:14.668685304Z","hostname":"w-01JPK3TSG4GD7HGEZJP118DX4C","pid":1252,"":"io task","client":"1","":"downstairs","session_id":"23d314cc-bbbd-4b93-8668-2fb4e270d8bc"}
5102025-03-17T22:41:15.755Z{"msg":"ds_connection connect to 127.0.0.1:8830 failure: Os { code: 146, kind: ConnectionRefused, message: \"Connection refused\" }","v":0,"name":"crucible","level":40,"time":"2025-03-17T22:41:14.66870744Z","hostname":"w-01JPK3TSG4GD7HGEZJP118DX4C","pid":1252,"":"io task","client":"2","":"downstairs","session_id":"23d314cc-bbbd-4b93-8668-2fb4e270d8bc"}
5112025-03-17T22:41:15.755Z{"msg":"client task is sending Done(ConnectionFailed(Os { code: 146, kind: ConnectionRefused, message: \"Connection refused\" }))","v":0,"name":"crucible","level":40,"time":"2025-03-17T22:41:14.668739004Z","hostname":"w-01JPK3TSG4GD7HGEZJP118DX4C","pid":1252,"":"io task","client":"2","":"downstairs","session_id":"23d314cc-bbbd-4b93-8668-2fb4e270d8bc"}
5122025-03-17T22:41:15.755Z{"msg":"ds_connection connected from Ok(127.0.0.1:54360)","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:41:14.66876111Z","hostname":"w-01JPK3TSG4GD7HGEZJP118DX4C","pid":1252,"":"io task","client":"0","":"downstairs","session_id":"23d314cc-bbbd-4b93-8668-2fb4e270d8bc"}
5132025-03-17T22:41:15.755Z{"msg":"ds_connection connected from Ok(127.0.0.1:53066)","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:41:14.668782776Z","hostname":"w-01JPK3TSG4GD7HGEZJP118DX4C","pid":1252,"":"io task","client":"1","":"downstairs","session_id":"23d314cc-bbbd-4b93-8668-2fb4e270d8bc"}
5142025-03-17T22:41:15.755Z{"msg":"downstairs task for 2 stopped due to ConnectionFailed(Os { code: 146, kind: ConnectionRefused, message: \"Connection refused\" })","v":0,"name":"crucible","level":40,"time":"2025-03-17T22:41:14.668807212Z","hostname":"w-01JPK3TSG4GD7HGEZJP118DX4C","pid":1252,"session_id":"23d314cc-bbbd-4b93-8668-2fb4e270d8bc"}
5152025-03-17T22:41:15.755Z{"msg":"client task is exiting","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:41:14.66897842Z","hostname":"w-01JPK3TSG4GD7HGEZJP118DX4C","pid":1252,"":"io task","client":"2","":"downstairs","session_id":"23d314cc-bbbd-4b93-8668-2fb4e270d8bc"}
5162025-03-17T22:41:15.755Z{"msg":"version negotiation from state Connecting { state: WaitForPromote, mode: New }","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:41:14.669273905Z","hostname":"w-01JPK3TSG4GD7HGEZJP118DX4C","pid":1252,"client":"0","":"downstairs","session_id":"23d314cc-bbbd-4b93-8668-2fb4e270d8bc"}
5172025-03-17T22:41:15.755Z{"msg":"version negotiation from state Connecting { state: WaitForPromote, mode: New }","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:41:14.669315048Z","hostname":"w-01JPK3TSG4GD7HGEZJP118DX4C","pid":1252,"client":"1","":"downstairs","session_id":"23d314cc-bbbd-4b93-8668-2fb4e270d8bc"}
5182025-03-17T22:41:15.755Z{"msg":"downstairs client at Some(127.0.0.1:8810) has region UUID 12345678-0000-0000-0000-000000008810","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:41:14.66989265Z","hostname":"w-01JPK3TSG4GD7HGEZJP118DX4C","pid":1252,"client":"0","":"downstairs","session_id":"23d314cc-bbbd-4b93-8668-2fb4e270d8bc"}
5192025-03-17T22:41:15.755Z{"msg":"downstairs client at Some(127.0.0.1:8820) has region UUID 12345678-0000-0000-0000-000000008820","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:41:14.669930663Z","hostname":"w-01JPK3TSG4GD7HGEZJP118DX4C","pid":1252,"client":"1","":"downstairs","session_id":"23d314cc-bbbd-4b93-8668-2fb4e270d8bc"}
5202025-03-17T22:41:15.755Z{"msg":"Waiting for more clients to be ready","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:41:14.670309563Z","hostname":"w-01JPK3TSG4GD7HGEZJP118DX4C","pid":1252,"session_id":"23d314cc-bbbd-4b93-8668-2fb4e270d8bc"}
5212025-03-17T22:41:15.755Z{"msg":"Waiting for more clients to be ready","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:41:14.670350336Z","hostname":"w-01JPK3TSG4GD7HGEZJP118DX4C","pid":1252,"session_id":"23d314cc-bbbd-4b93-8668-2fb4e270d8bc"}
5222025-03-17T22:41:25.656Z{"msg":"connecting to 127.0.0.1:8830","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:41:24.669555979Z","hostname":"w-01JPK3TSG4GD7HGEZJP118DX4C","pid":1252,"":"io task","client":"2","":"downstairs","session_id":"23d314cc-bbbd-4b93-8668-2fb4e270d8bc"}
5232025-03-17T22:41:25.663Z{"msg":"ds_connection connected from Ok(127.0.0.1:53402)","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:41:24.669743904Z","hostname":"w-01JPK3TSG4GD7HGEZJP118DX4C","pid":1252,"":"io task","client":"2","":"downstairs","session_id":"23d314cc-bbbd-4b93-8668-2fb4e270d8bc"}
5242025-03-17T22:41:25.663Z{"msg":"version negotiation from state Connecting { state: WaitForPromote, mode: New }","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:41:24.670935733Z","hostname":"w-01JPK3TSG4GD7HGEZJP118DX4C","pid":1252,"client":"2","":"downstairs","session_id":"23d314cc-bbbd-4b93-8668-2fb4e270d8bc"}
5252025-03-17T22:41:25.663Z{"msg":"downstairs client at Some(127.0.0.1:8830) has region UUID 12345678-0000-0000-0000-000000008830","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:41:24.671495369Z","hostname":"w-01JPK3TSG4GD7HGEZJP118DX4C","pid":1252,"client":"2","":"downstairs","session_id":"23d314cc-bbbd-4b93-8668-2fb4e270d8bc"}
5262025-03-17T22:41:25.663Z{"msg":"[0]R flush_numbers: [4002, 4002, 4002, 4002, 4002]","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:41:24.671904723Z","hostname":"w-01JPK3TSG4GD7HGEZJP118DX4C","pid":1252,"":"downstairs","":"downstairs","session_id":"23d314cc-bbbd-4b93-8668-2fb4e270d8bc"}
5272025-03-17T22:41:25.663Z{"msg":"[0]R generation: [32, 32, 32, 32, 32]","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:41:24.671934408Z","hostname":"w-01JPK3TSG4GD7HGEZJP118DX4C","pid":1252,"":"downstairs","":"downstairs","session_id":"23d314cc-bbbd-4b93-8668-2fb4e270d8bc"}
5282025-03-17T22:41:25.663Z{"msg":"[0]R dirty: [false, false, false, false, false]","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:41:24.671950495Z","hostname":"w-01JPK3TSG4GD7HGEZJP118DX4C","pid":1252,"":"downstairs","":"downstairs","session_id":"23d314cc-bbbd-4b93-8668-2fb4e270d8bc"}
5292025-03-17T22:41:25.663Z{"msg":"[1]R flush_numbers: [4002, 4002, 4002, 4002, 4002]","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:41:24.671983358Z","hostname":"w-01JPK3TSG4GD7HGEZJP118DX4C","pid":1252,"":"downstairs","":"downstairs","session_id":"23d314cc-bbbd-4b93-8668-2fb4e270d8bc"}
5302025-03-17T22:41:25.663Z{"msg":"[1]R generation: [32, 32, 32, 32, 32]","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:41:24.672026581Z","hostname":"w-01JPK3TSG4GD7HGEZJP118DX4C","pid":1252,"":"downstairs","":"downstairs","session_id":"23d314cc-bbbd-4b93-8668-2fb4e270d8bc"}
5312025-03-17T22:41:25.663Z{"msg":"[1]R dirty: [false, false, false, false, false]","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:41:24.672057895Z","hostname":"w-01JPK3TSG4GD7HGEZJP118DX4C","pid":1252,"":"downstairs","":"downstairs","session_id":"23d314cc-bbbd-4b93-8668-2fb4e270d8bc"}
5322025-03-17T22:41:25.663Z{"msg":"[2]R flush_numbers: [4001, 4001, 4001, 4001, 4001]","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:41:24.672091889Z","hostname":"w-01JPK3TSG4GD7HGEZJP118DX4C","pid":1252,"":"downstairs","":"downstairs","session_id":"23d314cc-bbbd-4b93-8668-2fb4e270d8bc"}
5332025-03-17T22:41:25.663Z{"msg":"[2]R generation: [31, 31, 31, 31, 31]","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:41:24.672122153Z","hostname":"w-01JPK3TSG4GD7HGEZJP118DX4C","pid":1252,"":"downstairs","":"downstairs","session_id":"23d314cc-bbbd-4b93-8668-2fb4e270d8bc"}
5342025-03-17T22:41:25.663Z{"msg":"[2]R dirty: [false, false, false, false, false]","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:41:24.672154227Z","hostname":"w-01JPK3TSG4GD7HGEZJP118DX4C","pid":1252,"":"downstairs","":"downstairs","session_id":"23d314cc-bbbd-4b93-8668-2fb4e270d8bc"}
5352025-03-17T22:41:25.663Z{"msg":"Max found gen is 33","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:41:24.672169824Z","hostname":"w-01JPK3TSG4GD7HGEZJP118DX4C","pid":1252,"":"downstairs","":"downstairs","session_id":"23d314cc-bbbd-4b93-8668-2fb4e270d8bc"}
5362025-03-17T22:41:25.663Z{"msg":"Generation requested: 33 >= found:33","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:41:24.67218908Z","hostname":"w-01JPK3TSG4GD7HGEZJP118DX4C","pid":1252,"":"downstairs","":"downstairs","session_id":"23d314cc-bbbd-4b93-8668-2fb4e270d8bc"}
5372025-03-17T22:41:25.663Z{"msg":"Next flush: 4003","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:41:24.672217605Z","hostname":"w-01JPK3TSG4GD7HGEZJP118DX4C","pid":1252,"":"downstairs","":"downstairs","session_id":"23d314cc-bbbd-4b93-8668-2fb4e270d8bc"}
5382025-03-17T22:41:25.663Z{"msg":"extent 0 needs reconciliation: ExtentMetadata { gen: 32, flush: 4002, dirty: false } ExtentMetadata { gen: 32, flush: 4002, dirty: false } ExtentMetadata { gen: 31, flush: 4001, dirty: false }","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:41:24.672238061Z","hostname":"w-01JPK3TSG4GD7HGEZJP118DX4C","pid":1252,"":"mend","":"downstairs","":"downstairs","session_id":"23d314cc-bbbd-4b93-8668-2fb4e270d8bc"}
5392025-03-17T22:41:25.663Z{"msg":"extent:0 [ExtentMetadata { gen: 32, flush: 4002, dirty: false }, ExtentMetadata { gen: 32, flush: 4002, dirty: false }, ExtentMetadata { gen: 31, flush: 4001, dirty: false }] => 0","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:41:24.672270245Z","hostname":"w-01JPK3TSG4GD7HGEZJP118DX4C","pid":1252,"":"mend","":"downstairs","":"downstairs","session_id":"23d314cc-bbbd-4b93-8668-2fb4e270d8bc"}
5402025-03-17T22:41:25.663Z{"msg":"found dest for source 0 for extent at index 0 => [ClientId(2)]","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:41:24.672286082Z","hostname":"w-01JPK3TSG4GD7HGEZJP118DX4C","pid":1252,"":"mend","":"downstairs","":"downstairs","session_id":"23d314cc-bbbd-4b93-8668-2fb4e270d8bc"}
5412025-03-17T22:41:25.663Z{"msg":"extent 1 needs reconciliation: ExtentMetadata { gen: 32, flush: 4002, dirty: false } ExtentMetadata { gen: 32, flush: 4002, dirty: false } ExtentMetadata { gen: 31, flush: 4001, dirty: false }","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:41:24.672335013Z","hostname":"w-01JPK3TSG4GD7HGEZJP118DX4C","pid":1252,"":"mend","":"downstairs","":"downstairs","session_id":"23d314cc-bbbd-4b93-8668-2fb4e270d8bc"}
5422025-03-17T22:41:25.663Z{"msg":"extent:0 [ExtentMetadata { gen: 32, flush: 4002, dirty: false }, ExtentMetadata { gen: 32, flush: 4002, dirty: false }, ExtentMetadata { gen: 31, flush: 4001, dirty: false }] => 0","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:41:24.672378235Z","hostname":"w-01JPK3TSG4GD7HGEZJP118DX4C","pid":1252,"":"mend","":"downstairs","":"downstairs","session_id":"23d314cc-bbbd-4b93-8668-2fb4e270d8bc"}
5432025-03-17T22:41:25.663Z{"msg":"found dest for source 0 for extent at index 1 => [ClientId(2)]","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:41:24.672419408Z","hostname":"w-01JPK3TSG4GD7HGEZJP118DX4C","pid":1252,"":"mend","":"downstairs","":"downstairs","session_id":"23d314cc-bbbd-4b93-8668-2fb4e270d8bc"}
5442025-03-17T22:41:25.663Z{"msg":"extent 2 needs reconciliation: ExtentMetadata { gen: 32, flush: 4002, dirty: false } ExtentMetadata { gen: 32, flush: 4002, dirty: false } ExtentMetadata { gen: 31, flush: 4001, dirty: false }","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:41:24.67245987Z","hostname":"w-01JPK3TSG4GD7HGEZJP118DX4C","pid":1252,"":"mend","":"downstairs","":"downstairs","session_id":"23d314cc-bbbd-4b93-8668-2fb4e270d8bc"}
5452025-03-17T22:41:25.663Z{"msg":"extent:0 [ExtentMetadata { gen: 32, flush: 4002, dirty: false }, ExtentMetadata { gen: 32, flush: 4002, dirty: false }, ExtentMetadata { gen: 31, flush: 4001, dirty: false }] => 0","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:41:24.672494284Z","hostname":"w-01JPK3TSG4GD7HGEZJP118DX4C","pid":1252,"":"mend","":"downstairs","":"downstairs","session_id":"23d314cc-bbbd-4b93-8668-2fb4e270d8bc"}
5462025-03-17T22:41:25.663Z{"msg":"found dest for source 0 for extent at index 2 => [ClientId(2)]","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:41:24.672511041Z","hostname":"w-01JPK3TSG4GD7HGEZJP118DX4C","pid":1252,"":"mend","":"downstairs","":"downstairs","session_id":"23d314cc-bbbd-4b93-8668-2fb4e270d8bc"}
5472025-03-17T22:41:25.663Z{"msg":"extent 3 needs reconciliation: ExtentMetadata { gen: 32, flush: 4002, dirty: false } ExtentMetadata { gen: 32, flush: 4002, dirty: false } ExtentMetadata { gen: 31, flush: 4001, dirty: false }","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:41:24.672533387Z","hostname":"w-01JPK3TSG4GD7HGEZJP118DX4C","pid":1252,"":"mend","":"downstairs","":"downstairs","session_id":"23d314cc-bbbd-4b93-8668-2fb4e270d8bc"}
5482025-03-17T22:41:25.663Z{"msg":"extent:0 [ExtentMetadata { gen: 32, flush: 4002, dirty: false }, ExtentMetadata { gen: 32, flush: 4002, dirty: false }, ExtentMetadata { gen: 31, flush: 4001, dirty: false }] => 0","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:41:24.672548954Z","hostname":"w-01JPK3TSG4GD7HGEZJP118DX4C","pid":1252,"":"mend","":"downstairs","":"downstairs","session_id":"23d314cc-bbbd-4b93-8668-2fb4e270d8bc"}
5492025-03-17T22:41:25.663Z{"msg":"found dest for source 0 for extent at index 3 => [ClientId(2)]","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:41:24.672564461Z","hostname":"w-01JPK3TSG4GD7HGEZJP118DX4C","pid":1252,"":"mend","":"downstairs","":"downstairs","session_id":"23d314cc-bbbd-4b93-8668-2fb4e270d8bc"}
5502025-03-17T22:41:25.663Z{"msg":"extent 4 needs reconciliation: ExtentMetadata { gen: 32, flush: 4002, dirty: false } ExtentMetadata { gen: 32, flush: 4002, dirty: false } ExtentMetadata { gen: 31, flush: 4001, dirty: false }","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:41:24.672591026Z","hostname":"w-01JPK3TSG4GD7HGEZJP118DX4C","pid":1252,"":"mend","":"downstairs","":"downstairs","session_id":"23d314cc-bbbd-4b93-8668-2fb4e270d8bc"}
5512025-03-17T22:41:25.663Z{"msg":"extent:0 [ExtentMetadata { gen: 32, flush: 4002, dirty: false }, ExtentMetadata { gen: 32, flush: 4002, dirty: false }, ExtentMetadata { gen: 31, flush: 4001, dirty: false }] => 0","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:41:24.672615531Z","hostname":"w-01JPK3TSG4GD7HGEZJP118DX4C","pid":1252,"":"mend","":"downstairs","":"downstairs","session_id":"23d314cc-bbbd-4b93-8668-2fb4e270d8bc"}
5522025-03-17T22:41:25.663Z{"msg":"found dest for source 0 for extent at index 4 => [ClientId(2)]","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:41:24.672647006Z","hostname":"w-01JPK3TSG4GD7HGEZJP118DX4C","pid":1252,"":"mend","":"downstairs","":"downstairs","session_id":"23d314cc-bbbd-4b93-8668-2fb4e270d8bc"}
5532025-03-17T22:41:25.663Z{"msg":"Transition from Connecting { state: WaitQuorum, mode: New } to Reconcile","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:41:24.672683059Z","hostname":"w-01JPK3TSG4GD7HGEZJP118DX4C","pid":1252,"client":"0","":"downstairs","session_id":"23d314cc-bbbd-4b93-8668-2fb4e270d8bc"}
5542025-03-17T22:41:25.663Z{"msg":"Transition from Connecting { state: WaitQuorum, mode: New } to Reconcile","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:41:24.672713833Z","hostname":"w-01JPK3TSG4GD7HGEZJP118DX4C","pid":1252,"client":"1","":"downstairs","session_id":"23d314cc-bbbd-4b93-8668-2fb4e270d8bc"}
5552025-03-17T22:41:25.664Z{"msg":"Transition from Connecting { state: WaitQuorum, mode: New } to Reconcile","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:41:24.672749696Z","hostname":"w-01JPK3TSG4GD7HGEZJP118DX4C","pid":1252,"client":"2","":"downstairs","session_id":"23d314cc-bbbd-4b93-8668-2fb4e270d8bc"}
5562025-03-17T22:41:25.664Z{"msg":"Full repair list: {ExtentId(2): ExtentFix { source: ClientId(0), dest: [ClientId(2)] }, ExtentId(0): ExtentFix { source: ClientId(0), dest: [ClientId(2)] }, ExtentId(3): ExtentFix { source: ClientId(0), dest: [ClientId(2)] }, ExtentId(4): ExtentFix { source: ClientId(0), dest: [ClientId(2)] }, ExtentId(1): ExtentFix { source: ClientId(0), dest: [ClientId(2)] }}","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:41:24.67278479Z","hostname":"w-01JPK3TSG4GD7HGEZJP118DX4C","pid":1252,"":"downstairs","":"downstairs","session_id":"23d314cc-bbbd-4b93-8668-2fb4e270d8bc"}
5572025-03-17T22:41:25.664Z{"msg":"Task list: [ReconcileIO { id: ReconciliationId(0), op: ExtentFlush { repair_id: ReconciliationId(0), extent_id: ExtentId(2), client_id: ClientId(0), flush_number: 4003, gen_number: 33 }, state: ClientData([New, New, New]) }, ReconcileIO { id: ReconciliationId(1), op: ExtentClose { repair_id: ReconciliationId(1), extent_id: ExtentId(2) }, state: ClientData([New, New, New]) }, ReconcileIO { id: ReconciliationId(2), op: ExtentRepair { repair_id: ReconciliationId(2), 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(3), op: ExtentReopen { repair_id: ReconciliationId(3), extent_id: ExtentId(2) }, state: ClientData([New, New, New]) }, ReconcileIO { id: ReconciliationId(4), op: ExtentFlush { repair_id: ReconciliationId(4), extent_id: ExtentId(0), client_id: ClientId(0), flush_number: 4003, gen_number: 33 }, state: ClientData([New, New, New]) }, ReconcileIO { id: ReconciliationId(5), op: ExtentClose { repair_id: ReconciliationId(5), extent_id: ExtentId(0) }, state: ClientData([New, New, New]) }, ReconcileIO { id: ReconciliationId(6), op: ExtentRepair { repair_id: ReconciliationId(6), 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(7), op: ExtentReopen { repair_id: ReconciliationId(7), extent_id: ExtentId(0) }, state: ClientData([New, New, New]) }, ReconcileIO { id: ReconciliationId(8), op: ExtentFlush { repair_id: ReconciliationId(8), extent_id: ExtentId(3), client_id: ClientId(0), flush_number: 4003, gen_number: 33 }, state: ClientData([New, New, New]) }, ReconcileIO { id: ReconciliationId(9), op: ExtentClose { repair_id: ReconciliationId(9), extent_id: ExtentId(3) }, state: ClientData([New, New, New]) }, ReconcileIO { id: ReconciliationId(10), op: ExtentRepair { repair_id: ReconciliationId(10), extent_id: ExtentId(3), source_client_id: ClientId(0), source_repair_address: 0.0.0.0:12810, dest_clients: [ClientId(2)] }, state: ClientData([New, New, New]) }, ReconcileIO { id: ReconciliationId(11), op: ExtentReopen { repair_id: ReconciliationId(11), extent_id: ExtentId(3) }, state: ClientData([New, New, New]) }, ReconcileIO { id: ReconciliationId(12), op: ExtentFlush { repair_id: ReconciliationId(12), extent_id: ExtentId(4), client_id: ClientId(0), flush_number: 4003, 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(1), client_id: ClientId(0), flush_number: 4003, gen_number: 33 }, state: ClientData([New, New, New]) }, ReconcileIO { id: ReconciliationId(17), op: ExtentClose { repair_id: ReconciliationId(17), extent_id: ExtentId(1) }, state: ClientData([New, New, New]) }, ReconcileIO { id: ReconciliationId(18), op: ExtentRepair { repair_id: ReconciliationId(18), 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(19), op: ExtentReopen { repair_id: ReconciliationId(19), extent_id: ExtentId(1) }, state: ClientData([New, New, New]) }]","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:41:24.672941721Z","hostname":"w-01JPK3TSG4GD7HGEZJP118DX4C","pid":1252,"":"downstairs","":"downstairs","session_id":"23d314cc-bbbd-4b93-8668-2fb4e270d8bc"}
5582025-03-17T22:41:25.664Z{"msg":"starting reconciliation 65aaa361-008f-4691-b858-6ac2666b1b96: found 20 extents that need repair","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:41:24.672979464Z","hostname":"w-01JPK3TSG4GD7HGEZJP118DX4C","pid":1252,"":"downstairs","":"downstairs","session_id":"23d314cc-bbbd-4b93-8668-2fb4e270d8bc"}
5592025-03-17T22:41:25.664Z{"msg":"sending reconcile request ReconciliationId(2)","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:41:24.673008028Z","hostname":"w-01JPK3TSG4GD7HGEZJP118DX4C","pid":1252,"client":"2","":"downstairs","session_id":"23d314cc-bbbd-4b93-8668-2fb4e270d8bc"}
5602025-03-17T22:41:25.668Z{"msg":"sending reconcile request ReconciliationId(6)","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:41:24.680791005Z","hostname":"w-01JPK3TSG4GD7HGEZJP118DX4C","pid":1252,"client":"2","":"downstairs","session_id":"23d314cc-bbbd-4b93-8668-2fb4e270d8bc"}
5612025-03-17T22:41:25.671Z{"msg":"sending reconcile request ReconciliationId(10)","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:41:24.684554788Z","hostname":"w-01JPK3TSG4GD7HGEZJP118DX4C","pid":1252,"client":"2","":"downstairs","session_id":"23d314cc-bbbd-4b93-8668-2fb4e270d8bc"}
5622025-03-17T22:41:25.683Z{"msg":"sending reconcile request ReconciliationId(14)","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:41:24.688093342Z","hostname":"w-01JPK3TSG4GD7HGEZJP118DX4C","pid":1252,"client":"2","":"downstairs","session_id":"23d314cc-bbbd-4b93-8668-2fb4e270d8bc"}
5632025-03-17T22:41:25.683Z{"msg":"sending reconcile request ReconciliationId(18)","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:41:24.691523506Z","hostname":"w-01JPK3TSG4GD7HGEZJP118DX4C","pid":1252,"client":"2","":"downstairs","session_id":"23d314cc-bbbd-4b93-8668-2fb4e270d8bc"}
5642025-03-17T22:41:25.683Z{"msg":"done with reconciliation","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:41:24.69473537Z","hostname":"w-01JPK3TSG4GD7HGEZJP118DX4C","pid":1252,"":"downstairs","":"downstairs","session_id":"23d314cc-bbbd-4b93-8668-2fb4e270d8bc"}
5652025-03-17T22:41:25.683Z{"msg":"Transition from Reconcile to Active","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:41:24.694777982Z","hostname":"w-01JPK3TSG4GD7HGEZJP118DX4C","pid":1252,"client":"0","":"downstairs","session_id":"23d314cc-bbbd-4b93-8668-2fb4e270d8bc"}
5662025-03-17T22:41:25.683Z{"msg":"Transition from Reconcile to Active","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:41:24.694804457Z","hostname":"w-01JPK3TSG4GD7HGEZJP118DX4C","pid":1252,"client":"1","":"downstairs","session_id":"23d314cc-bbbd-4b93-8668-2fb4e270d8bc"}
5672025-03-17T22:41:25.683Z{"msg":"Transition from Reconcile to Active","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:41:24.6948412Z","hostname":"w-01JPK3TSG4GD7HGEZJP118DX4C","pid":1252,"client":"2","":"downstairs","session_id":"23d314cc-bbbd-4b93-8668-2fb4e270d8bc"}
5682025-03-17T22:41:25.683Z{"msg":"All required reconciliation work is completed","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:41:24.694872845Z","hostname":"w-01JPK3TSG4GD7HGEZJP118DX4C","pid":1252,"session_id":"23d314cc-bbbd-4b93-8668-2fb4e270d8bc"}
5692025-03-17T22:41:25.683Z{"msg":"Set Downstairs and Upstairs active after reconciliation","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:41:24.694889182Z","hostname":"w-01JPK3TSG4GD7HGEZJP118DX4C","pid":1252,"session_id":"23d314cc-bbbd-4b93-8668-2fb4e270d8bc"}
5702025-03-17T22:41:25.683Z{"msg":"377c2fa4-f907-47c0-80b8-c36ee865be25 is now active with session: 23d314cc-bbbd-4b93-8668-2fb4e270d8bc","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:41:24.694921485Z","hostname":"w-01JPK3TSG4GD7HGEZJP118DX4C","pid":1252,"session_id":"23d314cc-bbbd-4b93-8668-2fb4e270d8bc"}
5712025-03-17T22:41:25.683Z{"msg":"The guest has finished waiting for activation with:33","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:41:24.694956139Z","hostname":"w-01JPK3TSG4GD7HGEZJP118DX4C","pid":1252}
5722025-03-17T22:41:25.683Z{"msg":"Activated sub_volume 377c2fa4-f907-47c0-80b8-c36ee865be25","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:41:24.694980085Z","hostname":"w-01JPK3TSG4GD7HGEZJP118DX4C","pid":1252}
5732025-03-17T22:41:25.683Z{"msg":"The guest has requested activation with gen:33","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:41:24.695071418Z","hostname":"w-01JPK3TSG4GD7HGEZJP118DX4C","pid":1252}
5742025-03-17T22:41:25.683Z{"msg":"377c2fa4-f907-47c0-80b8-c36ee865be25 active request set","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:41:24.695100832Z","hostname":"w-01JPK3TSG4GD7HGEZJP118DX4C","pid":1252,"session_id":"c1edb294-a874-4445-8479-711e355ed25f"}
5752025-03-17T22:41:25.683Z{"msg":"sending connect oneshot to client","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:41:24.69511582Z","hostname":"w-01JPK3TSG4GD7HGEZJP118DX4C","pid":1252,"client":"0","":"downstairs","session_id":"c1edb294-a874-4445-8479-711e355ed25f"}
5762025-03-17T22:41:25.683Z{"msg":"client set_active_request while in Connecting { state: Start { auto_promote: true }, mode: New }; waiting...","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:41:24.695139535Z","hostname":"w-01JPK3TSG4GD7HGEZJP118DX4C","pid":1252,"client":"0","":"downstairs","session_id":"c1edb294-a874-4445-8479-711e355ed25f"}
5772025-03-17T22:41:25.683Z{"msg":"sending connect oneshot to client","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:41:24.695163751Z","hostname":"w-01JPK3TSG4GD7HGEZJP118DX4C","pid":1252,"client":"1","":"downstairs","session_id":"c1edb294-a874-4445-8479-711e355ed25f"}
5782025-03-17T22:41:25.683Z{"msg":"client set_active_request while in Connecting { state: Start { auto_promote: true }, mode: New }; waiting...","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:41:24.695191745Z","hostname":"w-01JPK3TSG4GD7HGEZJP118DX4C","pid":1252,"client":"1","":"downstairs","session_id":"c1edb294-a874-4445-8479-711e355ed25f"}
5792025-03-17T22:41:25.683Z{"msg":"sending connect oneshot to client","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:41:24.69521779Z","hostname":"w-01JPK3TSG4GD7HGEZJP118DX4C","pid":1252,"client":"2","":"downstairs","session_id":"c1edb294-a874-4445-8479-711e355ed25f"}
5802025-03-17T22:41:25.683Z{"msg":"client set_active_request while in Connecting { state: Start { auto_promote: true }, mode: New }; waiting...","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:41:24.695264112Z","hostname":"w-01JPK3TSG4GD7HGEZJP118DX4C","pid":1252,"client":"2","":"downstairs","session_id":"c1edb294-a874-4445-8479-711e355ed25f"}
5812025-03-17T22:41:25.683Z{"msg":"connecting to 127.0.0.1:8860","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:41:24.695295426Z","hostname":"w-01JPK3TSG4GD7HGEZJP118DX4C","pid":1252,"":"io task","client":"2","":"downstairs","session_id":"c1edb294-a874-4445-8479-711e355ed25f"}
5822025-03-17T22:41:25.683Z{"msg":"connecting to 127.0.0.1:8840","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:41:24.69533014Z","hostname":"w-01JPK3TSG4GD7HGEZJP118DX4C","pid":1252,"":"io task","client":"0","":"downstairs","session_id":"c1edb294-a874-4445-8479-711e355ed25f"}
5832025-03-17T22:41:25.683Z{"msg":"connecting to 127.0.0.1:8850","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:41:24.695361014Z","hostname":"w-01JPK3TSG4GD7HGEZJP118DX4C","pid":1252,"":"io task","client":"1","":"downstairs","session_id":"c1edb294-a874-4445-8479-711e355ed25f"}
5842025-03-17T22:41:25.684Z{"msg":"ds_connection connected from Ok(127.0.0.1:36863)","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:41:24.695395628Z","hostname":"w-01JPK3TSG4GD7HGEZJP118DX4C","pid":1252,"":"io task","client":"0","":"downstairs","session_id":"c1edb294-a874-4445-8479-711e355ed25f"}
5852025-03-17T22:41:25.684Z{"msg":"ds_connection connected from Ok(127.0.0.1:64456)","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:41:24.695428671Z","hostname":"w-01JPK3TSG4GD7HGEZJP118DX4C","pid":1252,"":"io task","client":"2","":"downstairs","session_id":"c1edb294-a874-4445-8479-711e355ed25f"}
5862025-03-17T22:41:25.684Z{"msg":"ds_connection connected from Ok(127.0.0.1:38561)","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:41:24.695455377Z","hostname":"w-01JPK3TSG4GD7HGEZJP118DX4C","pid":1252,"":"io task","client":"1","":"downstairs","session_id":"c1edb294-a874-4445-8479-711e355ed25f"}
5872025-03-17T22:41:25.684Z{"msg":"version negotiation from state Connecting { state: WaitForPromote, mode: New }","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:41:24.69576025Z","hostname":"w-01JPK3TSG4GD7HGEZJP118DX4C","pid":1252,"client":"0","":"downstairs","session_id":"c1edb294-a874-4445-8479-711e355ed25f"}
5882025-03-17T22:41:25.684Z{"msg":"version negotiation from state Connecting { state: WaitForPromote, mode: New }","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:41:24.695821709Z","hostname":"w-01JPK3TSG4GD7HGEZJP118DX4C","pid":1252,"client":"2","":"downstairs","session_id":"c1edb294-a874-4445-8479-711e355ed25f"}
5892025-03-17T22:41:25.684Z{"msg":"version negotiation from state Connecting { state: WaitForPromote, mode: New }","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:41:24.695858562Z","hostname":"w-01JPK3TSG4GD7HGEZJP118DX4C","pid":1252,"client":"1","":"downstairs","session_id":"c1edb294-a874-4445-8479-711e355ed25f"}
5902025-03-17T22:41:25.684Z{"msg":"downstairs client at Some(127.0.0.1:8850) has region UUID 12345678-0000-0000-0000-000000008850","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:41:24.696340592Z","hostname":"w-01JPK3TSG4GD7HGEZJP118DX4C","pid":1252,"client":"1","":"downstairs","session_id":"c1edb294-a874-4445-8479-711e355ed25f"}
5912025-03-17T22:41:25.684Z{"msg":"downstairs client at Some(127.0.0.1:8840) has region UUID 12345678-0000-0000-0000-000000008840","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:41:24.696499553Z","hostname":"w-01JPK3TSG4GD7HGEZJP118DX4C","pid":1252,"client":"0","":"downstairs","session_id":"c1edb294-a874-4445-8479-711e355ed25f"}
5922025-03-17T22:41:25.684Z{"msg":"downstairs client at Some(127.0.0.1:8860) has region UUID 12345678-0000-0000-0000-000000008860","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:41:24.696522608Z","hostname":"w-01JPK3TSG4GD7HGEZJP118DX4C","pid":1252,"client":"2","":"downstairs","session_id":"c1edb294-a874-4445-8479-711e355ed25f"}
5932025-03-17T22:41:25.688Z{"msg":"Waiting for more clients to be ready","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:41:24.696739608Z","hostname":"w-01JPK3TSG4GD7HGEZJP118DX4C","pid":1252,"session_id":"c1edb294-a874-4445-8479-711e355ed25f"}
5942025-03-17T22:41:25.689Z{"msg":"Waiting for more clients to be ready","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:41:24.696903548Z","hostname":"w-01JPK3TSG4GD7HGEZJP118DX4C","pid":1252,"session_id":"c1edb294-a874-4445-8479-711e355ed25f"}
5952025-03-17T22:41:25.689Z{"msg":"[0]R flush_numbers: [5321, 5321, 5321, 5321, 5321]","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:41:24.696932313Z","hostname":"w-01JPK3TSG4GD7HGEZJP118DX4C","pid":1252,"":"downstairs","":"downstairs","session_id":"c1edb294-a874-4445-8479-711e355ed25f"}
5962025-03-17T22:41:25.689Z{"msg":"[0]R generation: [32, 32, 32, 32, 32]","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:41:24.6969479Z","hostname":"w-01JPK3TSG4GD7HGEZJP118DX4C","pid":1252,"":"downstairs","":"downstairs","session_id":"c1edb294-a874-4445-8479-711e355ed25f"}
5972025-03-17T22:41:25.689Z{"msg":"[0]R dirty: [false, false, false, false, false]","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:41:24.696961727Z","hostname":"w-01JPK3TSG4GD7HGEZJP118DX4C","pid":1252,"":"downstairs","":"downstairs","session_id":"c1edb294-a874-4445-8479-711e355ed25f"}
5982025-03-17T22:41:25.689Z{"msg":"[1]R flush_numbers: [5321, 5321, 5321, 5321, 5321]","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:41:24.696982823Z","hostname":"w-01JPK3TSG4GD7HGEZJP118DX4C","pid":1252,"":"downstairs","":"downstairs","session_id":"c1edb294-a874-4445-8479-711e355ed25f"}
5992025-03-17T22:41:25.689Z{"msg":"[1]R generation: [32, 32, 32, 32, 32]","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:41:24.697017767Z","hostname":"w-01JPK3TSG4GD7HGEZJP118DX4C","pid":1252,"":"downstairs","":"downstairs","session_id":"c1edb294-a874-4445-8479-711e355ed25f"}
6002025-03-17T22:41:25.689Z{"msg":"[1]R dirty: [false, false, false, false, false]","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:41:24.697034234Z","hostname":"w-01JPK3TSG4GD7HGEZJP118DX4C","pid":1252,"":"downstairs","":"downstairs","session_id":"c1edb294-a874-4445-8479-711e355ed25f"}
6012025-03-17T22:41:25.689Z{"msg":"[2]R flush_numbers: [5321, 5321, 5321, 5321, 5321]","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:41:24.69705485Z","hostname":"w-01JPK3TSG4GD7HGEZJP118DX4C","pid":1252,"":"downstairs","":"downstairs","session_id":"c1edb294-a874-4445-8479-711e355ed25f"}
6022025-03-17T22:41:25.689Z{"msg":"[2]R generation: [32, 32, 32, 32, 32]","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:41:24.697068627Z","hostname":"w-01JPK3TSG4GD7HGEZJP118DX4C","pid":1252,"":"downstairs","":"downstairs","session_id":"c1edb294-a874-4445-8479-711e355ed25f"}
6032025-03-17T22:41:25.689Z{"msg":"[2]R dirty: [false, false, false, false, false]","v":0,"name":"crucible","level":30Wait for a query_work_queue command to finish before sending IO
6042025-03-17T22:41:25.689Z,"time":"2025-03-17T22:41:24.697082325Z","hostname":"w-01JPK3TSG4GD7HGEZJP118DX4C","pid":1252,"":"downstairs","":"downstairs","session_id":"c1edb294-a874-4445-8479-711e355ed25f"}
6052025-03-17T22:41:25.689Z{"msg":"Max found gen is 33","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:41:24.69710928Z","hostname":"w-01JPK3TSG4GD7HGEZJP118DX4C","pid":1252,"":"downstairs","":"downstairs","session_id":"c1edb294-a874-4445-8479-711e355ed25f"}
6062025-03-17T22:41:25.689Z{"msg":"Generation requested: 33 >= found:33","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:41:24.697123047Z","hostname":"w-01JPK3TSG4GD7HGEZJP118DX4C","pid":1252,"":"downstairs","":"downstairs","session_id":"c1edb294-a874-4445-8479-711e355ed25f"}
6072025-03-17T22:41:25.689Z{"msg":"Next flush: 5322","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:41:24.697143193Z","hostname":"w-01JPK3TSG4GD7HGEZJP118DX4C","pid":1252,"":"downstairs","":"downstairs","session_id":"c1edb294-a874-4445-8479-711e355ed25f"}
6082025-03-17T22:41:25.689Z{"msg":"All extents match","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:41:24.697156251Z","hostname":"w-01JPK3TSG4GD7HGEZJP118DX4C","pid":1252,"":"downstairs","":"downstairs","session_id":"c1edb294-a874-4445-8479-711e355ed25f"}
6092025-03-17T22:41:25.689Z{"msg":"No downstairs reconciliation required","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:41:24.697169359Z","hostname":"w-01JPK3TSG4GD7HGEZJP118DX4C","pid":1252,"session_id":"c1edb294-a874-4445-8479-711e355ed25f"}
6102025-03-17T22:41:25.689Z{"msg":"Transition from WaitQuorum to Active","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:41:24.697187925Z","hostname":"w-01JPK3TSG4GD7HGEZJP118DX4C","pid":1252,"client":"0","":"downstairs","session_id":"c1edb294-a874-4445-8479-711e355ed25f"}
6112025-03-17T22:41:25.689Z{"msg":"Transition from WaitQuorum to Active","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:41:24.697201223Z","hostname":"w-01JPK3TSG4GD7HGEZJP118DX4C","pid":1252,"client":"1","":"downstairs","session_id":"c1edb294-a874-4445-8479-711e355ed25f"}
6122025-03-17T22:41:25.689Z{"msg":"Transition from WaitQuorum to Active","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:41:24.697220689Z","hostname":"w-01JPK3TSG4GD7HGEZJP118DX4C","pid":1252,"client":"2","":"downstairs","session_id":"c1edb294-a874-4445-8479-711e355ed25f"}
6132025-03-17T22:41:25.689Z{"msg":"All required reconciliation work is completed","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:41:24.697233717Z","hostname":"w-01JPK3TSG4GD7HGEZJP118DX4C","pid":1252,"session_id":"c1edb294-a874-4445-8479-711e355ed25f"}
6142025-03-17T22:41:25.689Z{"msg":"Set Downstairs and Upstairs active after reconciliation","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:41:24.697246434Z","hostname":"w-01JPK3TSG4GD7HGEZJP118DX4C","pid":1252,"session_id":"c1edb294-a874-4445-8479-711e355ed25f"}
6152025-03-17T22:41:25.689Z{"msg":"377c2fa4-f907-47c0-80b8-c36ee865be25 is now active with session: c1edb294-a874-4445-8479-711e355ed25f","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:41:24.697265871Z","hostname":"w-01JPK3TSG4GD7HGEZJP118DX4C","pid":1252,"session_id":"c1edb294-a874-4445-8479-711e355ed25f"}
6162025-03-17T22:41:25.689Z{"msg":"Set Active after no reconciliation","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:41:24.697277848Z","hostname":"w-01JPK3TSG4GD7HGEZJP118DX4C","pid":1252,"session_id":"c1edb294-a874-4445-8479-711e355ed25f"}
6172025-03-17T22:41:25.689Z{"msg":"The guest has finished waiting for activation with:33","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:41:24.697289546Z","hostname":"w-01JPK3TSG4GD7HGEZJP118DX4C","pid":1252}
6182025-03-17T22:41:25.689Z{"msg":"Activated sub_volume 377c2fa4-f907-47c0-80b8-c36ee865be25","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:41:24.697301224Z","hostname":"w-01JPK3TSG4GD7HGEZJP118DX4C","pid":1252}
6192025-03-17T22:41:25.689ZDisk: sv:2 bs:4096 ts:409600 tb:100 max_io:100 or 409600
6202025-03-17T22:41:25.689ZLoading write count information from file "/var/tmp/test_up-build/verify_file"
6212025-03-17T22:41:25.689ZRead and Verify all blocks (0..100 range:true)
6222025-03-17T22:41:25.772ZWrote out file "/var/tmp/test_up-build/verify_file"
6232025-03-17T22:41:25.772ZVerify test completed
6242025-03-17T22:41:25.776ZWrote out file "/var/tmp/test_up-build/verify_file"
6252025-03-17T22:41:25.776ZCLIENT: Tests done. All submitted work has been ACK'd
6262025-03-17T22:41:25.776Z----------------------------------------------------------------
6272025-03-17T22:41:25.776Z Crucible gen:33 GIO:true work queues: Upstairs:0 downstairs:1
6282025-03-17T22:41:25.776ZStates: Active Active Active
6292025-03-17T22:41:25.776ZJOBID ACK TYPE BKS/EXT DS:0 DS:1 DS:2 REPLAY
6302025-03-17T22:41:25.776Z 1000 Acked Read 50 Done Done Done false
6312025-03-17T22:41:25.776Z STATES DS:0 DS:1 DS:2 TOTAL
6322025-03-17T22:41:25.776Z Sent 0 0 0 0
6332025-03-17T22:41:25.776Z Done 1 1 1 3
6342025-03-17T22:41:25.776Z Skipped 0 0 0 0
6352025-03-17T22:41:25.776Z Error 0 0 0 0
6362025-03-17T22:41:25.776ZLast Flush: None None None
6372025-03-17T22:41:25.776ZDownstairs last five completed:
6382025-03-17T22:41:25.776ZUpstairs last five completed: 1000
6392025-03-17T22:41:25.776Z----------------------------------------------------------------
6402025-03-17T22:41:25.776Z Crucible gen:33 GIO:true work queues: Upstairs:0 downstairs:1
6412025-03-17T22:41:25.776ZStates: Active Active Active
6422025-03-17T22:41:25.776ZJOBID ACK TYPE BKS/EXT DS:0 DS:1 DS:2 REPLAY
6432025-03-17T22:41:25.776Z 1000 Acked Read 50 Done Done Done false
6442025-03-17T22:41:25.776Z STATES DS:0 DS:1 DS:2 TOTAL
6452025-03-17T22:41:25.776Z Sent 0 0 0 0
6462025-03-17T22:41:25.776Z Done 1 1 1 3
6472025-03-17T22:41:25.776Z Skipped 0 0 0 0
6482025-03-17T22:41:25.776Z Error 0 0 0 0
6492025-03-17T22:41:25.776ZLast Flush: None None None
6502025-03-17T22:41:25.776ZDownstairs last five completed:
6512025-03-17T22:41:25.776ZUpstairs last five completed: 1000
6522025-03-17T22:41:25.776ZCLIENT: Up:0 ds:2 act:6
6532025-03-17T22:41:29.774Z----------------------------------------------------------------
6542025-03-17T22:41:29.774Z Crucible gen:33 GIO:true work queues: Upstairs:0 downstairs:0
6552025-03-17T22:41:29.774ZDownstairs last five completed: 1001 1000
6562025-03-17T22:41:29.774ZUpstairs last five completed: 1001 1000
6572025-03-17T22:41:29.777Z----------------------------------------------------------------
6582025-03-17T22:41:29.777Z Crucible gen:33 GIO:true work queues: Upstairs:0 downstairs:0
6592025-03-17T22:41:29.777ZDownstairs last five completed: 1001 1000
6602025-03-17T22:41:29.777ZUpstairs last five completed: 1001 1000
6612025-03-17T22:41:29.777ZCLIENT: Up:0 ds:0 act:6
6622025-03-17T22:41:29.777ZCLIENT: All crucible jobs finished, exiting program
6632025-03-17T22:41:29.782ZRepair part 2 passed
6642025-03-17T22:41:29.785Z/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
6652025-03-17T22:41:29.800ZEXT BLOCKS GEN0 GEN1 GEN2 FL0 FL1 FL2 D0 D1 D2 DIFF
6662025-03-17T22:41:29.800Z 0 000-009 32 32 32 4002 4002 4002 F F F
6672025-03-17T22:41:29.800Z 1 010-019 32 32 32 4002 4002 4002 F F F
6682025-03-17T22:41:29.800Z 2 020-029 32 32 32 4002 4002 4002 F F F
6692025-03-17T22:41:29.800Z 3 030-039 32 32 32 4002 4002 4002 F F F
6702025-03-17T22:41:29.800Z 4 040-049 32 32 32 4002 4002 4002 F F F
6712025-03-17T22:41:29.806ZMax gen: 32, Max flush: 4002
6722025-03-17T22:41:29.809Zdump test passed
6732025-03-17T22:41:29.809Z/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
6742025-03-17T22:41:29.822Z Extent 1
6752025-03-17T22:41:29.825ZGEN 32 32 32
6762025-03-17T22:41:29.825ZFLUSH_ID 4002 4002 4002
6772025-03-17T22:41:29.825ZDIRTY
6782025-03-17T22:41:29.825Z
6792025-03-17T22:41:29.825ZBLOCK D0 D1 D2 C0 C1 C2 DIFF
6802025-03-17T22:41:29.825Z010 A A A A A A
6812025-03-17T22:41:29.828Z011 A A A A A A
6822025-03-17T22:41:29.828Z012 A A A A A A
6832025-03-17T22:41:29.828Z013 A A A A A A
6842025-03-17T22:41:29.831Z014 A A A A A A
6852025-03-17T22:41:29.831Z015 A A A A A A
6862025-03-17T22:41:29.834Z016 A A A A A A
6872025-03-17T22:41:29.834Z017 A A A A A A
6882025-03-17T22:41:29.837Z018 A A A A A A
6892025-03-17T22:41:29.837Z019 A A A A A A
6902025-03-17T22:41:29.840Zdump extent test passed
6912025-03-17T22:41:29.840Z/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
6922025-03-17T22:41:29.856ZExtent 2 Block in extent 0 Actual block 20
6932025-03-17T22:41:29.856Z
6942025-03-17T22:41:29.860Z DATA SHA256 VER
6952025-03-17T22:41:29.860Z------ ---------------------------------------------------------------- ---
6962025-03-17T22:41:29.860Z 0 ea06b2a7e37c8b10b07c5fd89d31b2fb8bf9c9e32d4f52e6586e88d495c6b437 A
6972025-03-17T22:41:29.860Z 1 ea06b2a7e37c8b10b07c5fd89d31b2fb8bf9c9e32d4f52e6586e88d495c6b437 A
6982025-03-17T22:41:29.860Z 2 ea06b2a7e37c8b10b07c5fd89d31b2fb8bf9c9e32d4f52e6586e88d495c6b437 A
6992025-03-17T22:41:29.860Z
7002025-03-17T22:41:29.860ZNONCES 0 1 2 DIFF
7012025-03-17T22:41:29.860Z------ ------------------------ ------------------------ ------------------------ -----
7022025-03-17T22:41:29.860Z 0 f5fc9a2a84a764494ccb1f46 f5fc9a2a84a764494ccb1f46 f5fc9a2a84a764494ccb1f46
7032025-03-17T22:41:29.860Z
7042025-03-17T22:41:29.860Z TAGS 0 1 2 DIFF
7052025-03-17T22:41:29.860Z------ -------------------------------- -------------------------------- -------------------------------- -----
7062025-03-17T22:41:29.860Z 0 6eaba36dd1b2327c162a32a7885cf73f 6eaba36dd1b2327c162a32a7885cf73f 6eaba36dd1b2327c162a32a7885cf73f
7072025-03-17T22:41:29.860Z
7082025-03-17T22:41:29.860ZHASHES 0 1 2 DIFF
7092025-03-17T22:41:29.860Z------ ---------------- ---------------- ---------------- -----
7102025-03-17T22:41:29.860Z
7112025-03-17T22:41:29.863Zdump block test passed
7122025-03-17T22:41:29.863ZInitial upstairs tests have completed, stopping all downstairs
7132025-03-17T22:41:34.931ZCreating 7 larger downstairs regions
7142025-03-17T22:41:35.123ZStarting 7 downstairs
7152025-03-17T22:41:40.132Zdsc restarted at PID: 1268
7162025-03-17T22:41:40.525ZNow do the replace-reconcile test
7172025-03-17T22:41:40.582ZUsing 8870 for the replacement port
7182025-03-17T22:44:43.484ZCompleted test: replace-reconcile
7192025-03-17T22:44:43.487ZNow do the replace-before-active test
7202025-03-17T22:48:16.908ZCompleted test: replace-before-active
7212025-03-17T22:48:16.908ZAll tests have completed, stopping all downstairs
7222025-03-17T22:48:16.968Z
7232025-03-17T22:48:16.968ZAll Tests have passed
7242025-03-17T22:48:16.972Z13:49 Test duration
7252025-03-17T22:48:16.972Z
7262025-03-17T22:48:16.972Zreal 13:49.242899706
7272025-03-17T22:48:16.972Zuser 18:32.277856328
7282025-03-17T22:48:16.972Zsys 25.244132740
7292025-03-17T22:48:16.972Ztrap 0.538959531
7302025-03-17T22:48:16.972Ztflt 0.040254168
7312025-03-17T22:48:16.972Zdflt 0.039122228
7322025-03-17T22:48:16.973Zkflt 0.001266928
7332025-03-17T22:48:16.973Zlock 25:49:21.969787467
7342025-03-17T22:48:16.973Zslp 1:15:21.088829906
7352025-03-17T22:48:16.973Zlat 2:00.260025726
7362025-03-17T22:48:16.973Zstop 0.218102162
7372025-03-17T22:48:16.973Z+ echo 'test-up-2region-encrypted ends'
7382025-03-17T22:48:16.973Ztest-up-2region-encrypted ends
7392025-03-17T22:48:21.974Zprocess exited: duration 837697 ms, exit code 0
7402025-03-17T22:48:21.975Zexec warning: : stdio descriptors remain open after task exit; waiting 60 seconds for them to close
7412025-03-17T22:49:22.021Zexec warning: : stdout descriptor may be held open by a background process; giving up!
7422025-03-17T22:49:22.021Zexec warning: : stderr descriptor may be held open by a background process; giving up!
 
7432025-03-17T22:49:22.034Zfound 17 output files
7442025-03-17T22:49:22.034Zuploading: /tmp/test_up-build/dsc-out.txt (52172 bytes)
7452025-03-17T22:49:23.050Zuploaded: /tmp/test_up-build/dsc-out.txt
7462025-03-17T22:49:23.057Zuploading: /tmp/test_up-build/test_up_out.txt (8664423 bytes)
7472025-03-17T22:49:24.196Zuploaded: /tmp/test_up-build/test_up_out.txt
7482025-03-17T22:49:24.199Zuploading: /tmp/test_up-build/dsc/downstairs-8810.txt (147277 bytes)
7492025-03-17T22:49:25.218Zuploaded: /tmp/test_up-build/dsc/downstairs-8810.txt
7502025-03-17T22:49:25.218Zuploading: /tmp/test_up-build/dsc/downstairs-8820.txt (144659 bytes)
7512025-03-17T22:49:26.240Zuploaded: /tmp/test_up-build/dsc/downstairs-8820.txt
7522025-03-17T22:49:26.243Zuploading: /tmp/test_up-build/dsc/downstairs-8830.txt (251002 bytes)
7532025-03-17T22:49:27.269Zuploaded: /tmp/test_up-build/dsc/downstairs-8830.txt
7542025-03-17T22:49:27.275Zuploading: /tmp/test_up-build/dsc/downstairs-8840.txt (139428 bytes)
7552025-03-17T22:49:28.291Zuploaded: /tmp/test_up-build/dsc/downstairs-8840.txt
7562025-03-17T22:49:28.291Zuploading: /tmp/test_up-build/dsc/downstairs-8850.txt (2503 bytes)
7572025-03-17T22:49:29.301Zuploaded: /tmp/test_up-build/dsc/downstairs-8850.txt
7582025-03-17T22:49:29.305Zuploading: /tmp/test_up-build/dsc/downstairs-8860.txt (33799 bytes)
7592025-03-17T22:49:30.315Zuploaded: /tmp/test_up-build/dsc/downstairs-8860.txt
7602025-03-17T22:49:30.315Zuploading: /tmp/test_up-build/dsc/downstairs-8870.txt (738354 bytes)
7612025-03-17T22:49:31.359Zuploaded: /tmp/test_up-build/dsc/downstairs-8870.txt
7622025-03-17T22:49:31.359Zuploading: /tmp/debug/df.txt (1270 bytes)
7632025-03-17T22:49:32.373Zuploaded: /tmp/debug/df.txt
7642025-03-17T22:49:32.376Zuploading: /tmp/debug/dtrace.txt (939743 bytes)
7652025-03-17T22:49:32.419Zupload warning: file "/tmp/debug/dtrace.txt" changed size mid upload: 939743 -> 1060358
7662025-03-17T22:49:33.428Zuploaded: /tmp/debug/dtrace.txt
7672025-03-17T22:49:33.431Zuploading: /tmp/debug/iostat.txt (266774 bytes)
7682025-03-17T22:49:33.450Zupload warning: file "/tmp/debug/iostat.txt" changed size mid upload: 266774 -> 270052
7692025-03-17T22:49:34.457Zuploaded: /tmp/debug/iostat.txt
7702025-03-17T22:49:34.460Zuploading: /tmp/debug/mpstat.txt (650678 bytes)
7712025-03-17T22:49:34.493Zupload warning: file "/tmp/debug/mpstat.txt" changed size mid upload: 650678 -> 659402
7722025-03-17T22:49:35.500Zuploaded: /tmp/debug/mpstat.txt
7732025-03-17T22:49:35.504Zuploading: /tmp/debug/paging.txt (115355 bytes)
7742025-03-17T22:49:35.516Zupload warning: file "/tmp/debug/paging.txt" changed size mid upload: 115355 -> 116982
7752025-03-17T22:49:36.525Zuploaded: /tmp/debug/paging.txt
7762025-03-17T22:49:36.525Zuploading: /tmp/debug/prstat.txt (1267626 bytes)
7772025-03-17T22:49:36.578Zupload warning: file "/tmp/debug/prstat.txt" changed size mid upload: 1267626 -> 1287011
7782025-03-17T22:49:37.587Zuploaded: /tmp/debug/prstat.txt
7792025-03-17T22:49:38.594Zuploading: /tmp/debug/psrinfo.txt (1528 bytes)
7802025-03-17T22:49:38.597Zuploaded: /tmp/debug/psrinfo.txt
7812025-03-17T22:49:38.601Zuploading: /tmp/debug/upstairs-info.txt (185245 bytes)
7822025-03-17T22:49:39.614Zuploaded: /tmp/debug/upstairs-info.txt