01JJR682SYAGQXBN87VWJ5H093: 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: 01JJR68N23HEP1TCMKESR8GG94

Tags:

Artefacts:

Output:

SEQ GLOBAL TIME DETAILS
12025-01-29T05:02:48.294Zjob dependencies complete; ready to run (waiting for 13 m 35 s)
22025-01-29T05:11:46.520Zjob assigned to worker 01JJR7GCCH0R2F5T18F3DFC8YY [factory aws, i-01d1e1af2b78c4516] (queued for 8 m 58 s)
32025-01-29T05:11:54.052Zdownloading input: /input/build/work/bins/crucible-downstairs.gz
42025-01-29T05:11:55.324Zdownloaded input: /input/build/work/bins/crucible-downstairs.gz
52025-01-29T05:11:55.324Zdownloading input: /input/build/work/bins/crucible-hammer.gz
62025-01-29T05:11:56.372Zdownloaded input: /input/build/work/bins/crucible-hammer.gz
72025-01-29T05:11:56.372Zdownloading input: /input/build/work/bins/crutest.gz
82025-01-29T05:11:57.473Zdownloaded input: /input/build/work/bins/crutest.gz
92025-01-29T05:11:57.473Zdownloading input: /input/build/work/bins/dsc.gz
102025-01-29T05:11:58.692Zdownloaded input: /input/build/work/bins/dsc.gz
112025-01-29T05:11:58.694Zdownloading input: /input/build/work/scripts/perf-downstairs-tick.d
122025-01-29T05:11:58.725Zdownloaded input: /input/build/work/scripts/perf-downstairs-tick.d
132025-01-29T05:11:58.725Zdownloading input: /input/build/work/scripts/test_ds.sh
142025-01-29T05:11:58.752Zdownloaded input: /input/build/work/scripts/test_ds.sh
152025-01-29T05:11:58.752Zdownloading input: /input/build/work/scripts/test_live_repair.sh
162025-01-29T05:11:58.777Zdownloaded input: /input/build/work/scripts/test_live_repair.sh
172025-01-29T05:11:58.777Zdownloading input: /input/build/work/scripts/test_repair.sh
182025-01-29T05:11:58.797Zdownloaded input: /input/build/work/scripts/test_repair.sh
192025-01-29T05:11:58.797Zdownloading input: /input/build/work/scripts/test_replay.sh
202025-01-29T05:11:58.818Zdownloaded input: /input/build/work/scripts/test_replay.sh
212025-01-29T05:11:58.818Zdownloading input: /input/build/work/scripts/test_up.sh
222025-01-29T05:11:58.852Zdownloaded input: /input/build/work/scripts/test_up.sh
232025-01-29T05:11:58.852Zdownloading input: /input/build/work/scripts/upstairs_info.d
242025-01-29T05:11:58.869Zdownloaded input: /input/build/work/scripts/upstairs_info.d
252025-01-29T05:11:58.872Zdownloading input: /input/build/tmp/cargo-test-out.log
262025-01-29T05:11:59.631Zdownloaded input: /input/build/tmp/cargo-test-out.log
 
272025-01-29T05:11:59.631Zstarting task 0: "setup"
282025-01-29T05:11:59.645Z++ uname -s
292025-01-29T05:11:59.647Z+ kern=SunOS
302025-01-29T05:11:59.648Z+ case "$kern" in
312025-01-29T05:11:59.648Z+ groupadd -g 12345 build
322025-01-29T05:11:59.650Z+ useradd -u 12345 -g build -d /home/build -s /bin/bash -c build -P 'Primary Administrator' build
332025-01-29T05:12:01.658Z+ zfs create -o mountpoint=/work rpool/work
342025-01-29T05:12:01.818Z++ awk '$2 == "/home" { print $3 }' /etc/mnttab
352025-01-29T05:12:01.821Z+ home_fs=zfs
362025-01-29T05:12:01.821Z+ [[ zfs == autofs ]]
372025-01-29T05:12:01.821Z+ mkdir -p /home/build
382025-01-29T05:12:01.824Z+ chown build:build /home/build /work
392025-01-29T05:12:03.826Z+ chmod 0700 /home/build /work
402025-01-29T05:12:03.830Zprocess exited: duration 4196 ms, exit code 0
 
412025-01-29T05:12:03.835Zstarting task 1: "authentication"
422025-01-29T05:12:03.852Zprocess exited: duration 16 ms, exit code 0
 
432025-01-29T05:12:03.858Zstarting task 2: "build"
442025-01-29T05:12:03.863Z+ banner cores
452025-01-29T05:12:03.867Z
462025-01-29T05:12:03.867Z #### #### ##### ###### ####
472025-01-29T05:12:03.867Z # # # # # # # #
482025-01-29T05:12:03.867Z # # # # # ##### ####
492025-01-29T05:12:03.867Z # # # ##### # #
502025-01-29T05:12:03.867Z # # # # # # # # #
512025-01-29T05:12:03.867Z #### #### # # ###### ####
522025-01-29T05:12:03.867Z
532025-01-29T05:12:03.870Z+ pfexec coreadm -i /tmp/core.%f.%p -g /tmp/core.%f.%p -e global -e log -e proc-setid -e global-setid
542025-01-29T05:12:03.876Z+ banner unpack
552025-01-29T05:12:03.879Z
562025-01-29T05:12:03.879Z # # # # ##### ## #### # #
572025-01-29T05:12:03.879Z # # ## # # # # # # # # #
582025-01-29T05:12:03.879Z # # # # # # # # # # ####
592025-01-29T05:12:03.879Z # # # # # ##### ###### # # #
602025-01-29T05:12:03.879Z # # # ## # # # # # # #
612025-01-29T05:12:03.879Z #### # # # # # #### # #
622025-01-29T05:12:03.879Z
632025-01-29T05:12:03.880Z+ mkdir -p /var/tmp/bins
642025-01-29T05:12:03.883Z+ for t in "$input/bins/"*.gz
652025-01-29T05:12:03.883Z++ basename /input/build/work/bins/crucible-downstairs.gz
662025-01-29T05:12:03.883Z+ b=crucible-downstairs.gz
672025-01-29T05:12:03.883Z+ b=crucible-downstairs
682025-01-29T05:12:03.883Z+ gunzip
692025-01-29T05:12:06.164Z+ chmod +x /var/tmp/bins/crucible-downstairs
702025-01-29T05:12:06.166Z+ for t in "$input/bins/"*.gz
712025-01-29T05:12:06.169Z++ basename /input/build/work/bins/crucible-hammer.gz
722025-01-29T05:12:06.169Z+ b=crucible-hammer.gz
732025-01-29T05:12:06.169Z+ b=crucible-hammer
742025-01-29T05:12:06.169Z+ gunzip
752025-01-29T05:12:08.307Z+ chmod +x /var/tmp/bins/crucible-hammer
762025-01-29T05:12:08.310Z+ for t in "$input/bins/"*.gz
772025-01-29T05:12:08.312Z++ basename /input/build/work/bins/crutest.gz
782025-01-29T05:12:08.312Z+ b=crutest.gz
792025-01-29T05:12:08.313Z+ b=crutest
802025-01-29T05:12:08.313Z+ gunzip
812025-01-29T05:12:10.610Z+ chmod +x /var/tmp/bins/crutest
822025-01-29T05:12:10.613Z+ for t in "$input/bins/"*.gz
832025-01-29T05:12:10.619Z++ basename /input/build/work/bins/dsc.gz
842025-01-29T05:12:10.619Z+ b=dsc.gz
852025-01-29T05:12:10.619Z+ b=dsc
862025-01-29T05:12:10.619Z+ gunzip
872025-01-29T05:12:11.990Z+ chmod +x /var/tmp/bins/dsc
882025-01-29T05:12:11.992Z+ export BINDIR=/var/tmp/bins
892025-01-29T05:12:11.992Z+ BINDIR=/var/tmp/bins
902025-01-29T05:12:11.992Z+ jobpid=1141
912025-01-29T05:12:11.995Z+ echo 'Setup debug logging'
922025-01-29T05:12:11.995ZSetup debug logging
932025-01-29T05:12:11.995Z+ mkdir /tmp/debug
942025-01-29T05:12:11.995Z+ sleep 3600
952025-01-29T05:12:11.995Z+ psrinfo -v
962025-01-29T05:12:11.999Z+ df -h
972025-01-29T05:12:12.007Z+ prstat -d d -mLc 1
982025-01-29T05:12:12.009Z+ iostat -T d -xn 1
992025-01-29T05:12:12.009Z+ mpstat -T d 1
1002025-01-29T05:12:12.009Z+ vmstat -T d -p 1
1012025-01-29T05:12:12.012Z+ pfexec dtrace -Z -s /input/build/work/scripts/perf-downstairs-tick.d
1022025-01-29T05:12:12.012Z+ banner test_up_2r_encrypted
1032025-01-29T05:12:12.012Z+ pfexec dtrace -Z -s /input/build/work/scripts/upstairs_info.d
1042025-01-29T05:12:12.014Z #####
1052025-01-29T05:12:12.014Z ##### ###### #### ##### # # ##### # # #####
1062025-01-29T05:12:12.016Z # # # # # # # # # # #
1072025-01-29T05:12:12.016Z # ##### #### # # # # # ##### # #
1082025-01-29T05:12:12.016Z # # # # # # ##### # #####
1092025-01-29T05:12:12.016Z # # # # # # # # # # #
1102025-01-29T05:12:12.016Z # ###### #### # ####### #### # ####### ####### # #
1112025-01-29T05:12:12.016Z
1122025-01-29T05:12:12.016Z+ ptime -m bash /input/build/work/scripts/test_up.sh -r 2 -N encrypted
1132025-01-29T05:12:12.025Z/input/build/work
1142025-01-29T05:12:12.038ZUsing 2 region sets
1152025-01-29T05:12:12.038ZTurn off color for downstairs dump
1162025-01-29T05:12:12.055ZUpstairs using key: SHgaJxxqdc0f4qfR8nhZsqCvTH7mH/l3BWZZM52dUQk=
1172025-01-29T05:12:12.059Zdsc output goes to /tmp/test_up-build/dsc-out.txt
1182025-01-29T05:12:12.059ZCreating 6 downstairs regions
1192025-01-29T05:12:12.437ZStarting 6 downstairs
1202025-01-29T05:12:12.440Zdsc started at PID: 1189
1212025-01-29T05:12:17.794ZDisable automatic restart on all downstairs
1222025-01-29T05:12:17.850Z
1232025-01-29T05:12:17.850ZBegin tests, output goes to /tmp/test_up-build/test_up_out.txt
1242025-01-29T05:12:17.854ZRunning test: span
1252025-01-29T05:12:22.036ZCompleted test: span
1262025-01-29T05:12:27.044ZRunning test: big
1272025-01-29T05:12:31.627ZCompleted test: big
1282025-01-29T05:12:36.634ZRunning test: dep
1292025-01-29T05:13:10.216ZCompleted test: dep
1302025-01-29T05:13:15.222ZRunning test: balloon
1312025-01-29T05:17:29.811ZCompleted test: balloon
1322025-01-29T05:17:34.819ZRunning test: deactivate
1332025-01-29T05:18:29.549ZCompleted test: deactivate
1342025-01-29T05:18:34.557ZRunning hammer
1352025-01-29T05:18:47.339ZRun repair tests
1362025-01-29T05:18:47.342Z/var/tmp/bins/crutest fill -g 31 -q --key SHgaJxxqdc0f4qfR8nhZsqCvTH7mH/l3BWZZM52dUQk= --dsc 127.0.0.1:9998 --verify-out /var/tmp/test_up-build/verify_file
1372025-01-29T05:18:47.401Z{"msg":"Use this region info from dsc: RegionExtentInfo { block_size: 4096, blocks_per_extent: 10, extent_count: 5 }","v":0,"name":"crucible","level":30,"time":"2025-01-29T05:18:46.241638351Z","hostname":"w-01JJR7GCCH0R2F5T18F3DFC8YY","pid":1232,"task":"crutest"}
1382025-01-29T05:18:47.404Z{"msg":"dsc has 6 regions. This means 2 sub_volumes","v":0,"name":"crucible","level":30,"time":"2025-01-29T05:18:46.242181952Z","hostname":"w-01JJR7GCCH0R2F5T18F3DFC8YY","pid":1232,"task":"crutest"}
1392025-01-29T05:18:47.404Z{"msg":"SV 0 has targets: [127.0.0.1:8810, 127.0.0.1:8820, 127.0.0.1:8830]","v":0,"name":"crucible","level":30,"time":"2025-01-29T05:18:46.243942393Z","hostname":"w-01JJR7GCCH0R2F5T18F3DFC8YY","pid":1232,"task":"crutest"}
1402025-01-29T05:18:47.404Z{"msg":"Upstairs starts","v":0,"name":"crucible","level":30,"time":"2025-01-29T05:18:46.244171698Z","hostname":"w-01JJR7GCCH0R2F5T18F3DFC8YY","pid":1232}
1412025-01-29T05:18:47.404Z{"msg":"Crucible Version: BuildInfo {\n version: \"0.0.1\",\n git_sha: \"442be2395eb3bf8ebe11d34acf0678a1aae4fa71\",\n git_commit_timestamp: \"2025-01-29T04:48:13.000000000Z\",\n git_branch: \"main\",\n rustc_semver: \"1.84.0\",\n rustc_channel: \"stable\",\n rustc_host_triple: \"x86_64-unknown-illumos\",\n rustc_commit_sha: \"9fc6b43126469e3858e2fe86cafb4f0fd5068869\",\n cargo_triple: \"x86_64-unknown-illumos\",\n debug: true,\n opt_level: 0,\n}","v":0,"name":"crucible","level":30,"time":"2025-01-29T05:18:46.244253899Z","hostname":"w-01JJR7GCCH0R2F5T18F3DFC8YY","pid":1232}
1422025-01-29T05:18:47.404Z{"msg":"Upstairs <-> Downstairs Message Version: 13","v":0,"name":"crucible","level":30,"time":"2025-01-29T05:18:46.244291655Z","hostname":"w-01JJR7GCCH0R2F5T18F3DFC8YY","pid":1232}
1432025-01-29T05:18:47.404Z{"msg":"Using region definition RegionDefinition { block_size: 4096, extent_size: Block { value: 10, shift: 12 }, extent_count: 5, uuid: 00000000-0000-0000-0000-000000000000, encrypted: true, database_read_version: 1, database_write_version: 1 }","v":0,"name":"crucible","level":30,"time":"2025-01-29T05:18:46.244308923Z","hostname":"w-01JJR7GCCH0R2F5T18F3DFC8YY","pid":1232}
1442025-01-29T05:18:47.407Z{"msg":"Crucible f5a6c5f3-3430-4abb-9bf5-a6dd223db52c has session id: b219cd2e-5dca-4e5d-9d33-ff886eafc6ff","v":0,"name":"crucible","level":30,"time":"2025-01-29T05:18:46.24498305Z","hostname":"w-01JJR7GCCH0R2F5T18F3DFC8YY","pid":1232,"session_id":"b219cd2e-5dca-4e5d-9d33-ff886eafc6ff"}
1452025-01-29T05:18:47.407Z{"msg":"Upstairs opts: Upstairs UUID: f5a6c5f3-3430-4abb-9bf5-a6dd223db52c, Targets: [127.0.0.1:8810, 127.0.0.1:8820, 127.0.0.1:8830], lossy: false, flush_timeout: None, key populated: true, cert_pem populated: false, key_pem populated: false, root_cert_pem populated: false, Control: None, read_only: false","v":0,"name":"crucible","level":30,"time":"2025-01-29T05:18:46.245062232Z","hostname":"w-01JJR7GCCH0R2F5T18F3DFC8YY","pid":1232,"session_id":"b219cd2e-5dca-4e5d-9d33-ff886eafc6ff"}
1462025-01-29T05:18:47.407Z{"msg":"Crucible stats registered with UUID: f5a6c5f3-3430-4abb-9bf5-a6dd223db52c","v":0,"name":"crucible","level":30,"time":"2025-01-29T05:18:46.245107707Z","hostname":"w-01JJR7GCCH0R2F5T18F3DFC8YY","pid":1232,"session_id":"b219cd2e-5dca-4e5d-9d33-ff886eafc6ff"}
1472025-01-29T05:18:47.407Z{"msg":"could not find Downstairs address for Nexus","v":0,"name":"crucible","level":40,"time":"2025-01-29T05:18:46.245130474Z","hostname":"w-01JJR7GCCH0R2F5T18F3DFC8YY","pid":1232,"session_id":"b219cd2e-5dca-4e5d-9d33-ff886eafc6ff"}
1482025-01-29T05:18:47.407Z{"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-01-29T05:18:46.247084244Z","hostname":"w-01JJR7GCCH0R2F5T18F3DFC8YY","pid":1232,"task":"crutest"}
1492025-01-29T05:18:47.407Z{"msg":"Upstairs starts","v":0,"name":"crucible","level":30,"time":"2025-01-29T05:18:46.247174014Z","hostname":"w-01JJR7GCCH0R2F5T18F3DFC8YY","pid":1232}
1502025-01-29T05:18:47.407Z{"msg":"Crucible Version: BuildInfo {\n version: \"0.0.1\",\n git_sha: \"442be2395eb3bf8ebe11d34acf0678a1aae4fa71\",\n git_commit_timestamp: \"2025-01-29T04:48:13.000000000Z\",\n git_branch: \"main\",\n rustc_semver: \"1.84.0\",\n rustc_channel: \"stable\",\n rustc_host_triple: \"x86_64-unknown-illumos\",\n rustc_commit_sha: \"9fc6b43126469e3858e2fe86cafb4f0fd5068869\",\n cargo_triple: \"x86_64-unknown-illumos\",\n debug: true,\n opt_level: 0,\n}","v":0,"name":"crucible","level":30,"time":"2025-01-29T05:18:46.24721093Z","hostname":"w-01JJR7GCCH0R2F5T18F3DFC8YY","pid":1232}
1512025-01-29T05:18:47.407Z{"msg":"Upstairs <-> Downstairs Message Version: 13","v":0,"name":"crucible","level":30,"time":"2025-01-29T05:18:46.247237838Z","hostname":"w-01JJR7GCCH0R2F5T18F3DFC8YY","pid":1232}
1522025-01-29T05:18:47.407Z{"msg":"Using region definition RegionDefinition { block_size: 4096, extent_size: Block { value: 10, shift: 12 }, extent_count: 5, uuid: 00000000-0000-0000-0000-000000000000, encrypted: true, database_read_version: 1, database_write_version: 1 }","v":0,"name":"crucible","level":30,"time":"2025-01-29T05:18:46.247256685Z","hostname":"w-01JJR7GCCH0R2F5T18F3DFC8YY","pid":1232}
1532025-01-29T05:18:47.410Z{"msg":"Crucible f5a6c5f3-3430-4abb-9bf5-a6dd223db52c has session id: 70bff5fd-33a7-43a8-8a29-6b4356f07098","v":0,"name":"crucible","level":30,"time":"2025-01-29T05:18:46.247596029Z","hostname":"w-01JJR7GCCH0R2F5T18F3DFC8YY","pid":1232,"session_id":"70bff5fd-33a7-43a8-8a29-6b4356f07098"}
1542025-01-29T05:18:47.410Z{"msg":"Upstairs opts: Upstairs UUID: f5a6c5f3-3430-4abb-9bf5-a6dd223db52c, 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-01-29T05:18:46.247662742Z","hostname":"w-01JJR7GCCH0R2F5T18F3DFC8YY","pid":1232,"session_id":"70bff5fd-33a7-43a8-8a29-6b4356f07098"}
1552025-01-29T05:18:47.410Z{"msg":"Crucible stats registered with UUID: f5a6c5f3-3430-4abb-9bf5-a6dd223db52c","v":0,"name":"crucible","level":30,"time":"2025-01-29T05:18:46.247715016Z","hostname":"w-01JJR7GCCH0R2F5T18F3DFC8YY","pid":1232,"session_id":"70bff5fd-33a7-43a8-8a29-6b4356f07098"}
1562025-01-29T05:18:47.411Z{"msg":"could not find Downstairs address for Nexus","v":0,"name":"crucible","level":40,"time":"2025-01-29T05:18:46.247730314Z","hostname":"w-01JJR7GCCH0R2F5T18F3DFC8YY","pid":1232,"session_id":"70bff5fd-33a7-43a8-8a29-6b4356f07098"}
1572025-01-29T05:18:47.411Z{"msg":"Downstairs in volume = 6","v":0,"name":"crucible","level":30,"time":"2025-01-29T05:18:46.248384084Z","hostname":"w-01JJR7GCCH0R2F5T18F3DFC8YY","pid":1232,"task":"crutest"}
1582025-01-29T05:18:47.412Z{"msg":"The guest has requested activation with gen:31","v":0,"name":"crucible","level":30,"time":"2025-01-29T05:18:46.248425949Z","hostname":"w-01JJR7GCCH0R2F5T18F3DFC8YY","pid":1232}
1592025-01-29T05:18:47.412Z{"msg":"f5a6c5f3-3430-4abb-9bf5-a6dd223db52c active request set","v":0,"name":"crucible","level":30,"time":"2025-01-29T05:18:46.248498132Z","hostname":"w-01JJR7GCCH0R2F5T18F3DFC8YY","pid":1232,"session_id":"b219cd2e-5dca-4e5d-9d33-ff886eafc6ff"}
1602025-01-29T05:18:47.412Z{"msg":"sending connect oneshot to client","v":0,"name":"crucible","level":30,"time":"2025-01-29T05:18:46.248535527Z","hostname":"w-01JJR7GCCH0R2F5T18F3DFC8YY","pid":1232,"client":"0","":"downstairs","session_id":"b219cd2e-5dca-4e5d-9d33-ff886eafc6ff"}
1612025-01-29T05:18:47.412Z{"msg":"client set_active_request while in Connecting { state: Start { auto_promote: true }, mode: New }; waiting...","v":0,"name":"crucible","level":30,"time":"2025-01-29T05:18:46.248560445Z","hostname":"w-01JJR7GCCH0R2F5T18F3DFC8YY","pid":1232,"client":"0","":"downstairs","session_id":"b219cd2e-5dca-4e5d-9d33-ff886eafc6ff"}
1622025-01-29T05:18:47.412Z{"msg":"sending connect oneshot to client","v":0,"name":"crucible","level":30,"time":"2025-01-29T05:18:46.248597461Z","hostname":"w-01JJR7GCCH0R2F5T18F3DFC8YY","pid":1232,"client":"1","":"downstairs","session_id":"b219cd2e-5dca-4e5d-9d33-ff886eafc6ff"}
1632025-01-29T05:18:47.412Z{"msg":"client set_active_request while in Connecting { state: Start { auto_promote: true }, mode: New }; waiting...","v":0,"name":"crucible","level":30,"time":"2025-01-29T05:18:46.248625438Z","hostname":"w-01JJR7GCCH0R2F5T18F3DFC8YY","pid":1232,"client":"1","":"downstairs","session_id":"b219cd2e-5dca-4e5d-9d33-ff886eafc6ff"}
1642025-01-29T05:18:47.412Z{"msg":"sending connect oneshot to client","v":0,"name":"crucible","level":30,"time":"2025-01-29T05:18:46.248675332Z","hostname":"w-01JJR7GCCH0R2F5T18F3DFC8YY","pid":1232,"client":"2","":"downstairs","session_id":"b219cd2e-5dca-4e5d-9d33-ff886eafc6ff"}
1652025-01-29T05:18:47.412Z{"msg":"client set_active_request while in Connecting { state: Start { auto_promote: true }, mode: New }; waiting...","v":0,"name":"crucible","level":30,"time":"2025-01-29T05:18:46.248704839Z","hostname":"w-01JJR7GCCH0R2F5T18F3DFC8YY","pid":1232,"client":"2","":"downstairs","session_id":"b219cd2e-5dca-4e5d-9d33-ff886eafc6ff"}
1662025-01-29T05:18:47.412Z{"msg":"connecting to 127.0.0.1:8830","v":0,"name":"crucible","level":30,"time":"2025-01-29T05:18:46.248725347Z","hostname":"w-01JJR7GCCH0R2F5T18F3DFC8YY","pid":1232,"":"io task","client":"2","":"downstairs","session_id":"b219cd2e-5dca-4e5d-9d33-ff886eafc6ff"}
1672025-01-29T05:18:47.412Z{"msg":"connecting to 127.0.0.1:8810","v":0,"name":"crucible","level":30,"time":"2025-01-29T05:18:46.248763003Z","hostname":"w-01JJR7GCCH0R2F5T18F3DFC8YY","pid":1232,"":"io task","client":"0","":"downstairs","session_id":"b219cd2e-5dca-4e5d-9d33-ff886eafc6ff"}
1682025-01-29T05:18:47.412Z{"msg":"connecting to 127.0.0.1:8820","v":0,"name":"crucible","level":30,"time":"2025-01-29T05:18:46.24879073Z","hostname":"w-01JJR7GCCH0R2F5T18F3DFC8YY","pid":1232,"":"io task","client":"1","":"downstairs","session_id":"b219cd2e-5dca-4e5d-9d33-ff886eafc6ff"}
1692025-01-29T05:18:47.412Z{"msg":"ds_connection connected from Ok(127.0.0.1:65057)","v":0,"name":"crucible","level":30,"time":"2025-01-29T05:18:46.249049292Z","hostname":"w-01JJR7GCCH0R2F5T18F3DFC8YY","pid":1232,"":"io task","client":"1","":"downstairs","session_id":"b219cd2e-5dca-4e5d-9d33-ff886eafc6ff"}
1702025-01-29T05:18:47.412Z{"msg":"ds_connection connected from Ok(127.0.0.1:44656)","v":0,"name":"crucible","level":30,"time":"2025-01-29T05:18:46.249085498Z","hostname":"w-01JJR7GCCH0R2F5T18F3DFC8YY","pid":1232,"":"io task","client":"2","":"downstairs","session_id":"b219cd2e-5dca-4e5d-9d33-ff886eafc6ff"}
1712025-01-29T05:18:47.412Z{"msg":"ds_connection connected from Ok(127.0.0.1:64600)","v":0,"name":"crucible","level":30,"time":"2025-01-29T05:18:46.249123494Z","hostname":"w-01JJR7GCCH0R2F5T18F3DFC8YY","pid":1232,"":"io task","client":"0","":"downstairs","session_id":"b219cd2e-5dca-4e5d-9d33-ff886eafc6ff"}
1722025-01-29T05:18:47.412Z{"msg":"version negotiation from state Connecting { state: WaitForPromote, mode: New }","v":0,"name":"crucible","level":30,"time":"2025-01-29T05:18:46.249501754Z","hostname":"w-01JJR7GCCH0R2F5T18F3DFC8YY","pid":1232,"client":"1","":"downstairs","session_id":"b219cd2e-5dca-4e5d-9d33-ff886eafc6ff"}
1732025-01-29T05:18:47.412Z{"msg":"version negotiation from state Connecting { state: WaitForPromote, mode: New }","v":0,"name":"crucible","level":30,"time":"2025-01-29T05:18:46.249544389Z","hostname":"w-01JJR7GCCH0R2F5T18F3DFC8YY","pid":1232,"client":"2","":"downstairs","session_id":"b219cd2e-5dca-4e5d-9d33-ff886eafc6ff"}
1742025-01-29T05:18:47.412Z{"msg":"version negotiation from state Connecting { state: WaitForPromote, mode: New }","v":0,"name":"crucible","level":30,"time":"2025-01-29T05:18:46.249584945Z","hostname":"w-01JJR7GCCH0R2F5T18F3DFC8YY","pid":1232,"client":"0","":"downstairs","session_id":"b219cd2e-5dca-4e5d-9d33-ff886eafc6ff"}
1752025-01-29T05:18:47.412Z{"msg":"downstairs client at Some(127.0.0.1:8820) has region UUID 12345678-0000-0000-0000-000000008820","v":0,"name":"crucible","level":30,"time":"2025-01-29T05:18:46.250139155Z","hostname":"w-01JJR7GCCH0R2F5T18F3DFC8YY","pid":1232,"client":"1","":"downstairs","session_id":"b219cd2e-5dca-4e5d-9d33-ff886eafc6ff"}
1762025-01-29T05:18:47.412Z{"msg":"downstairs client at Some(127.0.0.1:8810) has region UUID 12345678-0000-0000-0000-000000008810","v":0,"name":"crucible","level":30,"time":"2025-01-29T05:18:46.250177431Z","hostname":"w-01JJR7GCCH0R2F5T18F3DFC8YY","pid":1232,"client":"0","":"downstairs","session_id":"b219cd2e-5dca-4e5d-9d33-ff886eafc6ff"}
1772025-01-29T05:18:47.412Z{"msg":"downstairs client at Some(127.0.0.1:8830) has region UUID 12345678-0000-0000-0000-000000008830","v":0,"name":"crucible","level":30,"time":"2025-01-29T05:18:46.250201598Z","hostname":"w-01JJR7GCCH0R2F5T18F3DFC8YY","pid":1232,"client":"2","":"downstairs","session_id":"b219cd2e-5dca-4e5d-9d33-ff886eafc6ff"}
1782025-01-29T05:18:47.412Z{"msg":"Waiting for more clients to be ready","v":0,"name":"crucible","level":30,"time":"2025-01-29T05:18:46.250573248Z","hostname":"w-01JJR7GCCH0R2F5T18F3DFC8YY","pid":1232,"session_id":"b219cd2e-5dca-4e5d-9d33-ff886eafc6ff"}
1792025-01-29T05:18:47.412Z{"msg":"Waiting for more clients to be ready","v":0,"name":"crucible","level":30,"time":"2025-01-29T05:18:46.250605295Z","hostname":"w-01JJR7GCCH0R2F5T18F3DFC8YY","pid":1232,"session_id":"b219cd2e-5dca-4e5d-9d33-ff886eafc6ff"}
1802025-01-29T05:18:47.416Z{"msg":"[0]R flush_numbers: [3994, 3994, 3994, 3994, 3994]","v":0,"name":"crucible","level":30,"time":"2025-01-29T05:18:46.250729731Z","hostname":"w-01JJR7GCCH0R2F5T18F3DFC8YY","pid":1232,"":"downstairs","":"downstairs","session_id":"b219cd2e-5dca-4e5d-9d33-ff886eafc6ff"}
1812025-01-29T05:18:47.416Z{"msg":"[0]R generation: [25, 25, 25, 25, 25]","v":0,"name":"crucible","level":30,"time":"2025-01-29T05:18:46.250772786Z","hostname":"w-01JJR7GCCH0R2F5T18F3DFC8YY","pid":1232,"":"downstairs","":"downstairs","session_id":"b219cd2e-5dca-4e5d-9d33-ff886eafc6ff"}
1822025-01-29T05:18:47.416Z{"msg":"[0]R dirty: [false, false, false, false, false]","v":0,"name":"crucible","level":30,"time":"2025-01-29T05:18:46.250798344Z","hostname":"w-01JJR7GCCH0R2F5T18F3DFC8YY","pid":1232,"":"downstairs","":"downstairs","session_id":"b219cd2e-5dca-4e5d-9d33-ff886eafc6ff"}
1832025-01-29T05:18:47.416Z{"msg":"[1]R flush_numbers: [3994, 3994, 3994, 3994, 3994]","v":0,"name":"crucible","level":30,"time":"2025-01-29T05:18:46.25083416Z","hostname":"w-01JJR7GCCH0R2F5T18F3DFC8YY","pid":1232,"":"downstairs","":"downstairs","session_id":"b219cd2e-5dca-4e5d-9d33-ff886eafc6ff"}
1842025-01-29T05:18:47.416Z{"msg":"[1]R generation: [25, 25, 25, 25, 25]","v":0,"name":"crucible","level":30,"time":"2025-01-29T05:18:46.250859277Z","hostname":"w-01JJR7GCCH0R2F5T18F3DFC8YY","pid":1232,"":"downstairs","":"downstairs","session_id":"b219cd2e-5dca-4e5d-9d33-ff886eafc6ff"}
1852025-01-29T05:18:47.416Z{"msg":"[1]R dirty: [false, false, false, false, false]","v":0,"name":"crucible","level":30,"time":"2025-01-29T05:18:46.250883414Z","hostname":"w-01JJR7GCCH0R2F5T18F3DFC8YY","pid":1232,"":"downstairs","":"downstairs","session_id":"b219cd2e-5dca-4e5d-9d33-ff886eafc6ff"}
1862025-01-29T05:18:47.416Z{"msg":"[2]R flush_numbers: [3994, 3994, 3994, 3994, 3994]","v":0,"name":"crucible","level":30,"time":"2025-01-29T05:18:46.250907782Z","hostname":"w-01JJR7GCCH0R2F5T18F3DFC8YY","pid":1232,"":"downstairs","":"downstairs","session_id":"b219cd2e-5dca-4e5d-9d33-ff886eafc6ff"}
1872025-01-29T05:18:47.416Z{"msg":"[2]R generation: [25, 25, 25, 25, 25]","v":0,"name":"crucible","level":30,"time":"2025-01-29T05:18:46.25092447Z","hostname":"w-01JJR7GCCH0R2F5T18F3DFC8YY","pid":1232,"":"downstairs","":"downstairs","session_id":"b219cd2e-5dca-4e5d-9d33-ff886eafc6ff"}
1882025-01-29T05:18:47.417Z{"msg":"[2]R dirty: [false, false, false, false, false]","v":0,"name":"crucible","level":30,"time":"2025-01-29T05:18:46.250948867Z","hostname":"w-01JJR7GCCH0R2F5T18F3DFC8YY","pid":1232,"":"downstairs","":"downstairs","session_id":"b219cd2e-5dca-4e5d-9d33-ff886eafc6ff"}
1892025-01-29T05:18:47.417Z{"msg":"Max found gen is 26","v":0,"name":"crucible","level":30,"time":"2025-01-29T05:18:46.250973595Z","hostname":"w-01JJR7GCCH0R2F5T18F3DFC8YY","pid":1232,"":"downstairs","":"downstairs","session_id":"b219cd2e-5dca-4e5d-9d33-ff886eafc6ff"}
1902025-01-29T05:18:47.417Z{"msg":"Generation requested: 31 >= found:26","v":0,"name":"crucible","level":30,"time":"2025-01-29T05:18:46.25101398Z","hostname":"w-01JJR7GCCH0R2F5T18F3DFC8YY","pid":1232,"":"downstairs","":"downstairs","session_id":"b219cd2e-5dca-4e5d-9d33-ff886eafc6ff"}
1912025-01-29T05:18:47.417Z{"msg":"Next flush: 3995","v":0,"name":"crucible","level":30,"time":"2025-01-29T05:18:46.251041337Z","hostname":"w-01JJR7GCCH0R2F5T18F3DFC8YY","pid":1232,"":"downstairs","":"downstairs","session_id":"b219cd2e-5dca-4e5d-9d33-ff886eafc6ff"}
1922025-01-29T05:18:47.417Z{"msg":"All extents match","v":0,"name":"crucible","level":30,"time":"2025-01-29T05:18:46.251080873Z","hostname":"w-01JJR7GCCH0R2F5T18F3DFC8YY","pid":1232,"":"downstairs","":"downstairs","session_id":"b219cd2e-5dca-4e5d-9d33-ff886eafc6ff"}
1932025-01-29T05:18:47.417Z{"msg":"No downstairs reconciliation required","v":0,"name":"crucible","level":30,"time":"2025-01-29T05:18:46.251121949Z","hostname":"w-01JJR7GCCH0R2F5T18F3DFC8YY","pid":1232,"session_id":"b219cd2e-5dca-4e5d-9d33-ff886eafc6ff"}
1942025-01-29T05:18:47.417Z{"msg":"Transition from WaitQuorum to Active","v":0,"name":"crucible","level":30,"time":"2025-01-29T05:18:46.251158465Z","hostname":"w-01JJR7GCCH0R2F5T18F3DFC8YY","pid":1232,"client":"0","":"downstairs","session_id":"b219cd2e-5dca-4e5d-9d33-ff886eafc6ff"}
1952025-01-29T05:18:47.417Z{"msg":"Transition from WaitQuorum to Active","v":0,"name":"crucible","level":30,"time":"2025-01-29T05:18:46.251250725Z","hostname":"w-01JJR7GCCH0R2F5T18F3DFC8YY","pid":1232,"client":"1","":"downstairs","session_id":"b219cd2e-5dca-4e5d-9d33-ff886eafc6ff"}
1962025-01-29T05:18:47.417Z{"msg":"Transition from WaitQuorum to Active","v":0,"name":"crucible","level":30,"time":"2025-01-29T05:18:46.251282291Z","hostname":"w-01JJR7GCCH0R2F5T18F3DFC8YY","pid":1232,"client":"2","":"downstairs","session_id":"b219cd2e-5dca-4e5d-9d33-ff886eafc6ff"}
1972025-01-29T05:18:47.417Z{"msg":"All required reconciliation work is completed","v":0,"name":"crucible","level":30,"time":"2025-01-29T05:18:46.25138709Z","hostname":"w-01JJR7GCCH0R2F5T18F3DFC8YY","pid":1232,"session_id":"b219cd2e-5dca-4e5d-9d33-ff886eafc6ff"}
1982025-01-29T05:18:47.417Z{"msg":"Set Downstairs and Upstairs active after reconciliation","v":0,"name":"crucible","level":30,"time":"2025-01-29T05:18:46.251421256Z","hostname":"w-01JJR7GCCH0R2F5T18F3DFC8YY","pid":1232,"session_id":"b219cd2e-5dca-4e5d-9d33-ff886eafc6ff"}
1992025-01-29T05:18:47.417Z{"msg":"f5a6c5f3-3430-4abb-9bf5-a6dd223db52c is now active with session: b219cd2e-5dca-4e5d-9d33-ff886eafc6ff","v":0,"name":"crucible","level":30,"time":"2025-01-29T05:18:46.251447934Z","hostname":"w-01JJR7GCCH0R2F5T18F3DFC8YY","pid":1232,"session_id":"b219cd2e-5dca-4e5d-9d33-ff886eafc6ff"}
2002025-01-29T05:18:47.417Z{"msg":"Set Active after no reconciliation","v":0,"name":"crucible","level":30,"time":"2025-01-29T05:18:46.25148239Z","hostname":"w-01JJR7GCCH0R2F5T18F3DFC8YY","pid":1232,"session_id":"b219cd2e-5dca-4e5d-9d33-ff886eafc6ff"}
2012025-01-29T05:18:47.417Z{"msg":"The guest has finished waiting for activation with:31","v":0,"name":"crucible","level":30,"time":"2025-01-29T05:18:46.251505447Z","hostname":"w-01JJR7GCCH0R2F5T18F3DFC8YY","pid":1232}
2022025-01-29T05:18:47.417Z{"msg":"The guest has requested activation with gen:31","v":0,"name":"crucible","level":30,"time":"2025-01-29T05:18:46.251535104Z","hostname":"w-01JJR7GCCH0R2F5T18F3DFC8YY","pid":1232}
2032025-01-29T05:18:47.417Z{"msg":"f5a6c5f3-3430-4abb-9bf5-a6dd223db52c active request set","v":0,"name":"crucible","level":30,"time":"2025-01-29T05:18:46.251555832Z","hostname":"w-01JJR7GCCH0R2F5T18F3DFC8YY","pid":1232,"session_id":"70bff5fd-33a7-43a8-8a29-6b4356f07098"}
2042025-01-29T05:18:47.417Z{"msg":"sending connect oneshot to client","v":0,"name":"crucible","level":30,"time":"2025-01-29T05:18:46.251586159Z","hostname":"w-01JJR7GCCH0R2F5T18F3DFC8YY","pid":1232,"client":"0","":"downstairs","session_id":"70bff5fd-33a7-43a8-8a29-6b4356f07098"}
2052025-01-29T05:18:47.417Z{"msg":"client set_active_request while in Connecting { state: Start { auto_promote: true }, mode: New }; waiting...","v":0,"name":"crucible","level":30,"time":"2025-01-29T05:18:46.251612596Z","hostname":"w-01JJR7GCCH0R2F5T18F3DFC8YY","pid":1232,"client":"0","":"downstairs","session_id":"70bff5fd-33a7-43a8-8a29-6b4356f07098"}
2062025-01-29T05:18:47.417Z{"msg":"sending connect oneshot to client","v":0,"name":"crucible","level":30,"time":"2025-01-29T05:18:46.251645522Z","hostname":"w-01JJR7GCCH0R2F5T18F3DFC8YY","pid":1232,"client":"1","":"downstairs","session_id":"70bff5fd-33a7-43a8-8a29-6b4356f07098"}
2072025-01-29T05:18:47.417Z{"msg":"client set_active_request while in Connecting { state: Start { auto_promote: true }, mode: New }; waiting...","v":0,"name":"crucible","level":30,"time":"2025-01-29T05:18:46.25167126Z","hostname":"w-01JJR7GCCH0R2F5T18F3DFC8YY","pid":1232,"client":"1","":"downstairs","session_id":"70bff5fd-33a7-43a8-8a29-6b4356f07098"}
2082025-01-29T05:18:47.417Z{"msg":"sending connect oneshot to client","v":0,"name":"crucible","level":30,"time":"2025-01-29T05:18:46.251701766Z","hostname":"w-01JJR7GCCH0R2F5T18F3DFC8YY","pid":1232,"client":"2","":"downstairs","session_id":"70bff5fd-33a7-43a8-8a29-6b4356f07098"}
2092025-01-29T05:18:47.417Z{"msg":"client set_active_request while in Connecting { state: Start { auto_promote: true }, mode: New }; waiting...","v":0,"name":"crucible","level":30,"time":"2025-01-29T05:18:46.251728494Z","hostname":"w-01JJR7GCCH0R2F5T18F3DFC8YY","pid":1232,"client":"2","":"downstairs","session_id":"70bff5fd-33a7-43a8-8a29-6b4356f07098"}
2102025-01-29T05:18:47.418Z{"msg":"connecting to 127.0.0.1:8860","v":0,"name":"crucible","level":30,"time":"2025-01-29T05:18:46.251780948Z","hostname":"w-01JJR7GCCH0R2F5T18F3DFC8YY","pid":1232,"":"io task","client":"2","":"downstairs","session_id":"70bff5fd-33a7-43a8-8a29-6b4356f07098"}
2112025-01-29T05:18:47.418Z{"msg":"connecting to 127.0.0.1:8840","v":0,"name":"crucible","level":30,"time":"2025-01-29T05:18:46.251809335Z","hostname":"w-01JJR7GCCH0R2F5T18F3DFC8YY","pid":1232,"":"io task","client":"0","":"downstairs","session_id":"70bff5fd-33a7-43a8-8a29-6b4356f07098"}
2122025-01-29T05:18:47.418Z{"msg":"connecting to 127.0.0.1:8850","v":0,"name":"crucible","level":30,"time":"2025-01-29T05:18:46.251846671Z","hostname":"w-01JJR7GCCH0R2F5T18F3DFC8YY","pid":1232,"":"io task","client":"1","":"downstairs","session_id":"70bff5fd-33a7-43a8-8a29-6b4356f07098"}
2132025-01-29T05:18:47.418Z{"msg":"ds_connection connected from Ok(127.0.0.1:33956)","v":0,"name":"crucible","level":30,"time":"2025-01-29T05:18:46.251861899Z","hostname":"w-01JJR7GCCH0R2F5T18F3DFC8YY","pid":1232,"":"io task","client":"2","":"downstairs","session_id":"70bff5fd-33a7-43a8-8a29-6b4356f07098"}
2142025-01-29T05:18:47.418Z{"msg":"ds_connection connected from Ok(127.0.0.1:49087)","v":0,"name":"crucible","level":30,"time":"2025-01-29T05:18:46.251893716Z","hostname":"w-01JJR7GCCH0R2F5T18F3DFC8YY","pid":1232,"":"io task","client":"0","":"downstairs","session_id":"70bff5fd-33a7-43a8-8a29-6b4356f07098"}
2152025-01-29T05:18:47.418Z{"msg":"ds_connection connected from Ok(127.0.0.1:48891)","v":0,"name":"crucible","level":30,"time":"2025-01-29T05:18:46.251910754Z","hostname":"w-01JJR7GCCH0R2F5T18F3DFC8YY","pid":1232,"":"io task","client":"1","":"downstairs","session_id":"70bff5fd-33a7-43a8-8a29-6b4356f07098"}
2162025-01-29T05:18:47.418Z{"msg":"version negotiation from state Connecting { state: WaitForPromote, mode: New }","v":0,"name":"crucible","level":30,"time":"2025-01-29T05:18:46.251925892Z","hostname":"w-01JJR7GCCH0R2F5T18F3DFC8YY","pid":1232,"client":"0","":"downstairs","session_id":"70bff5fd-33a7-43a8-8a29-6b4356f07098"}
2172025-01-29T05:18:47.418Z{"msg":"version negotiation from state Connecting { state: WaitForPromote, mode: New }","v":0,"name":"crucible","level":30,"time":"2025-01-29T05:18:46.25194498Z","hostname":"w-01JJR7GCCH0R2F5T18F3DFC8YY","pid":1232,"client":"2","":"downstairs","session_id":"70bff5fd-33a7-43a8-8a29-6b4356f07098"}
2182025-01-29T05:18:47.418Z{"msg":"version negotiation from state Connecting { state: WaitForPromote, mode: New }","v":0,"name":"crucible","level":30,"time":"2025-01-29T05:18:46.251958739Z","hostname":"w-01JJR7GCCH0R2F5T18F3DFC8YY","pid":1232,"client":"1","":"downstairs","session_id":"70bff5fd-33a7-43a8-8a29-6b4356f07098"}
2192025-01-29T05:18:47.419Z{"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-01-29T05:18:46.252140639Z","hostname":"w-01JJR7GCCH0R2F5T18F3DFC8YY","pid":1232,"client":"0","":"downstairs","session_id":"70bff5fd-33a7-43a8-8a29-6b4356f07098"}
2202025-01-29T05:18:47.419Z{"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-01-29T05:18:46.252305581Z","hostname":"w-01JJR7GCCH0R2F5T18F3DFC8YY","pid":1232,"client":"1","":"downstairs","session_id":"70bff5fd-33a7-43a8-8a29-6b4356f07098"}
2212025-01-29T05:18:47.419Z{"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-01-29T05:18:46.252335678Z","hostname":"w-01JJR7GCCH0R2F5T18F3DFC8YY","pid":1232,"client":"2","":"downstairs","session_id":"70bff5fd-33a7-43a8-8a29-6b4356f07098"}
2222025-01-29T05:18:47.419Z{"msg":"Waiting for more clients to be ready","v":0,"name":"crucible","level":30,"time":"2025-01-29T05:18:46.252522728Z","hostname":"w-01JJR7GCCH0R2F5T18F3DFC8YY","pid":1232,"session_id":"70bff5fd-33a7-43a8-8a29-6b4356f07098"}
2232025-01-29T05:18:47.419Z{"msg":"Waiting for more clients to be ready","v":0,"name":"crucible","level":30,"time":"2025-01-29T05:18:46.252707668Z","hostname":"w-01JJR7GCCH0R2F5T18F3DFC8YY","pid":1232,"session_id":"70bff5fd-33a7-43a8-8a29-6b4356f07098"}
2242025-01-29T05:18:47.419Z{"msg":"[0]R flush_numbers: [5308, 5307, 5314, 5313, 5310]","v":0,"name":"crucible","level":30,"time":"2025-01-29T05:18:46.252757412Z","hostname":"w-01JJR7GCCH0R2F5T18F3DFC8YY","pid":1232,"":"downstairs","":"downstairs","session_id":"70bff5fd-33a7-43a8-8a29-6b4356f07098"}
2252025-01-29T05:18:47.419Z{"msg":"[0]R generation: [11, 10, 14, 13, 12]","v":0,"name":"crucible","level":30,"time":"2025-01-29T05:18:46.252804818Z","hostname":"w-01JJR7GCCH0R2F5T18F3DFC8YY","pid":1232,"":"downstairs","":"downstairs","session_id":"70bff5fd-33a7-43a8-8a29-6b4356f07098"}
2262025-01-29T05:18:47.419Z{"msg":"[0]R dirty: [false, false, false, false, false]","v":0,"name":"crucible","level":30,"time":"2025-01-29T05:18:46.252830525Z","hostname":"w-01JJR7GCCH0R2F5T18F3DFC8YY","pid":1232,"":"downstairs","":"downstairs","session_id":"70bff5fd-33a7-43a8-8a29-6b4356f07098"}
2272025-01-29T05:18:47.419ZWait for a query_work_queue command to finish before sending IO
2282025-01-29T05:18:47.419Z{"msg":"[1]R flush_numbers: [5308, 5307, 5314, 5313, 5310]","v":0,"name":"crucible","level":30,"time":"2025-01-29T05:18:46.25287439Z","hostname":"w-01JJR7GCCH0R2F5T18F3DFC8YY","pid":1232,"":"downstairs","":"downstairs","session_id":"70bff5fd-33a7-43a8-8a29-6b4356f07098"}
2292025-01-29T05:18:47.419Z{"msg":"[1]R generation: [11, 10, 14, 13, 12]","v":0,"name":"crucible","level":30,"time":"2025-01-29T05:18:46.252910646Z","hostname":"w-01JJR7GCCH0R2F5T18F3DFC8YY","pid":1232,"":"downstairs","":"downstairs","session_id":"70bff5fd-33a7-43a8-8a29-6b4356f07098"}
2302025-01-29T05:18:47.419Z{"msg":"[1]R dirty: [false, false, false, false, false]","v":0,"name":"crucible","level":30,"time":"2025-01-29T05:18:46.252939923Z","hostname":"w-01JJR7GCCH0R2F5T18F3DFC8YY","pid":1232,"":"downstairs","":"downstairs","session_id":"70bff5fd-33a7-43a8-8a29-6b4356f07098"}
2312025-01-29T05:18:47.419Z{"msg":"[2]R flush_numbers: [5308, 5307, 5314, 5313, 5310]","v":0,"name":"crucible","level":30,"time":"2025-01-29T05:18:46.25296416Z","hostname":"w-01JJR7GCCH0R2F5T18F3DFC8YY","pid":1232,"":"downstairs","":"downstairs","session_id":"70bff5fd-33a7-43a8-8a29-6b4356f07098"}
2322025-01-29T05:18:47.419Z{"msg":"[2]R generation: [11, 10, 14, 13, 12]","v":0,"name":"crucible","level":30,"time":"2025-01-29T05:18:46.253014605Z","hostname":"w-01JJR7GCCH0R2F5T18F3DFC8YY","pid":1232,"":"downstairs","":"downstairs","session_id":"70bff5fd-33a7-43a8-8a29-6b4356f07098"}
2332025-01-29T05:18:47.419Z{"msg":"[2]R dirty: [false, false, false, false, false]","v":0,"name":"crucible","level":30,"time":"2025-01-29T05:18:46.253043982Z","hostname":"w-01JJR7GCCH0R2F5T18F3DFC8YY","pid":1232,"":"downstairs","":"downstairs","session_id":"70bff5fd-33a7-43a8-8a29-6b4356f07098"}
2342025-01-29T05:18:47.419Z{"msg":"Max found gen is 15","v":0,"name":"crucible","level":30,"time":"2025-01-29T05:18:46.253080238Z","hostname":"w-01JJR7GCCH0R2F5T18F3DFC8YY","pid":1232,"":"downstairs","":"downstairs","session_id":"70bff5fd-33a7-43a8-8a29-6b4356f07098"}
2352025-01-29T05:18:47.419Z{"msg":"Generation requested: 31 >= found:15","v":0,"name":"crucible","level":30,"time":"2025-01-29T05:18:46.253116444Z","hostname":"w-01JJR7GCCH0R2F5T18F3DFC8YY","pid":1232,"":"downstairs","":"downstairs","session_id":"70bff5fd-33a7-43a8-8a29-6b4356f07098"}
2362025-01-29T05:18:47.419Z{"msg":"Next flush: 5315","v":0,"name":"crucible","level":30,"time":"2025-01-29T05:18:46.253143581Z","hostname":"w-01JJR7GCCH0R2F5T18F3DFC8YY","pid":1232,"":"downstairs","":"downstairs","session_id":"70bff5fd-33a7-43a8-8a29-6b4356f07098"}
2372025-01-29T05:18:47.419Z{"msg":"All extents match","v":0,"name":"crucible","level":30,"time":"2025-01-29T05:18:46.253179817Z","hostname":"w-01JJR7GCCH0R2F5T18F3DFC8YY","pid":1232,"":"downstairs","":"downstairs","session_id":"70bff5fd-33a7-43a8-8a29-6b4356f07098"}
2382025-01-29T05:18:47.419Z{"msg":"No downstairs reconciliation required","v":0,"name":"crucible","level":30,"time":"2025-01-29T05:18:46.253196975Z","hostname":"w-01JJR7GCCH0R2F5T18F3DFC8YY","pid":1232,"session_id":"70bff5fd-33a7-43a8-8a29-6b4356f07098"}
2392025-01-29T05:18:47.419Z{"msg":"Transition from WaitQuorum to Active","v":0,"name":"crucible","level":30,"time":"2025-01-29T05:18:46.253216303Z","hostname":"w-01JJR7GCCH0R2F5T18F3DFC8YY","pid":1232,"client":"0","":"downstairs","session_id":"70bff5fd-33a7-43a8-8a29-6b4356f07098"}
2402025-01-29T05:18:47.419Z{"msg":"Transition from WaitQuorum to Active","v":0,"name":"crucible","level":30,"time":"2025-01-29T05:18:46.253252589Z","hostname":"w-01JJR7GCCH0R2F5T18F3DFC8YY","pid":1232,"client":"1","":"downstairs","session_id":"70bff5fd-33a7-43a8-8a29-6b4356f07098"}
2412025-01-29T05:18:47.420Z{"msg":"Transition from WaitQuorum to Active","v":0,"name":"crucible","level":30,"time":"2025-01-29T05:18:46.253272707Z","hostname":"w-01JJR7GCCH0R2F5T18F3DFC8YY","pid":1232,"client":"2","":"downstairs","session_id":"70bff5fd-33a7-43a8-8a29-6b4356f07098"}
2422025-01-29T05:18:47.420Z{"msg":"All required reconciliation work is completed","v":0,"name":"crucible","level":30,"time":"2025-01-29T05:18:46.253294835Z","hostname":"w-01JJR7GCCH0R2F5T18F3DFC8YY","pid":1232,"session_id":"70bff5fd-33a7-43a8-8a29-6b4356f07098"}
2432025-01-29T05:18:47.420Z{"msg":"Set Downstairs and Upstairs active after reconciliation","v":0,"name":"crucible","level":30,"time":"2025-01-29T05:18:46.253316332Z","hostname":"w-01JJR7GCCH0R2F5T18F3DFC8YY","pid":1232,"session_id":"70bff5fd-33a7-43a8-8a29-6b4356f07098"}
2442025-01-29T05:18:47.420Z{"msg":"f5a6c5f3-3430-4abb-9bf5-a6dd223db52c is now active with session: 70bff5fd-33a7-43a8-8a29-6b4356f07098","v":0,"name":"crucible","level":30,"time":"2025-01-29T05:18:46.253348789Z","hostname":"w-01JJR7GCCH0R2F5T18F3DFC8YY","pid":1232,"session_id":"70bff5fd-33a7-43a8-8a29-6b4356f07098"}
2452025-01-29T05:18:47.420Z{"msg":"Set Active after no reconciliation","v":0,"name":"crucible","level":30,"time":"2025-01-29T05:18:46.253373896Z","hostname":"w-01JJR7GCCH0R2F5T18F3DFC8YY","pid":1232,"session_id":"70bff5fd-33a7-43a8-8a29-6b4356f07098"}
2462025-01-29T05:18:47.420Z{"msg":"The guest has finished waiting for activation with:31","v":0,"name":"crucible","level":30,"time":"2025-01-29T05:18:46.253389095Z","hostname":"w-01JJR7GCCH0R2F5T18F3DFC8YY","pid":1232}
2472025-01-29T05:18:47.420ZDisk: sv:2 bs:4096 ts:409600 tb:100 max_io:100 or 409600
2482025-01-29T05:18:47.420ZFill test
2492025-01-29T05:18:47.455ZRead and Verify all blocks (0..100 range:false)
2502025-01-29T05:18:47.534ZWrote out file "/var/tmp/test_up-build/verify_file"
2512025-01-29T05:18:47.534ZCLIENT: Tests done. All submitted work has been ACK'd
2522025-01-29T05:18:47.537Z----------------------------------------------------------------
2532025-01-29T05:18:47.537Z Crucible gen:31 GIO:true work queues: Upstairs:0 downstairs:1
2542025-01-29T05:18:47.537ZStates: Active Active Active
2552025-01-29T05:18:47.537ZJOBID ACK TYPE BKS/EXT DS:0 DS:1 DS:2 REPLAY
2562025-01-29T05:18:47.537Z 1002 Acked Read 50 Done Done Done false
2572025-01-29T05:18:47.538Z STATES DS:0 DS:1 DS:2 TOTAL
2582025-01-29T05:18:47.538Z Sent 0 0 0 0
2592025-01-29T05:18:47.538Z Done 1 1 1 3
2602025-01-29T05:18:47.538Z Skipped 0 0 0 0
2612025-01-29T05:18:47.538Z Error 0 0 0 0
2622025-01-29T05:18:47.538ZLast Flush: Some(JobId(1001)) Some(JobId(1001)) Some(JobId(1001))
2632025-01-29T05:18:47.538ZDownstairs last five completed: 1001 1000
2642025-01-29T05:18:47.538ZUpstairs last five completed: 1002 1001 1000
2652025-01-29T05:18:47.538Z----------------------------------------------------------------
2662025-01-29T05:18:47.538Z Crucible gen:31 GIO:true work queues: Upstairs:0 downstairs:1
2672025-01-29T05:18:47.538ZStates: Active Active Active
2682025-01-29T05:18:47.538ZJOBID ACK TYPE BKS/EXT DS:0 DS:1 DS:2 REPLAY
2692025-01-29T05:18:47.538Z 1002 Acked Read 50 Done Done Done false
2702025-01-29T05:18:47.538Z STATES DS:0 DS:1 DS:2 TOTAL
2712025-01-29T05:18:47.538Z Sent 0 0 0 0
2722025-01-29T05:18:47.538Z Done 1 1 1 3
2732025-01-29T05:18:47.538Z Skipped 0 0 0 0
2742025-01-29T05:18:47.538Z Error 0 0 0 0
2752025-01-29T05:18:47.538ZLast Flush: Some(JobId(1001)) Some(JobId(1001)) Some(JobId(1001))
2762025-01-29T05:18:47.538ZDownstairs last five completed: 1001 1000
2772025-01-29T05:18:47.539ZUpstairs last five completed: 1002 1001 1000
2782025-01-29T05:18:47.539ZCLIENT: Up:0 ds:2 act:6
2792025-01-29T05:18:51.537Z----------------------------------------------------------------
2802025-01-29T05:18:51.537Z Crucible gen:31 GIO:true work queues: Upstairs:0 downstairs:0
2812025-01-29T05:18:51.537ZDownstairs last five completed: 1003 1002 1001 1000
2822025-01-29T05:18:51.537ZUpstairs last five completed: 1003 1002 1001 1000
2832025-01-29T05:18:51.537Z----------------------------------------------------------------
2842025-01-29T05:18:51.537Z Crucible gen:31 GIO:true work queues: Upstairs:0 downstairs:0
2852025-01-29T05:18:51.538ZDownstairs last five completed: 1003 1002 1001 1000
2862025-01-29T05:18:51.538ZUpstairs last five completed: 1003 1002 1001 1000
2872025-01-29T05:18:51.540ZCLIENT: Up:0 ds:0 act:6
2882025-01-29T05:18:51.540ZCLIENT: All crucible jobs finished, exiting program
2892025-01-29T05:18:51.549ZRepair setup passed
2902025-01-29T05:18:51.552ZCopy the region for /var/tmp/test_up-build/8830
2912025-01-29T05:18:51.555Zcp -r /var/tmp/test_up-build/8830 /var/tmp/test_up-build/previous
2922025-01-29T05:18:51.557Z/var/tmp/bins/crutest fill -g 32 -q --key SHgaJxxqdc0f4qfR8nhZsqCvTH7mH/l3BWZZM52dUQk= --dsc 127.0.0.1:9998 --verify-out /var/tmp/test_up-build/verify_file --verify-in /var/tmp/test_up-build/verify_file
2932025-01-29T05:18:51.615Z{"msg":"Use this region info from dsc: RegionExtentInfo { block_size: 4096, blocks_per_extent: 10, extent_count: 5 }","v":0,"name":"crucible","level":30,"time":"2025-01-29T05:18:50.454600798Z","hostname":"w-01JJR7GCCH0R2F5T18F3DFC8YY","pid":1238,"task":"crutest"}
2942025-01-29T05:18:51.618Z{"msg":"dsc has 6 regions. This means 2 sub_volumes","v":0,"name":"crucible","level":30,"time":"2025-01-29T05:18:50.455170747Z","hostname":"w-01JJR7GCCH0R2F5T18F3DFC8YY","pid":1238,"task":"crutest"}
2952025-01-29T05:18:51.618Z{"msg":"SV 0 has targets: [127.0.0.1:8810, 127.0.0.1:8820, 127.0.0.1:8830]","v":0,"name":"crucible","level":30,"time":"2025-01-29T05:18:50.456759365Z","hostname":"w-01JJR7GCCH0R2F5T18F3DFC8YY","pid":1238,"task":"crutest"}
2962025-01-29T05:18:51.618Z{"msg":"Upstairs starts","v":0,"name":"crucible","level":30,"time":"2025-01-29T05:18:50.456945465Z","hostname":"w-01JJR7GCCH0R2F5T18F3DFC8YY","pid":1238}
2972025-01-29T05:18:51.618Z{"msg":"Crucible Version: BuildInfo {\n version: \"0.0.1\",\n git_sha: \"442be2395eb3bf8ebe11d34acf0678a1aae4fa71\",\n git_commit_timestamp: \"2025-01-29T04:48:13.000000000Z\",\n git_branch: \"main\",\n rustc_semver: \"1.84.0\",\n rustc_channel: \"stable\",\n rustc_host_triple: \"x86_64-unknown-illumos\",\n rustc_commit_sha: \"9fc6b43126469e3858e2fe86cafb4f0fd5068869\",\n cargo_triple: \"x86_64-unknown-illumos\",\n debug: true,\n opt_level: 0,\n}","v":0,"name":"crucible","level":30,"time":"2025-01-29T05:18:50.45699022Z","hostname":"w-01JJR7GCCH0R2F5T18F3DFC8YY","pid":1238}
2982025-01-29T05:18:51.618Z{"msg":"Upstairs <-> Downstairs Message Version: 13","v":0,"name":"crucible","level":30,"time":"2025-01-29T05:18:50.457021927Z","hostname":"w-01JJR7GCCH0R2F5T18F3DFC8YY","pid":1238}
2992025-01-29T05:18:51.618Z{"msg":"Using region definition RegionDefinition { block_size: 4096, extent_size: Block { value: 10, shift: 12 }, extent_count: 5, uuid: 00000000-0000-0000-0000-000000000000, encrypted: true, database_read_version: 1, database_write_version: 1 }","v":0,"name":"crucible","level":30,"time":"2025-01-29T05:18:50.457038685Z","hostname":"w-01JJR7GCCH0R2F5T18F3DFC8YY","pid":1238}
3002025-01-29T05:18:51.620Z{"msg":"Crucible 05430afc-eb7c-4acd-a07b-cbfe59ed94ee has session id: 04ec08bb-f3fe-4409-9a4e-6c2986849bb9","v":0,"name":"crucible","level":30,"time":"2025-01-29T05:18:50.457695444Z","hostname":"w-01JJR7GCCH0R2F5T18F3DFC8YY","pid":1238,"session_id":"04ec08bb-f3fe-4409-9a4e-6c2986849bb9"}
3012025-01-29T05:18:51.620Z{"msg":"Upstairs opts: Upstairs UUID: 05430afc-eb7c-4acd-a07b-cbfe59ed94ee, Targets: [127.0.0.1:8810, 127.0.0.1:8820, 127.0.0.1:8830], lossy: false, flush_timeout: None, key populated: true, cert_pem populated: false, key_pem populated: false, root_cert_pem populated: false, Control: None, read_only: false","v":0,"name":"crucible","level":30,"time":"2025-01-29T05:18:50.457753928Z","hostname":"w-01JJR7GCCH0R2F5T18F3DFC8YY","pid":1238,"session_id":"04ec08bb-f3fe-4409-9a4e-6c2986849bb9"}
3022025-01-29T05:18:51.620Z{"msg":"Crucible stats registered with UUID: 05430afc-eb7c-4acd-a07b-cbfe59ed94ee","v":0,"name":"crucible","level":30,"time":"2025-01-29T05:18:50.457798433Z","hostname":"w-01JJR7GCCH0R2F5T18F3DFC8YY","pid":1238,"session_id":"04ec08bb-f3fe-4409-9a4e-6c2986849bb9"}
3032025-01-29T05:18:51.620Z{"msg":"could not find Downstairs address for Nexus","v":0,"name":"crucible","level":40,"time":"2025-01-29T05:18:50.457821621Z","hostname":"w-01JJR7GCCH0R2F5T18F3DFC8YY","pid":1238,"session_id":"04ec08bb-f3fe-4409-9a4e-6c2986849bb9"}
3042025-01-29T05:18:51.620Z{"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-01-29T05:18:50.459783649Z","hostname":"w-01JJR7GCCH0R2F5T18F3DFC8YY","pid":1238,"task":"crutest"}
3052025-01-29T05:18:51.620Z{"msg":"Upstairs starts","v":0,"name":"crucible","level":30,"time":"2025-01-29T05:18:50.459894627Z","hostname":"w-01JJR7GCCH0R2F5T18F3DFC8YY","pid":1238}
3062025-01-29T05:18:51.621Z{"msg":"Crucible Version: BuildInfo {\n version: \"0.0.1\",\n git_sha: \"442be2395eb3bf8ebe11d34acf0678a1aae4fa71\",\n git_commit_timestamp: \"2025-01-29T04:48:13.000000000Z\",\n git_branch: \"main\",\n rustc_semver: \"1.84.0\",\n rustc_channel: \"stable\",\n rustc_host_triple: \"x86_64-unknown-illumos\",\n rustc_commit_sha: \"9fc6b43126469e3858e2fe86cafb4f0fd5068869\",\n cargo_triple: \"x86_64-unknown-illumos\",\n debug: true,\n opt_level: 0,\n}","v":0,"name":"crucible","level":30,"time":"2025-01-29T05:18:50.459938393Z","hostname":"w-01JJR7GCCH0R2F5T18F3DFC8YY","pid":1238}
3072025-01-29T05:18:51.621Z{"msg":"Upstairs <-> Downstairs Message Version: 13","v":0,"name":"crucible","level":30,"time":"2025-01-29T05:18:50.4599606Z","hostname":"w-01JJR7GCCH0R2F5T18F3DFC8YY","pid":1238}
3082025-01-29T05:18:51.621Z{"msg":"Using region definition RegionDefinition { block_size: 4096, extent_size: Block { value: 10, shift: 12 }, extent_count: 5, uuid: 00000000-0000-0000-0000-000000000000, encrypted: true, database_read_version: 1, database_write_version: 1 }","v":0,"name":"crucible","level":30,"time":"2025-01-29T05:18:50.459975929Z","hostname":"w-01JJR7GCCH0R2F5T18F3DFC8YY","pid":1238}
3092025-01-29T05:18:51.625Z{"msg":"Crucible 05430afc-eb7c-4acd-a07b-cbfe59ed94ee has session id: 3b944c8d-a29a-4f08-bcd7-3880379ef589","v":0,"name":"crucible","level":30,"time":"2025-01-29T05:18:50.460356008Z","hostname":"w-01JJR7GCCH0R2F5T18F3DFC8YY","pid":1238,"session_id":"3b944c8d-a29a-4f08-bcd7-3880379ef589"}
3102025-01-29T05:18:51.625Z{"msg":"Upstairs opts: Upstairs UUID: 05430afc-eb7c-4acd-a07b-cbfe59ed94ee, 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-01-29T05:18:50.460407722Z","hostname":"w-01JJR7GCCH0R2F5T18F3DFC8YY","pid":1238,"session_id":"3b944c8d-a29a-4f08-bcd7-3880379ef589"}
3112025-01-29T05:18:51.625Z{"msg":"Crucible stats registered with UUID: 05430afc-eb7c-4acd-a07b-cbfe59ed94ee","v":0,"name":"crucible","level":30,"time":"2025-01-29T05:18:50.460444928Z","hostname":"w-01JJR7GCCH0R2F5T18F3DFC8YY","pid":1238,"session_id":"3b944c8d-a29a-4f08-bcd7-3880379ef589"}
3122025-01-29T05:18:51.625Z{"msg":"could not find Downstairs address for Nexus","v":0,"name":"crucible","level":40,"time":"2025-01-29T05:18:50.460468026Z","hostname":"w-01JJR7GCCH0R2F5T18F3DFC8YY","pid":1238,"session_id":"3b944c8d-a29a-4f08-bcd7-3880379ef589"}
3132025-01-29T05:18:51.625Z{"msg":"Downstairs in volume = 6","v":0,"name":"crucible","level":30,"time":"2025-01-29T05:18:50.46107758Z","hostname":"w-01JJR7GCCH0R2F5T18F3DFC8YY","pid":1238,"task":"crutest"}
3142025-01-29T05:18:51.625Z{"msg":"The guest has requested activation with gen:32","v":0,"name":"crucible","level":30,"time":"2025-01-29T05:18:50.461132784Z","hostname":"w-01JJR7GCCH0R2F5T18F3DFC8YY","pid":1238}
3152025-01-29T05:18:51.625Z{"msg":"05430afc-eb7c-4acd-a07b-cbfe59ed94ee active request set","v":0,"name":"crucible","level":30,"time":"2025-01-29T05:18:50.461229754Z","hostname":"w-01JJR7GCCH0R2F5T18F3DFC8YY","pid":1238,"session_id":"04ec08bb-f3fe-4409-9a4e-6c2986849bb9"}
3162025-01-29T05:18:51.625Z{"msg":"sending connect oneshot to client","v":0,"name":"crucible","level":30,"time":"2025-01-29T05:18:50.46126555Z","hostname":"w-01JJR7GCCH0R2F5T18F3DFC8YY","pid":1238,"client":"0","":"downstairs","session_id":"04ec08bb-f3fe-4409-9a4e-6c2986849bb9"}
3172025-01-29T05:18:51.625Z{"msg":"client set_active_request while in Connecting { state: Start { auto_promote: true }, mode: New }; waiting...","v":0,"name":"crucible","level":30,"time":"2025-01-29T05:18:50.461312595Z","hostname":"w-01JJR7GCCH0R2F5T18F3DFC8YY","pid":1238,"client":"0","":"downstairs","session_id":"04ec08bb-f3fe-4409-9a4e-6c2986849bb9"}
3182025-01-29T05:18:51.626Z{"msg":"sending connect oneshot to client","v":0,"name":"crucible","level":30,"time":"2025-01-29T05:18:50.461410494Z","hostname":"w-01JJR7GCCH0R2F5T18F3DFC8YY","pid":1238,"client":"1","":"downstairs","session_id":"04ec08bb-f3fe-4409-9a4e-6c2986849bb9"}
3192025-01-29T05:18:51.626Z{"msg":"client set_active_request while in Connecting { state: Start { auto_promote: true }, mode: New }; waiting...","v":0,"name":"crucible","level":30,"time":"2025-01-29T05:18:50.461461929Z","hostname":"w-01JJR7GCCH0R2F5T18F3DFC8YY","pid":1238,"client":"1","":"downstairs","session_id":"04ec08bb-f3fe-4409-9a4e-6c2986849bb9"}
3202025-01-29T05:18:51.626Z{"msg":"sending connect oneshot to client","v":0,"name":"crucible","level":30,"time":"2025-01-29T05:18:50.461490195Z","hostname":"w-01JJR7GCCH0R2F5T18F3DFC8YY","pid":1238,"client":"2","":"downstairs","session_id":"04ec08bb-f3fe-4409-9a4e-6c2986849bb9"}
3212025-01-29T05:18:51.626Z{"msg":"client set_active_request while in Connecting { state: Start { auto_promote: true }, mode: New }; waiting...","v":0,"name":"crucible","level":30,"time":"2025-01-29T05:18:50.461530491Z","hostname":"w-01JJR7GCCH0R2F5T18F3DFC8YY","pid":1238,"client":"2","":"downstairs","session_id":"04ec08bb-f3fe-4409-9a4e-6c2986849bb9"}
3222025-01-29T05:18:51.626Z{"msg":"connecting to 127.0.0.1:8830","v":0,"name":"crucible","level":30,"time":"2025-01-29T05:18:50.461567797Z","hostname":"w-01JJR7GCCH0R2F5T18F3DFC8YY","pid":1238,"":"io task","client":"2","":"downstairs","session_id":"04ec08bb-f3fe-4409-9a4e-6c2986849bb9"}
3232025-01-29T05:18:51.626Z{"msg":"connecting to 127.0.0.1:8810","v":0,"name":"crucible","level":30,"time":"2025-01-29T05:18:50.461802722Z","hostname":"w-01JJR7GCCH0R2F5T18F3DFC8YY","pid":1238,"":"io task","client":"0","":"downstairs","session_id":"04ec08bb-f3fe-4409-9a4e-6c2986849bb9"}
3242025-01-29T05:18:51.626Z{"msg":"connecting to 127.0.0.1:8820","v":0,"name":"crucible","level":30,"time":"2025-01-29T05:18:50.461847587Z","hostname":"w-01JJR7GCCH0R2F5T18F3DFC8YY","pid":1238,"":"io task","client":"1","":"downstairs","session_id":"04ec08bb-f3fe-4409-9a4e-6c2986849bb9"}
3252025-01-29T05:18:51.626Z{"msg":"ds_connection connected from Ok(127.0.0.1:43835)","v":0,"name":"crucible","level":30,"time":"2025-01-29T05:18:50.461885493Z","hostname":"w-01JJR7GCCH0R2F5T18F3DFC8YY","pid":1238,"":"io task","client":"2","":"downstairs","session_id":"04ec08bb-f3fe-4409-9a4e-6c2986849bb9"}
3262025-01-29T05:18:51.626Z{"msg":"ds_connection connected from Ok(127.0.0.1:51629)","v":0,"name":"crucible","level":30,"time":"2025-01-29T05:18:50.46190841Z","hostname":"w-01JJR7GCCH0R2F5T18F3DFC8YY","pid":1238,"":"io task","client":"1","":"downstairs","session_id":"04ec08bb-f3fe-4409-9a4e-6c2986849bb9"}
3272025-01-29T05:18:51.626Z{"msg":"ds_connection connected from Ok(127.0.0.1:49975)","v":0,"name":"crucible","level":30,"time":"2025-01-29T05:18:50.461959205Z","hostname":"w-01JJR7GCCH0R2F5T18F3DFC8YY","pid":1238,"":"io task","client":"0","":"downstairs","session_id":"04ec08bb-f3fe-4409-9a4e-6c2986849bb9"}
3282025-01-29T05:18:51.626Z{"msg":"version negotiation from state Connecting { state: WaitForPromote, mode: New }","v":0,"name":"crucible","level":30,"time":"2025-01-29T05:18:50.462322626Z","hostname":"w-01JJR7GCCH0R2F5T18F3DFC8YY","pid":1238,"client":"2","":"downstairs","session_id":"04ec08bb-f3fe-4409-9a4e-6c2986849bb9"}
3292025-01-29T05:18:51.626Z{"msg":"version negotiation from state Connecting { state: WaitForPromote, mode: New }","v":0,"name":"crucible","level":30,"time":"2025-01-29T05:18:50.462366521Z","hostname":"w-01JJR7GCCH0R2F5T18F3DFC8YY","pid":1238,"client":"0","":"downstairs","session_id":"04ec08bb-f3fe-4409-9a4e-6c2986849bb9"}
3302025-01-29T05:18:51.626Z{"msg":"version negotiation from state Connecting { state: WaitForPromote, mode: New }","v":0,"name":"crucible","level":30,"time":"2025-01-29T05:18:50.462409227Z","hostname":"w-01JJR7GCCH0R2F5T18F3DFC8YY","pid":1238,"client":"1","":"downstairs","session_id":"04ec08bb-f3fe-4409-9a4e-6c2986849bb9"}
3312025-01-29T05:18:51.629Z{"msg":"downstairs client at Some(127.0.0.1:8810) has region UUID 12345678-0000-0000-0000-000000008810","v":0,"name":"crucible","level":30,"time":"2025-01-29T05:18:50.463077304Z","hostname":"w-01JJR7GCCH0R2F5T18F3DFC8YY","pid":1238,"client":"0","":"downstairs","session_id":"04ec08bb-f3fe-4409-9a4e-6c2986849bb9"}
3322025-01-29T05:18:51.629Z{"msg":"downstairs client at Some(127.0.0.1:8820) has region UUID 12345678-0000-0000-0000-000000008820","v":0,"name":"crucible","level":30,"time":"2025-01-29T05:18:50.463201781Z","hostname":"w-01JJR7GCCH0R2F5T18F3DFC8YY","pid":1238,"client":"1","":"downstairs","session_id":"04ec08bb-f3fe-4409-9a4e-6c2986849bb9"}
3332025-01-29T05:18:51.629Z{"msg":"downstairs client at Some(127.0.0.1:8830) has region UUID 12345678-0000-0000-0000-000000008830","v":0,"name":"crucible","level":30,"time":"2025-01-29T05:18:50.463249016Z","hostname":"w-01JJR7GCCH0R2F5T18F3DFC8YY","pid":1238,"client":"2","":"downstairs","session_id":"04ec08bb-f3fe-4409-9a4e-6c2986849bb9"}
3342025-01-29T05:18:51.629Z{"msg":"Waiting for more clients to be ready","v":0,"name":"crucible","level":30,"time":"2025-01-29T05:18:50.463428477Z","hostname":"w-01JJR7GCCH0R2F5T18F3DFC8YY","pid":1238,"session_id":"04ec08bb-f3fe-4409-9a4e-6c2986849bb9"}
3352025-01-29T05:18:51.630Z{"msg":"Waiting for more clients to be ready","v":0,"name":"crucible","level":30,"time":"2025-01-29T05:18:50.463544444Z","hostname":"w-01JJR7GCCH0R2F5T18F3DFC8YY","pid":1238,"session_id":"04ec08bb-f3fe-4409-9a4e-6c2986849bb9"}
3362025-01-29T05:18:51.630Z{"msg":"[0]R flush_numbers: [3995, 3995, 3995, 3995, 3995]","v":0,"name":"crucible","level":30,"time":"2025-01-29T05:18:50.463632735Z","hostname":"w-01JJR7GCCH0R2F5T18F3DFC8YY","pid":1238,"":"downstairs","":"downstairs","session_id":"04ec08bb-f3fe-4409-9a4e-6c2986849bb9"}
3372025-01-29T05:18:51.630Z{"msg":"[0]R generation: [31, 31, 31, 31, 31]","v":0,"name":"crucible","level":30,"time":"2025-01-29T05:18:50.463661172Z","hostname":"w-01JJR7GCCH0R2F5T18F3DFC8YY","pid":1238,"":"downstairs","":"downstairs","session_id":"04ec08bb-f3fe-4409-9a4e-6c2986849bb9"}
3382025-01-29T05:18:51.630Z{"msg":"[0]R dirty: [false, false, false, false, false]","v":0,"name":"crucible","level":30,"time":"2025-01-29T05:18:50.46367591Z","hostname":"w-01JJR7GCCH0R2F5T18F3DFC8YY","pid":1238,"":"downstairs","":"downstairs","session_id":"04ec08bb-f3fe-4409-9a4e-6c2986849bb9"}
3392025-01-29T05:18:51.630Z{"msg":"[1]R flush_numbers: [3995, 3995, 3995, 3995, 3995]","v":0,"name":"crucible","level":30,"time":"2025-01-29T05:18:50.463738193Z","hostname":"w-01JJR7GCCH0R2F5T18F3DFC8YY","pid":1238,"":"downstairs","":"downstairs","session_id":"04ec08bb-f3fe-4409-9a4e-6c2986849bb9"}
3402025-01-29T05:18:51.630Z{"msg":"[1]R generation: [31, 31, 31, 31, 31]","v":0,"name":"crucible","level":30,"time":"2025-01-29T05:18:50.463779649Z","hostname":"w-01JJR7GCCH0R2F5T18F3DFC8YY","pid":1238,"":"downstairs","":"downstairs","session_id":"04ec08bb-f3fe-4409-9a4e-6c2986849bb9"}
3412025-01-29T05:18:51.630Z{"msg":"[1]R dirty: [false, false, false, false, false]","v":0,"name":"crucible","level":30,"time":"2025-01-29T05:18:50.463804676Z","hostname":"w-01JJR7GCCH0R2F5T18F3DFC8YY","pid":1238,"":"downstairs","":"downstairs","session_id":"04ec08bb-f3fe-4409-9a4e-6c2986849bb9"}
3422025-01-29T05:18:51.630Z{"msg":"[2]R flush_numbers: [3995, 3995, 3995, 3995, 3995]","v":0,"name":"crucible","level":30,"time":"2025-01-29T05:18:50.463837042Z","hostname":"w-01JJR7GCCH0R2F5T18F3DFC8YY","pid":1238,"":"downstairs","":"downstairs","session_id":"04ec08bb-f3fe-4409-9a4e-6c2986849bb9"}
3432025-01-29T05:18:51.630Z{"msg":"[2]R generation: [31, 31, 31, 31, 31]","v":0,"name":"crucible","level":30,"time":"2025-01-29T05:18:50.46385845Z","hostname":"w-01JJR7GCCH0R2F5T18F3DFC8YY","pid":1238,"":"downstairs","":"downstairs","session_id":"04ec08bb-f3fe-4409-9a4e-6c2986849bb9"}
3442025-01-29T05:18:51.630Z{"msg":"[2]R dirty: [false, false, false, false, false]","v":0,"name":"crucible","level":30,"time":"2025-01-29T05:18:50.463897676Z","hostname":"w-01JJR7GCCH0R2F5T18F3DFC8YY","pid":1238,"":"downstairs","":"downstairs","session_id":"04ec08bb-f3fe-4409-9a4e-6c2986849bb9"}
3452025-01-29T05:18:51.630Z{"msg":"Max found gen is 32","v":0,"name":"crucible","level":30,"time":"2025-01-29T05:18:50.463931582Z","hostname":"w-01JJR7GCCH0R2F5T18F3DFC8YY","pid":1238,"":"downstairs","":"downstairs","session_id":"04ec08bb-f3fe-4409-9a4e-6c2986849bb9"}
3462025-01-29T05:18:51.630Z{"msg":"Generation requested: 32 >= found:32","v":0,"name":"crucible","level":30,"time":"2025-01-29T05:18:50.46395611Z","hostname":"w-01JJR7GCCH0R2F5T18F3DFC8YY","pid":1238,"":"downstairs","":"downstairs","session_id":"04ec08bb-f3fe-4409-9a4e-6c2986849bb9"}
3472025-01-29T05:18:51.630Z{"msg":"Next flush: 3996","v":0,"name":"crucible","level":30,"time":"2025-01-29T05:18:50.463998545Z","hostname":"w-01JJR7GCCH0R2F5T18F3DFC8YY","pid":1238,"":"downstairs","":"downstairs","session_id":"04ec08bb-f3fe-4409-9a4e-6c2986849bb9"}
3482025-01-29T05:18:51.630Z{"msg":"All extents match","v":0,"name":"crucible","level":30,"time":"2025-01-29T05:18:50.464022393Z","hostname":"w-01JJR7GCCH0R2F5T18F3DFC8YY","pid":1238,"":"downstairs","":"downstairs","session_id":"04ec08bb-f3fe-4409-9a4e-6c2986849bb9"}
3492025-01-29T05:18:51.630Z{"msg":"No downstairs reconciliation required","v":0,"name":"crucible","level":30,"time":"2025-01-29T05:18:50.46404597Z","hostname":"w-01JJR7GCCH0R2F5T18F3DFC8YY","pid":1238,"session_id":"04ec08bb-f3fe-4409-9a4e-6c2986849bb9"}
3502025-01-29T05:18:51.630Z{"msg":"Transition from WaitQuorum to Active","v":0,"name":"crucible","level":30,"time":"2025-01-29T05:18:50.464169987Z","hostname":"w-01JJR7GCCH0R2F5T18F3DFC8YY","pid":1238,"client":"0","":"downstairs","session_id":"04ec08bb-f3fe-4409-9a4e-6c2986849bb9"}
3512025-01-29T05:18:51.630Z{"msg":"Transition from WaitQuorum to Active","v":0,"name":"crucible","level":30,"time":"2025-01-29T05:18:50.464202893Z","hostname":"w-01JJR7GCCH0R2F5T18F3DFC8YY","pid":1238,"client":"1","":"downstairs","session_id":"04ec08bb-f3fe-4409-9a4e-6c2986849bb9"}
3522025-01-29T05:18:51.630Z{"msg":"Transition from WaitQuorum to Active","v":0,"name":"crucible","level":30,"time":"2025-01-29T05:18:50.46422808Z","hostname":"w-01JJR7GCCH0R2F5T18F3DFC8YY","pid":1238,"client":"2","":"downstairs","session_id":"04ec08bb-f3fe-4409-9a4e-6c2986849bb9"}
3532025-01-29T05:18:51.631Z{"msg":"All required reconciliation work is completed","v":0,"name":"crucible","level":30,"time":"2025-01-29T05:18:50.464255827Z","hostname":"w-01JJR7GCCH0R2F5T18F3DFC8YY","pid":1238,"session_id":"04ec08bb-f3fe-4409-9a4e-6c2986849bb9"}
3542025-01-29T05:18:51.631Z{"msg":"Set Downstairs and Upstairs active after reconciliation","v":0,"name":"crucible","level":30,"time":"2025-01-29T05:18:50.464278745Z","hostname":"w-01JJR7GCCH0R2F5T18F3DFC8YY","pid":1238,"session_id":"04ec08bb-f3fe-4409-9a4e-6c2986849bb9"}
3552025-01-29T05:18:51.631Z{"msg":"05430afc-eb7c-4acd-a07b-cbfe59ed94ee is now active with session: 04ec08bb-f3fe-4409-9a4e-6c2986849bb9","v":0,"name":"crucible","level":30,"time":"2025-01-29T05:18:50.464304482Z","hostname":"w-01JJR7GCCH0R2F5T18F3DFC8YY","pid":1238,"session_id":"04ec08bb-f3fe-4409-9a4e-6c2986849bb9"}
3562025-01-29T05:18:51.631Z{"msg":"Set Active after no reconciliation","v":0,"name":"crucible","level":30,"time":"2025-01-29T05:18:50.464332619Z","hostname":"w-01JJR7GCCH0R2F5T18F3DFC8YY","pid":1238,"session_id":"04ec08bb-f3fe-4409-9a4e-6c2986849bb9"}
3572025-01-29T05:18:51.631Z{"msg":"The guest has finished waiting for activation with:32","v":0,"name":"crucible","level":30,"time":"2025-01-29T05:18:50.464347278Z","hostname":"w-01JJR7GCCH0R2F5T18F3DFC8YY","pid":1238}
3582025-01-29T05:18:51.631Z{"msg":"The guest has requested activation with gen:32","v":0,"name":"crucible","level":30,"time":"2025-01-29T05:18:50.464367115Z","hostname":"w-01JJR7GCCH0R2F5T18F3DFC8YY","pid":1238}
3592025-01-29T05:18:51.631Z{"msg":"05430afc-eb7c-4acd-a07b-cbfe59ed94ee active request set","v":0,"name":"crucible","level":30,"time":"2025-01-29T05:18:50.464389383Z","hostname":"w-01JJR7GCCH0R2F5T18F3DFC8YY","pid":1238,"session_id":"3b944c8d-a29a-4f08-bcd7-3880379ef589"}
3602025-01-29T05:18:51.631Z{"msg":"sending connect oneshot to client","v":0,"name":"crucible","level":30,"time":"2025-01-29T05:18:50.46441208Z","hostname":"w-01JJR7GCCH0R2F5T18F3DFC8YY","pid":1238,"client":"0","":"downstairs","session_id":"3b944c8d-a29a-4f08-bcd7-3880379ef589"}
3612025-01-29T05:18:51.631Z{"msg":"client set_active_request while in Connecting { state: Start { auto_promote: true }, mode: New }; waiting...","v":0,"name":"crucible","level":30,"time":"2025-01-29T05:18:50.464450956Z","hostname":"w-01JJR7GCCH0R2F5T18F3DFC8YY","pid":1238,"client":"0","":"downstairs","session_id":"3b944c8d-a29a-4f08-bcd7-3880379ef589"}
3622025-01-29T05:18:51.631Z{"msg":"sending connect oneshot to client","v":0,"name":"crucible","level":30,"time":"2025-01-29T05:18:50.464475254Z","hostname":"w-01JJR7GCCH0R2F5T18F3DFC8YY","pid":1238,"client":"1","":"downstairs","session_id":"3b944c8d-a29a-4f08-bcd7-3880379ef589"}
3632025-01-29T05:18:51.631Z{"msg":"client set_active_request while in Connecting { state: Start { auto_promote: true }, mode: New }; waiting...","v":0,"name":"crucible","level":30,"time":"2025-01-29T05:18:50.464498271Z","hostname":"w-01JJR7GCCH0R2F5T18F3DFC8YY","pid":1238,"client":"1","":"downstairs","session_id":"3b944c8d-a29a-4f08-bcd7-3880379ef589"}
3642025-01-29T05:18:51.631Z{"msg":"sending connect oneshot to client","v":0,"name":"crucible","level":30,"time":"2025-01-29T05:18:50.464520839Z","hostname":"w-01JJR7GCCH0R2F5T18F3DFC8YY","pid":1238,"client":"2","":"downstairs","session_id":"3b944c8d-a29a-4f08-bcd7-3880379ef589"}
3652025-01-29T05:18:51.631Z{"msg":"client set_active_request while in Connecting { state: Start { auto_promote: true }, mode: New }; waiting...","v":0,"name":"crucible","level":30,"time":"2025-01-29T05:18:50.464544976Z","hostname":"w-01JJR7GCCH0R2F5T18F3DFC8YY","pid":1238,"client":"2","":"downstairs","session_id":"3b944c8d-a29a-4f08-bcd7-3880379ef589"}
3662025-01-29T05:18:51.631Z{"msg":"connecting to 127.0.0.1:8860","v":0,"name":"crucible","level":30,"time":"2025-01-29T05:18:50.464574553Z","hostname":"w-01JJR7GCCH0R2F5T18F3DFC8YY","pid":1238,"":"io task","client":"2","":"downstairs","session_id":"3b944c8d-a29a-4f08-bcd7-3880379ef589"}
3672025-01-29T05:18:51.631Z{"msg":"connecting to 127.0.0.1:8840","v":0,"name":"crucible","level":30,"time":"2025-01-29T05:18:50.464598331Z","hostname":"w-01JJR7GCCH0R2F5T18F3DFC8YY","pid":1238,"":"io task","client":"0","":"downstairs","session_id":"3b944c8d-a29a-4f08-bcd7-3880379ef589"}
3682025-01-29T05:18:51.631Z{"msg":"connecting to 127.0.0.1:8850","v":0,"name":"crucible","level":30,"time":"2025-01-29T05:18:50.464637216Z","hostname":"w-01JJR7GCCH0R2F5T18F3DFC8YY","pid":1238,"":"io task","client":"1","":"downstairs","session_id":"3b944c8d-a29a-4f08-bcd7-3880379ef589"}
3692025-01-29T05:18:51.631Z{"msg":"ds_connection connected from Ok(127.0.0.1:54158)","v":0,"name":"crucible","level":30,"time":"2025-01-29T05:18:50.464659834Z","hostname":"w-01JJR7GCCH0R2F5T18F3DFC8YY","pid":1238,"":"io task","client":"2","":"downstairs","session_id":"3b944c8d-a29a-4f08-bcd7-3880379ef589"}
3702025-01-29T05:18:51.631Z{"msg":"ds_connection connected from Ok(127.0.0.1:44396)","v":0,"name":"crucible","level":30,"time":"2025-01-29T05:18:50.464682571Z","hostname":"w-01JJR7GCCH0R2F5T18F3DFC8YY","pid":1238,"":"io task","client":"0","":"downstairs","session_id":"3b944c8d-a29a-4f08-bcd7-3880379ef589"}
3712025-01-29T05:18:51.631Z{"msg":"ds_connection connected from Ok(127.0.0.1:33356)","v":0,"name":"crucible","level":30,"time":"2025-01-29T05:18:50.464707459Z","hostname":"w-01JJR7GCCH0R2F5T18F3DFC8YY","pid":1238,"":"io task","client":"1","":"downstairs","session_id":"3b944c8d-a29a-4f08-bcd7-3880379ef589"}
3722025-01-29T05:18:51.631Z{"msg":"version negotiation from state Connecting { state: WaitForPromote, mode: New }","v":0,"name":"crucible","level":30,"time":"2025-01-29T05:18:50.464742045Z","hostname":"w-01JJR7GCCH0R2F5T18F3DFC8YY","pid":1238,"client":"0","":"downstairs","session_id":"3b944c8d-a29a-4f08-bcd7-3880379ef589"}
3732025-01-29T05:18:51.631Z{"msg":"version negotiation from state Connecting { state: WaitForPromote, mode: New }","v":0,"name":"crucible","level":30,"time":"2025-01-29T05:18:50.464767062Z","hostname":"w-01JJR7GCCH0R2F5T18F3DFC8YY","pid":1238,"client":"1","":"downstairs","session_id":"3b944c8d-a29a-4f08-bcd7-3880379ef589"}
3742025-01-29T05:18:51.632Z{"msg":"version negotiation from state Connecting { state: WaitForPromote, mode: New }","v":0,"name":"crucible","level":30,"time":"2025-01-29T05:18:50.464795219Z","hostname":"w-01JJR7GCCH0R2F5T18F3DFC8YY","pid":1238,"client":"2","":"downstairs","session_id":"3b944c8d-a29a-4f08-bcd7-3880379ef589"}
3752025-01-29T05:18:51.632Z{"msg":"downstairs client at Some(127.0.0.1:8840) has region UUID 12345678-0000-0000-0000-000000008840","v":0,"name":"crucible","level":30,"time":"2025-01-29T05:18:50.465051022Z","hostname":"w-01JJR7GCCH0R2F5T18F3DFC8YY","pid":1238,"client":"0","":"downstairs","session_id":"3b944c8d-a29a-4f08-bcd7-3880379ef589"}
3762025-01-29T05:18:51.632Z{"msg":"downstairs client at Some(127.0.0.1:8850) has region UUID 12345678-0000-0000-0000-000000008850","v":0,"name":"crucible","level":30,"time":"2025-01-29T05:18:50.46525417Z","hostname":"w-01JJR7GCCH0R2F5T18F3DFC8YY","pid":1238,"client":"1","":"downstairs","session_id":"3b944c8d-a29a-4f08-bcd7-3880379ef589"}
3772025-01-29T05:18:51.632Z{"msg":"Waiting for more clients to be ready","v":0,"name":"crucible","level":30,"time":"2025-01-29T05:18:50.465445399Z","hostname":"w-01JJR7GCCH0R2F5T18F3DFC8YY","pid":1238,"session_id":"3b944c8d-a29a-4f08-bcd7-3880379ef589"}
3782025-01-29T05:18:51.632Z{"msg":"downstairs client at Some(127.0.0.1:8860) has region UUID 12345678-0000-0000-0000-000000008860","v":0,"name":"crucible","level":30,"time":"2025-01-29T05:18:50.465547178Z","hostname":"w-01JJR7GCCH0R2F5T18F3DFC8YY","pid":1238,"client":"2","":"downstairs","session_id":"3b944c8d-a29a-4f08-bcd7-3880379ef589"}
3792025-01-29T05:18:51.632Z{"msg":"Waiting for more clients to be ready","v":0,"name":"crucible","level":30,"time":"2025-01-29T05:18:50.465698932Z","hostname":"w-01JJR7GCCH0R2F5T18F3DFC8YY","pid":1238,"session_id":"3b944c8d-a29a-4f08-bcd7-3880379ef589"}
3802025-01-29T05:18:51.632Z{"msg":"[0]R flush_numbers: [5315, 5315, 5315, 5315, 5315]","v":0,"name":"crucible","level":30,"time":"2025-01-29T05:18:50.465861664Z","hostname":"w-01JJR7GCCH0R2F5T18F3DFC8YY","pid":1238,"":"downstairs","":"downstairs","session_id":"3b944c8d-a29a-4f08-bcd7-3880379ef589"}
3812025-01-29T05:18:51.632Z{"msg":"[0]R generation: [31, 31, 31, 31, 31]","v":0,"name":"crucible","level":30,"time":"2025-01-29T05:18:50.465889671Z","hostname":"w-01JJR7GCCH0R2F5T18F3DFC8YY","pid":1238,"":"downstairs","":"downstairs","session_id":"3b944c8d-a29a-4f08-bcd7-3880379ef589"}
3822025-01-29T05:18:51.632Z{"msg":"[0]R dirty: [false, false, false, false, false]","v":0,"name":"crucible","level":30,"time":"2025-01-29T05:18:50.46590516Z","hostname":"w-01JJR7GCCH0R2F5T18F3DFC8YY","pid":1238,"":"downstairs","":"downstairs","session_id":"3b944c8d-a29a-4f08-bcd7-3880379ef589"}
3832025-01-29T05:18:51.633Z{"msg":"[1]R flush_numbers: [5315, 5315, 5315, 5315, 5315]","v":0,"name":"crucible","level":30,"time":"2025-01-29T05:18:50.465935736Z","hostname":"w-01JJR7GCCH0R2F5T18F3DFC8YY","pid":1238,"":"downstairs","":"downstairs","session_id":"3b944c8d-a29a-4f08-bcd7-3880379ef589"}
3842025-01-29T05:18:51.633Z{"msg":"[1]R generation: [31, 31, 31, 31, 31]","v":0,"name":"crucible","level":30,"time":"2025-01-29T05:18:50.465950965Z","hostname":"w-01JJR7GCCH0R2F5T18F3DFC8YY","pid":1238,"":"downstairs","":"downstairs","session_id":"3b944c8d-a29a-4f08-bcd7-3880379ef589"}
3852025-01-29T05:18:51.633Z{"msg":"[1]R dirty: [false, false, false, false, false]","v":0,"name":"crucible","level":30,"time":"2025-01-29T05:18:50.465981991Z","hostname":"w-01JJR7GCCH0R2F5T18F3DFC8YY","pid":1238,"":"downstairs","":"downstairs","session_id":"3b944c8d-a29a-4f08-bcd7-3880379ef589"}
3862025-01-29T05:18:51.633Z{"msg":"[2]R flush_numbers: [5315, 5315, 5315, 5315, 5315]","v":0,"name":"crucible","level":30Wait for a query_work_queue command to finish before sending IO
3872025-01-29T05:18:51.633Z,"time":"2025-01-29T05:18:50.466003469Z","hostname":"w-01JJR7GCCH0R2F5T18F3DFC8YY","pid":1238,"":"downstairs","":"downstairs","session_id":"3b944c8d-a29a-4f08-bcd7-3880379ef589"}
3882025-01-29T05:18:51.633Z{"msg":"[2]R generation: [31, 31, 31, 31, 31]","v":0,"name":"crucible","level":30,"time":"2025-01-29T05:18:50.466030616Z","hostname":"w-01JJR7GCCH0R2F5T18F3DFC8YY","pid":1238,"":"downstairs","":"downstairs","session_id":"3b944c8d-a29a-4f08-bcd7-3880379ef589"}
3892025-01-29T05:18:51.633Z{"msg":"[2]R dirty: [false, false, false, false, false]","v":0,"name":"crucible","level":30,"time":"2025-01-29T05:18:50.466060753Z","hostname":"w-01JJR7GCCH0R2F5T18F3DFC8YY","pid":1238,"":"downstairs","":"downstairs","session_id":"3b944c8d-a29a-4f08-bcd7-3880379ef589"}
3902025-01-29T05:18:51.633Z{"msg":"Max found gen is 32","v":0,"name":"crucible","level":30,"time":"2025-01-29T05:18:50.466076041Z","hostname":"w-01JJR7GCCH0R2F5T18F3DFC8YY","pid":1238,"":"downstairs","":"downstairs","session_id":"3b944c8d-a29a-4f08-bcd7-3880379ef589"}
3912025-01-29T05:18:51.633Z{"msg":"Generation requested: 32 >= found:32","v":0,"name":"crucible","level":30,"time":"2025-01-29T05:18:50.466116107Z","hostname":"w-01JJR7GCCH0R2F5T18F3DFC8YY","pid":1238,"":"downstairs","":"downstairs","session_id":"3b944c8d-a29a-4f08-bcd7-3880379ef589"}
3922025-01-29T05:18:51.633Z{"msg":"Next flush: 5316","v":0,"name":"crucible","level":30,"time":"2025-01-29T05:18:50.466132675Z","hostname":"w-01JJR7GCCH0R2F5T18F3DFC8YY","pid":1238,"":"downstairs","":"downstairs","session_id":"3b944c8d-a29a-4f08-bcd7-3880379ef589"}
3932025-01-29T05:18:51.633Z{"msg":"All extents match","v":0,"name":"crucible","level":30,"time":"2025-01-29T05:18:50.466164172Z","hostname":"w-01JJR7GCCH0R2F5T18F3DFC8YY","pid":1238,"":"downstairs","":"downstairs","session_id":"3b944c8d-a29a-4f08-bcd7-3880379ef589"}
3942025-01-29T05:18:51.633Z{"msg":"No downstairs reconciliation required","v":0,"name":"crucible","level":30,"time":"2025-01-29T05:18:50.46618176Z","hostname":"w-01JJR7GCCH0R2F5T18F3DFC8YY","pid":1238,"session_id":"3b944c8d-a29a-4f08-bcd7-3880379ef589"}
3952025-01-29T05:18:51.633Z{"msg":"Transition from WaitQuorum to Active","v":0,"name":"crucible","level":30,"time":"2025-01-29T05:18:50.466209637Z","hostname":"w-01JJR7GCCH0R2F5T18F3DFC8YY","pid":1238,"client":"0","":"downstairs","session_id":"3b944c8d-a29a-4f08-bcd7-3880379ef589"}
3962025-01-29T05:18:51.633Z{"msg":"Transition from WaitQuorum to Active","v":0,"name":"crucible","level":30,"time":"2025-01-29T05:18:50.466224325Z","hostname":"w-01JJR7GCCH0R2F5T18F3DFC8YY","pid":1238,"client":"1","":"downstairs","session_id":"3b944c8d-a29a-4f08-bcd7-3880379ef589"}
3972025-01-29T05:18:51.633Z{"msg":"Transition from WaitQuorum to Active","v":0,"name":"crucible","level":30,"time":"2025-01-29T05:18:50.466253402Z","hostname":"w-01JJR7GCCH0R2F5T18F3DFC8YY","pid":1238,"client":"2","":"downstairs","session_id":"3b944c8d-a29a-4f08-bcd7-3880379ef589"}
3982025-01-29T05:18:51.633Z{"msg":"All required reconciliation work is completed","v":0,"name":"crucible","level":30,"time":"2025-01-29T05:18:50.46627316Z","hostname":"w-01JJR7GCCH0R2F5T18F3DFC8YY","pid":1238,"session_id":"3b944c8d-a29a-4f08-bcd7-3880379ef589"}
3992025-01-29T05:18:51.633Z{"msg":"Set Downstairs and Upstairs active after reconciliation","v":0,"name":"crucible","level":30,"time":"2025-01-29T05:18:50.466301867Z","hostname":"w-01JJR7GCCH0R2F5T18F3DFC8YY","pid":1238,"session_id":"3b944c8d-a29a-4f08-bcd7-3880379ef589"}
4002025-01-29T05:18:51.633Z{"msg":"05430afc-eb7c-4acd-a07b-cbfe59ed94ee is now active with session: 3b944c8d-a29a-4f08-bcd7-3880379ef589","v":0,"name":"crucible","level":30,"time":"2025-01-29T05:18:50.466315855Z","hostname":"w-01JJR7GCCH0R2F5T18F3DFC8YY","pid":1238,"session_id":"3b944c8d-a29a-4f08-bcd7-3880379ef589"}
4012025-01-29T05:18:51.633Z{"msg":"Set Active after no reconciliation","v":0,"name":"crucible","level":30,"time":"2025-01-29T05:18:50.466343183Z","hostname":"w-01JJR7GCCH0R2F5T18F3DFC8YY","pid":1238,"session_id":"3b944c8d-a29a-4f08-bcd7-3880379ef589"}
4022025-01-29T05:18:51.633Z{"msg":"The guest has finished waiting for activation with:32","v":0,"name":"crucible","level":30,"time":"2025-01-29T05:18:50.466359641Z","hostname":"w-01JJR7GCCH0R2F5T18F3DFC8YY","pid":1238}
4032025-01-29T05:18:51.633ZDisk: sv:2 bs:4096 ts:409600 tb:100 max_io:100 or 409600
4042025-01-29T05:18:51.633ZLoading write count information from file "/var/tmp/test_up-build/verify_file"
4052025-01-29T05:18:51.633ZFill test
4062025-01-29T05:18:51.668ZRead and Verify all blocks (0..100 range:false)
4072025-01-29T05:18:51.747ZWrote out file "/var/tmp/test_up-build/verify_file"
4082025-01-29T05:18:51.747ZCLIENT: Tests done. All submitted work has been ACK'd
4092025-01-29T05:18:51.747Z----------------------------------------------------------------
4102025-01-29T05:18:51.747Z Crucible gen:32 GIO:true work queues: Upstairs:0 downstairs:1
4112025-01-29T05:18:51.747ZStates: Active Active Active
4122025-01-29T05:18:51.747ZJOBID ACK TYPE BKS/EXT DS:0 DS:1 DS:2 REPLAY
4132025-01-29T05:18:51.750Z 1002 Acked Read 50 Done Done Done false
4142025-01-29T05:18:51.750Z STATES DS:0 DS:1 DS:2 TOTAL
4152025-01-29T05:18:51.750Z Sent 0 0 0 0
4162025-01-29T05:18:51.750Z Done 1 1 1 3
4172025-01-29T05:18:51.750Z Skipped 0 0 0 0
4182025-01-29T05:18:51.750Z Error 0 0 0 0
4192025-01-29T05:18:51.751ZLast Flush: Some(JobId(1001)) Some(JobId(1001)) Some(JobId(1001))
4202025-01-29T05:18:51.751ZDownstairs last five completed: 1001 1000
4212025-01-29T05:18:51.751ZUpstairs last five completed: 1002 1001 1000
4222025-01-29T05:18:51.751Z----------------------------------------------------------------
4232025-01-29T05:18:51.751Z Crucible gen:32 GIO:true work queues: Upstairs:0 downstairs:1
4242025-01-29T05:18:51.751ZStates: Active Active Active
4252025-01-29T05:18:51.751ZJOBID ACK TYPE BKS/EXT DS:0 DS:1 DS:2 REPLAY
4262025-01-29T05:18:51.751Z 1002 Acked Read 50 Done Done Done false
4272025-01-29T05:18:51.751Z STATES DS:0 DS:1 DS:2 TOTAL
4282025-01-29T05:18:51.751Z Sent 0 0 0 0
4292025-01-29T05:18:51.751Z Done 1 1 1 3
4302025-01-29T05:18:51.751Z Skipped 0 0 0 0
4312025-01-29T05:18:51.751Z Error 0 0 0 0
4322025-01-29T05:18:51.751ZLast Flush: Some(JobId(1001)) Some(JobId(1001)) Some(JobId(1001))
4332025-01-29T05:18:51.751ZDownstairs last five completed: 1001 1000
4342025-01-29T05:18:51.751ZUpstairs last five completed: 1002 1001 1000
4352025-01-29T05:18:51.751ZCLIENT: Up:0 ds:2 act:6
4362025-01-29T05:18:55.749Z----------------------------------------------------------------
4372025-01-29T05:18:55.750Z Crucible gen:32 GIO:true work queues: Upstairs:0 downstairs:0
4382025-01-29T05:18:55.750ZDownstairs last five completed: 1003 1002 1001 1000
4392025-01-29T05:18:55.750ZUpstairs last five completed: 1003 1002 1001 1000
4402025-01-29T05:18:55.752Z----------------------------------------------------------------
4412025-01-29T05:18:55.752Z Crucible gen:32 GIO:true work queues: Upstairs:0 downstairs:0
4422025-01-29T05:18:55.752ZDownstairs last five completed: 1003 1002 1001 1000
4432025-01-29T05:18:55.753ZUpstairs last five completed: 1003 1002 1001 1000
4442025-01-29T05:18:55.753ZCLIENT: Up:0 ds:0 act:6
4452025-01-29T05:18:55.753ZCLIENT: All crucible jobs finished, exiting program
4462025-01-29T05:18:55.757ZRepair part 1 passed
4472025-01-29T05:18:55.759Z
4482025-01-29T05:18:55.760ZKill the current downstairs
4492025-01-29T05:18:55.935ZDownstairs 2 stopped
4502025-01-29T05:18:55.935Zmv /var/tmp/test_up-build/8830 /var/tmp/test_up-build/new
4512025-01-29T05:18:55.938ZNow put back the original so we have a mismatch
4522025-01-29T05:18:55.938Zmv /var/tmp/test_up-build/previous /var/tmp/test_up-build/8830
4532025-01-29T05:18:55.940ZRestart downstairs with old directory
4542025-01-29T05:18:56.005Z/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
4552025-01-29T05:18:56.021ZEXT BLOCKS GEN0 GEN1 GEN2 FL0 FL1 FL2 D0 D1 D2 DIFF
4562025-01-29T05:18:56.024Z 0 000-009 32 32 31 3996 3996 3995 F F F <---
4572025-01-29T05:18:56.025Z 1 010-019 32 32 31 3996 3996 3995 F F F <---
4582025-01-29T05:18:56.025Z 2 020-029 32 32 31 3996 3996 3995 F F F <---
4592025-01-29T05:18:56.025Z 3 030-039 32 32 31 3996 3996 3995 F F F <---
4602025-01-29T05:18:56.025Z 4 040-049 32 32 31 3996 3996 3995 F F F <---
4612025-01-29T05:18:56.025ZMax gen: 32, Max flush: 3996
4622025-01-29T05:18:56.025ZError: Difference in extent metadata found!
4632025-01-29T05:18:56.028Zdump test found error as expected
4642025-01-29T05:18:56.028Z
4652025-01-29T05:18:56.028Z
4662025-01-29T05:18:56.028Z/var/tmp/bins/crutest verify --range -g 33 -q --key SHgaJxxqdc0f4qfR8nhZsqCvTH7mH/l3BWZZM52dUQk= --dsc 127.0.0.1:9998 --verify-out /var/tmp/test_up-build/verify_file --verify-in /var/tmp/test_up-build/verify_file
4672025-01-29T05:18:56.084Z{"msg":"Use this region info from dsc: RegionExtentInfo { block_size: 4096, blocks_per_extent: 10, extent_count: 5 }","v":0,"name":"crucible","level":30,"time":"2025-01-29T05:18:54.923330648Z","hostname":"w-01JJR7GCCH0R2F5T18F3DFC8YY","pid":1246,"task":"crutest"}
4682025-01-29T05:18:56.087Z{"msg":"dsc has 6 regions. This means 2 sub_volumes","v":0,"name":"crucible","level":30,"time":"2025-01-29T05:18:54.923928493Z","hostname":"w-01JJR7GCCH0R2F5T18F3DFC8YY","pid":1246,"task":"crutest"}
4692025-01-29T05:18:56.087Z{"msg":"SV 0 has targets: [127.0.0.1:8810, 127.0.0.1:8820, 127.0.0.1:8830]","v":0,"name":"crucible","level":30,"time":"2025-01-29T05:18:54.925606333Z","hostname":"w-01JJR7GCCH0R2F5T18F3DFC8YY","pid":1246,"task":"crutest"}
4702025-01-29T05:18:56.087Z{"msg":"Upstairs starts","v":0,"name":"crucible","level":30,"time":"2025-01-29T05:18:54.925804841Z","hostname":"w-01JJR7GCCH0R2F5T18F3DFC8YY","pid":1246}
4712025-01-29T05:18:56.087Z{"msg":"Crucible Version: BuildInfo {\n version: \"0.0.1\",\n git_sha: \"442be2395eb3bf8ebe11d34acf0678a1aae4fa71\",\n git_commit_timestamp: \"2025-01-29T04:48:13.000000000Z\",\n git_branch: \"main\",\n rustc_semver: \"1.84.0\",\n rustc_channel: \"stable\",\n rustc_host_triple: \"x86_64-unknown-illumos\",\n rustc_commit_sha: \"9fc6b43126469e3858e2fe86cafb4f0fd5068869\",\n cargo_triple: \"x86_64-unknown-illumos\",\n debug: true,\n opt_level: 0,\n}","v":0,"name":"crucible","level":30,"time":"2025-01-29T05:18:54.925851256Z","hostname":"w-01JJR7GCCH0R2F5T18F3DFC8YY","pid":1246}
4722025-01-29T05:18:56.087Z{"msg":"Upstairs <-> Downstairs Message Version: 13","v":0,"name":"crucible","level":30,"time":"2025-01-29T05:18:54.925875904Z","hostname":"w-01JJR7GCCH0R2F5T18F3DFC8YY","pid":1246}
4732025-01-29T05:18:56.087Z{"msg":"Using region definition RegionDefinition { block_size: 4096, extent_size: Block { value: 10, shift: 12 }, extent_count: 5, uuid: 00000000-0000-0000-0000-000000000000, encrypted: true, database_read_version: 1, database_write_version: 1 }","v":0,"name":"crucible","level":30,"time":"2025-01-29T05:18:54.925891112Z","hostname":"w-01JJR7GCCH0R2F5T18F3DFC8YY","pid":1246}
4742025-01-29T05:18:56.090Z{"msg":"Crucible aabd67c9-c40f-46d7-af73-3f2fd95245c1 has session id: 041f7efc-ed37-46d8-99c9-df961754a65a","v":0,"name":"crucible","level":30,"time":"2025-01-29T05:18:54.926494427Z","hostname":"w-01JJR7GCCH0R2F5T18F3DFC8YY","pid":1246,"session_id":"041f7efc-ed37-46d8-99c9-df961754a65a"}
4752025-01-29T05:18:56.090Z{"msg":"Upstairs opts: Upstairs UUID: aabd67c9-c40f-46d7-af73-3f2fd95245c1, Targets: [127.0.0.1:8810, 127.0.0.1:8820, 127.0.0.1:8830], lossy: false, flush_timeout: None, key populated: true, cert_pem populated: false, key_pem populated: false, root_cert_pem populated: false, Control: None, read_only: false","v":0,"name":"crucible","level":30,"time":"2025-01-29T05:18:54.926599206Z","hostname":"w-01JJR7GCCH0R2F5T18F3DFC8YY","pid":1246,"session_id":"041f7efc-ed37-46d8-99c9-df961754a65a"}
4762025-01-29T05:18:56.090Z{"msg":"Crucible stats registered with UUID: aabd67c9-c40f-46d7-af73-3f2fd95245c1","v":0,"name":"crucible","level":30,"time":"2025-01-29T05:18:54.926657929Z","hostname":"w-01JJR7GCCH0R2F5T18F3DFC8YY","pid":1246,"session_id":"041f7efc-ed37-46d8-99c9-df961754a65a"}
4772025-01-29T05:18:56.090Z{"msg":"could not find Downstairs address for Nexus","v":0,"name":"crucible","level":40,"time":"2025-01-29T05:18:54.926699985Z","hostname":"w-01JJR7GCCH0R2F5T18F3DFC8YY","pid":1246,"session_id":"041f7efc-ed37-46d8-99c9-df961754a65a"}
4782025-01-29T05:18:56.090Z{"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-01-29T05:18:54.928613648Z","hostname":"w-01JJR7GCCH0R2F5T18F3DFC8YY","pid":1246,"task":"crutest"}
4792025-01-29T05:18:56.090Z{"msg":"Upstairs starts","v":0,"name":"crucible","level":30,"time":"2025-01-29T05:18:54.928705029Z","hostname":"w-01JJR7GCCH0R2F5T18F3DFC8YY","pid":1246}
4802025-01-29T05:18:56.090Z{"msg":"Crucible Version: BuildInfo {\n version: \"0.0.1\",\n git_sha: \"442be2395eb3bf8ebe11d34acf0678a1aae4fa71\",\n git_commit_timestamp: \"2025-01-29T04:48:13.000000000Z\",\n git_branch: \"main\",\n rustc_semver: \"1.84.0\",\n rustc_channel: \"stable\",\n rustc_host_triple: \"x86_64-unknown-illumos\",\n rustc_commit_sha: \"9fc6b43126469e3858e2fe86cafb4f0fd5068869\",\n cargo_triple: \"x86_64-unknown-illumos\",\n debug: true,\n opt_level: 0,\n}","v":0,"name":"crucible","level":30,"time":"2025-01-29T05:18:54.928742405Z","hostname":"w-01JJR7GCCH0R2F5T18F3DFC8YY","pid":1246}
4812025-01-29T05:18:56.090Z{"msg":"Upstairs <-> Downstairs Message Version: 13","v":0,"name":"crucible","level":30,"time":"2025-01-29T05:18:54.928755993Z","hostname":"w-01JJR7GCCH0R2F5T18F3DFC8YY","pid":1246}
4822025-01-29T05:18:56.090Z{"msg":"Using region definition RegionDefinition { block_size: 4096, extent_size: Block { value: 10, shift: 12 }, extent_count: 5, uuid: 00000000-0000-0000-0000-000000000000, encrypted: true, database_read_version: 1, database_write_version: 1 }","v":0,"name":"crucible","level":30,"time":"2025-01-29T05:18:54.92878085Z","hostname":"w-01JJR7GCCH0R2F5T18F3DFC8YY","pid":1246}
4832025-01-29T05:18:56.093Z{"msg":"Crucible aabd67c9-c40f-46d7-af73-3f2fd95245c1 has session id: a6fd3390-f12a-4723-9426-0dc6961f280a","v":0,"name":"crucible","level":30,"time":"2025-01-29T05:18:54.929258309Z","hostname":"w-01JJR7GCCH0R2F5T18F3DFC8YY","pid":1246,"session_id":"a6fd3390-f12a-4723-9426-0dc6961f280a"}
4842025-01-29T05:18:56.093Z{"msg":"Upstairs opts: Upstairs UUID: aabd67c9-c40f-46d7-af73-3f2fd95245c1, 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-01-29T05:18:54.929299405Z","hostname":"w-01JJR7GCCH0R2F5T18F3DFC8YY","pid":1246,"session_id":"a6fd3390-f12a-4723-9426-0dc6961f280a"}
4852025-01-29T05:18:56.093Z{"msg":"Crucible stats registered with UUID: aabd67c9-c40f-46d7-af73-3f2fd95245c1","v":0,"name":"crucible","level":30,"time":"2025-01-29T05:18:54.929323832Z","hostname":"w-01JJR7GCCH0R2F5T18F3DFC8YY","pid":1246,"session_id":"a6fd3390-f12a-4723-9426-0dc6961f280a"}
4862025-01-29T05:18:56.093Z{"msg":"could not find Downstairs address for Nexus","v":0,"name":"crucible","level":40,"time":"2025-01-29T05:18:54.929361018Z","hostname":"w-01JJR7GCCH0R2F5T18F3DFC8YY","pid":1246,"session_id":"a6fd3390-f12a-4723-9426-0dc6961f280a"}
4872025-01-29T05:18:56.093Z{"msg":"Downstairs in volume = 6","v":0,"name":"crucible","level":30,"time":"2025-01-29T05:18:54.930115837Z","hostname":"w-01JJR7GCCH0R2F5T18F3DFC8YY","pid":1246,"task":"crutest"}
4882025-01-29T05:18:56.094Z{"msg":"The guest has requested activation with gen:33","v":0,"name":"crucible","level":30,"time":"2025-01-29T05:18:54.930171121Z","hostname":"w-01JJR7GCCH0R2F5T18F3DFC8YY","pid":1246}
4892025-01-29T05:18:56.094Z{"msg":"aabd67c9-c40f-46d7-af73-3f2fd95245c1 active request set","v":0,"name":"crucible","level":30,"time":"2025-01-29T05:18:54.93026659Z","hostname":"w-01JJR7GCCH0R2F5T18F3DFC8YY","pid":1246,"session_id":"041f7efc-ed37-46d8-99c9-df961754a65a"}
4902025-01-29T05:18:56.094Z{"msg":"sending connect oneshot to client","v":0,"name":"crucible","level":30,"time":"2025-01-29T05:18:54.930338703Z","hostname":"w-01JJR7GCCH0R2F5T18F3DFC8YY","pid":1246,"client":"0","":"downstairs","session_id":"041f7efc-ed37-46d8-99c9-df961754a65a"}
4912025-01-29T05:18:56.094Z{"msg":"client set_active_request while in Connecting { state: Start { auto_promote: true }, mode: New }; waiting...","v":0,"name":"crucible","level":30,"time":"2025-01-29T05:18:54.930393477Z","hostname":"w-01JJR7GCCH0R2F5T18F3DFC8YY","pid":1246,"client":"0","":"downstairs","session_id":"041f7efc-ed37-46d8-99c9-df961754a65a"}
4922025-01-29T05:18:56.094Z{"msg":"sending connect oneshot to client","v":0,"name":"crucible","level":30,"time":"2025-01-29T05:18:54.930429313Z","hostname":"w-01JJR7GCCH0R2F5T18F3DFC8YY","pid":1246,"client":"1","":"downstairs","session_id":"041f7efc-ed37-46d8-99c9-df961754a65a"}
4932025-01-29T05:18:56.094Z{"msg":"client set_active_request while in Connecting { state: Start { auto_promote: true }, mode: New }; waiting...","v":0,"name":"crucible","level":30,"time":"2025-01-29T05:18:54.93045379Z","hostname":"w-01JJR7GCCH0R2F5T18F3DFC8YY","pid":1246,"client":"1","":"downstairs","session_id":"041f7efc-ed37-46d8-99c9-df961754a65a"}
4942025-01-29T05:18:56.094Z{"msg":"sending connect oneshot to client","v":0,"name":"crucible","level":30,"time":"2025-01-29T05:18:54.930489896Z","hostname":"w-01JJR7GCCH0R2F5T18F3DFC8YY","pid":1246,"client":"2","":"downstairs","session_id":"041f7efc-ed37-46d8-99c9-df961754a65a"}
4952025-01-29T05:18:56.094Z{"msg":"client set_active_request while in Connecting { state: Start { auto_promote: true }, mode: New }; waiting...","v":0,"name":"crucible","level":30,"time":"2025-01-29T05:18:54.930508324Z","hostname":"w-01JJR7GCCH0R2F5T18F3DFC8YY","pid":1246,"client":"2","":"downstairs","session_id":"041f7efc-ed37-46d8-99c9-df961754a65a"}
4962025-01-29T05:18:56.094Z{"msg":"connecting to 127.0.0.1:8830","v":0,"name":"crucible","level":30,"time":"2025-01-29T05:18:54.930543771Z","hostname":"w-01JJR7GCCH0R2F5T18F3DFC8YY","pid":1246,"":"io task","client":"2","":"downstairs","session_id":"041f7efc-ed37-46d8-99c9-df961754a65a"}
4972025-01-29T05:18:56.094Z{"msg":"connecting to 127.0.0.1:8810","v":0,"name":"crucible","level":30,"time":"2025-01-29T05:18:54.930574677Z","hostname":"w-01JJR7GCCH0R2F5T18F3DFC8YY","pid":1246,"":"io task","client":"0","":"downstairs","session_id":"041f7efc-ed37-46d8-99c9-df961754a65a"}
4982025-01-29T05:18:56.095Z{"msg":"connecting to 127.0.0.1:8820","v":0,"name":"crucible","level":30,"time":"2025-01-29T05:18:54.930597015Z","hostname":"w-01JJR7GCCH0R2F5T18F3DFC8YY","pid":1246,"":"io task","client":"1","":"downstairs","session_id":"041f7efc-ed37-46d8-99c9-df961754a65a"}
4992025-01-29T05:18:56.095Z{"msg":"ds_connection connected from Ok(127.0.0.1:39152)","v":0,"name":"crucible","level":30,"time":"2025-01-29T05:18:54.930628422Z","hostname":"w-01JJR7GCCH0R2F5T18F3DFC8YY","pid":1246,"":"io task","client":"0","":"downstairs","session_id":"041f7efc-ed37-46d8-99c9-df961754a65a"}
5002025-01-29T05:18:56.095Z{"msg":"ds_connection connected from Ok(127.0.0.1:59015)","v":0,"name":"crucible","level":30,"time":"2025-01-29T05:18:54.930652109Z","hostname":"w-01JJR7GCCH0R2F5T18F3DFC8YY","pid":1246,"":"io task","client":"1","":"downstairs","session_id":"041f7efc-ed37-46d8-99c9-df961754a65a"}
5012025-01-29T05:18:56.095Z{"msg":"ds_connection connect to 127.0.0.1:8830 failure: Os { code: 146, kind: ConnectionRefused, message: \"Connection refused\" }","v":0,"name":"crucible","level":40,"time":"2025-01-29T05:18:54.930699254Z","hostname":"w-01JJR7GCCH0R2F5T18F3DFC8YY","pid":1246,"":"io task","client":"2","":"downstairs","session_id":"041f7efc-ed37-46d8-99c9-df961754a65a"}
5022025-01-29T05:18:56.095Z{"msg":"client task is sending Done(ConnectionFailed(Os { code: 146, kind: ConnectionRefused, message: \"Connection refused\" }))","v":0,"name":"crucible","level":40,"time":"2025-01-29T05:18:54.930794593Z","hostname":"w-01JJR7GCCH0R2F5T18F3DFC8YY","pid":1246,"":"io task","client":"2","":"downstairs","session_id":"041f7efc-ed37-46d8-99c9-df961754a65a"}
5032025-01-29T05:18:56.095Z{"msg":"downstairs task for 2 stopped due to ConnectionFailed(Os { code: 146, kind: ConnectionRefused, message: \"Connection refused\" })","v":0,"name":"crucible","level":40,"time":"2025-01-29T05:18:54.930816601Z","hostname":"w-01JJR7GCCH0R2F5T18F3DFC8YY","pid":1246,"session_id":"041f7efc-ed37-46d8-99c9-df961754a65a"}
5042025-01-29T05:18:56.095Z{"msg":"client task is exiting","v":0,"name":"crucible","level":30,"time":"2025-01-29T05:18:54.93083014Z","hostname":"w-01JJR7GCCH0R2F5T18F3DFC8YY","pid":1246,"":"io task","client":"2","":"downstairs","session_id":"041f7efc-ed37-46d8-99c9-df961754a65a"}
5052025-01-29T05:18:56.095Z{"msg":"version negotiation from state Connecting { state: WaitForPromote, mode: New }","v":0,"name":"crucible","level":30,"time":"2025-01-29T05:18:54.931359943Z","hostname":"w-01JJR7GCCH0R2F5T18F3DFC8YY","pid":1246,"client":"1","":"downstairs","session_id":"041f7efc-ed37-46d8-99c9-df961754a65a"}
5062025-01-29T05:18:56.095Z{"msg":"version negotiation from state Connecting { state: WaitForPromote, mode: New }","v":0,"name":"crucible","level":30,"time":"2025-01-29T05:18:54.931396759Z","hostname":"w-01JJR7GCCH0R2F5T18F3DFC8YY","pid":1246,"client":"0","":"downstairs","session_id":"041f7efc-ed37-46d8-99c9-df961754a65a"}
5072025-01-29T05:18:56.095Z{"msg":"downstairs client at Some(127.0.0.1:8810) has region UUID 12345678-0000-0000-0000-000000008810","v":0,"name":"crucible","level":30,"time":"2025-01-29T05:18:54.931973106Z","hostname":"w-01JJR7GCCH0R2F5T18F3DFC8YY","pid":1246,"client":"0","":"downstairs","session_id":"041f7efc-ed37-46d8-99c9-df961754a65a"}
5082025-01-29T05:18:56.095Z{"msg":"downstairs client at Some(127.0.0.1:8820) has region UUID 12345678-0000-0000-0000-000000008820","v":0,"name":"crucible","level":30,"time":"2025-01-29T05:18:54.932147088Z","hostname":"w-01JJR7GCCH0R2F5T18F3DFC8YY","pid":1246,"client":"1","":"downstairs","session_id":"041f7efc-ed37-46d8-99c9-df961754a65a"}
5092025-01-29T05:18:56.098Z{"msg":"Waiting for more clients to be ready","v":0,"name":"crucible","level":30,"time":"2025-01-29T05:18:54.932371963Z","hostname":"w-01JJR7GCCH0R2F5T18F3DFC8YY","pid":1246,"session_id":"041f7efc-ed37-46d8-99c9-df961754a65a"}
5102025-01-29T05:18:56.098Z{"msg":"Waiting for more clients to be ready","v":0,"name":"crucible","level":30,"time":"2025-01-29T05:18:54.932520567Z","hostname":"w-01JJR7GCCH0R2F5T18F3DFC8YY","pid":1246,"session_id":"041f7efc-ed37-46d8-99c9-df961754a65a"}
5112025-01-29T05:19:06.094Z{"msg":"connecting to 127.0.0.1:8830","v":0,"name":"crucible","level":30,"time":"2025-01-29T05:19:04.931399078Z","hostname":"w-01JJR7GCCH0R2F5T18F3DFC8YY","pid":1246,"":"io task","client":"2","":"downstairs","session_id":"041f7efc-ed37-46d8-99c9-df961754a65a"}
5122025-01-29T05:19:06.094Z{"msg":"ds_connection connected from Ok(127.0.0.1:43156)","v":0,"name":"crucible","level":30,"time":"2025-01-29T05:19:04.931573249Z","hostname":"w-01JJR7GCCH0R2F5T18F3DFC8YY","pid":1246,"":"io task","client":"2","":"downstairs","session_id":"041f7efc-ed37-46d8-99c9-df961754a65a"}
5132025-01-29T05:19:06.098Z{"msg":"version negotiation from state Connecting { state: WaitForPromote, mode: New }","v":0,"name":"crucible","level":30,"time":"2025-01-29T05:19:04.932908136Z","hostname":"w-01JJR7GCCH0R2F5T18F3DFC8YY","pid":1246,"client":"2","":"downstairs","session_id":"041f7efc-ed37-46d8-99c9-df961754a65a"}
5142025-01-29T05:19:06.098Z{"msg":"downstairs client at Some(127.0.0.1:8830) has region UUID 12345678-0000-0000-0000-000000008830","v":0,"name":"crucible","level":30,"time":"2025-01-29T05:19:04.933478284Z","hostname":"w-01JJR7GCCH0R2F5T18F3DFC8YY","pid":1246,"client":"2","":"downstairs","session_id":"041f7efc-ed37-46d8-99c9-df961754a65a"}
5152025-01-29T05:19:06.098Z{"msg":"[0]R flush_numbers: [3996, 3996, 3996, 3996, 3996]","v":0,"name":"crucible","level":30,"time":"2025-01-29T05:19:04.933882681Z","hostname":"w-01JJR7GCCH0R2F5T18F3DFC8YY","pid":1246,"":"downstairs","":"downstairs","session_id":"041f7efc-ed37-46d8-99c9-df961754a65a"}
5162025-01-29T05:19:06.098Z{"msg":"[0]R generation: [32, 32, 32, 32, 32]","v":0,"name":"crucible","level":30,"time":"2025-01-29T05:19:04.933916117Z","hostname":"w-01JJR7GCCH0R2F5T18F3DFC8YY","pid":1246,"":"downstairs","":"downstairs","session_id":"041f7efc-ed37-46d8-99c9-df961754a65a"}
5172025-01-29T05:19:06.098Z{"msg":"[0]R dirty: [false, false, false, false, false]","v":0,"name":"crucible","level":30,"time":"2025-01-29T05:19:04.933931605Z","hostname":"w-01JJR7GCCH0R2F5T18F3DFC8YY","pid":1246,"":"downstairs","":"downstairs","session_id":"041f7efc-ed37-46d8-99c9-df961754a65a"}
5182025-01-29T05:19:06.098Z{"msg":"[1]R flush_numbers: [3996, 3996, 3996, 3996, 3996]","v":0,"name":"crucible","level":30,"time":"2025-01-29T05:19:04.933953343Z","hostname":"w-01JJR7GCCH0R2F5T18F3DFC8YY","pid":1246,"":"downstairs","":"downstairs","session_id":"041f7efc-ed37-46d8-99c9-df961754a65a"}
5192025-01-29T05:19:06.098Z{"msg":"[1]R generation: [32, 32, 32, 32, 32]","v":0,"name":"crucible","level":30,"time":"2025-01-29T05:19:04.933968121Z","hostname":"w-01JJR7GCCH0R2F5T18F3DFC8YY","pid":1246,"":"downstairs","":"downstairs","session_id":"041f7efc-ed37-46d8-99c9-df961754a65a"}
5202025-01-29T05:19:06.098Z{"msg":"[1]R dirty: [false, false, false, false, false]","v":0,"name":"crucible","level":30,"time":"2025-01-29T05:19:04.933988419Z","hostname":"w-01JJR7GCCH0R2F5T18F3DFC8YY","pid":1246,"":"downstairs","":"downstairs","session_id":"041f7efc-ed37-46d8-99c9-df961754a65a"}
5212025-01-29T05:19:06.098Z{"msg":"[2]R flush_numbers: [3995, 3995, 3995, 3995, 3995]","v":0,"name":"crucible","level":30,"time":"2025-01-29T05:19:04.934024215Z","hostname":"w-01JJR7GCCH0R2F5T18F3DFC8YY","pid":1246,"":"downstairs","":"downstairs","session_id":"041f7efc-ed37-46d8-99c9-df961754a65a"}
5222025-01-29T05:19:06.099Z{"msg":"[2]R generation: [31, 31, 31, 31, 31]","v":0,"name":"crucible","level":30,"time":"2025-01-29T05:19:04.934038664Z","hostname":"w-01JJR7GCCH0R2F5T18F3DFC8YY","pid":1246,"":"downstairs","":"downstairs","session_id":"041f7efc-ed37-46d8-99c9-df961754a65a"}
5232025-01-29T05:19:06.099Z{"msg":"[2]R dirty: [false, false, false, false, false]","v":0,"name":"crucible","level":30,"time":"2025-01-29T05:19:04.934052302Z","hostname":"w-01JJR7GCCH0R2F5T18F3DFC8YY","pid":1246,"":"downstairs","":"downstairs","session_id":"041f7efc-ed37-46d8-99c9-df961754a65a"}
5242025-01-29T05:19:06.099Z{"msg":"Max found gen is 33","v":0,"name":"crucible","level":30,"time":"2025-01-29T05:19:04.934065181Z","hostname":"w-01JJR7GCCH0R2F5T18F3DFC8YY","pid":1246,"":"downstairs","":"downstairs","session_id":"041f7efc-ed37-46d8-99c9-df961754a65a"}
5252025-01-29T05:19:06.099Z{"msg":"Generation requested: 33 >= found:33","v":0,"name":"crucible","level":30,"time":"2025-01-29T05:19:04.934079869Z","hostname":"w-01JJR7GCCH0R2F5T18F3DFC8YY","pid":1246,"":"downstairs","":"downstairs","session_id":"041f7efc-ed37-46d8-99c9-df961754a65a"}
5262025-01-29T05:19:06.099Z{"msg":"Next flush: 3997","v":0,"name":"crucible","level":30,"time":"2025-01-29T05:19:04.934100387Z","hostname":"w-01JJR7GCCH0R2F5T18F3DFC8YY","pid":1246,"":"downstairs","":"downstairs","session_id":"041f7efc-ed37-46d8-99c9-df961754a65a"}
5272025-01-29T05:19:06.099Z{"msg":"extent 0 needs reconciliation: ExtentMetadata { gen: 32, flush: 3996, dirty: false } ExtentMetadata { gen: 32, flush: 3996, dirty: false } ExtentMetadata { gen: 31, flush: 3995, dirty: false }","v":0,"name":"crucible","level":30,"time":"2025-01-29T05:19:04.934115935Z","hostname":"w-01JJR7GCCH0R2F5T18F3DFC8YY","pid":1246,"":"mend","":"downstairs","":"downstairs","session_id":"041f7efc-ed37-46d8-99c9-df961754a65a"}
5282025-01-29T05:19:06.099Z{"msg":"extent:0 [ExtentMetadata { gen: 32, flush: 3996, dirty: false }, ExtentMetadata { gen: 32, flush: 3996, dirty: false }, ExtentMetadata { gen: 31, flush: 3995, dirty: false }] => 0","v":0,"name":"crucible","level":30,"time":"2025-01-29T05:19:04.934139303Z","hostname":"w-01JJR7GCCH0R2F5T18F3DFC8YY","pid":1246,"":"mend","":"downstairs","":"downstairs","session_id":"041f7efc-ed37-46d8-99c9-df961754a65a"}
5292025-01-29T05:19:06.099Z{"msg":"found dest for source 0 for extent at index 0 => [ClientId(2)]","v":0,"name":"crucible","level":30,"time":"2025-01-29T05:19:04.934154061Z","hostname":"w-01JJR7GCCH0R2F5T18F3DFC8YY","pid":1246,"":"mend","":"downstairs","":"downstairs","session_id":"041f7efc-ed37-46d8-99c9-df961754a65a"}
5302025-01-29T05:19:06.099Z{"msg":"extent 1 needs reconciliation: ExtentMetadata { gen: 32, flush: 3996, dirty: false } ExtentMetadata { gen: 32, flush: 3996, dirty: false } ExtentMetadata { gen: 31, flush: 3995, dirty: false }","v":0,"name":"crucible","level":30,"time":"2025-01-29T05:19:04.934176589Z","hostname":"w-01JJR7GCCH0R2F5T18F3DFC8YY","pid":1246,"":"mend","":"downstairs","":"downstairs","session_id":"041f7efc-ed37-46d8-99c9-df961754a65a"}
5312025-01-29T05:19:06.099Z{"msg":"extent:0 [ExtentMetadata { gen: 32, flush: 3996, dirty: false }, ExtentMetadata { gen: 32, flush: 3996, dirty: false }, ExtentMetadata { gen: 31, flush: 3995, dirty: false }] => 0","v":0,"name":"crucible","level":30,"time":"2025-01-29T05:19:04.934192177Z","hostname":"w-01JJR7GCCH0R2F5T18F3DFC8YY","pid":1246,"":"mend","":"downstairs","":"downstairs","session_id":"041f7efc-ed37-46d8-99c9-df961754a65a"}
5322025-01-29T05:19:06.099Z{"msg":"found dest for source 0 for extent at index 1 => [ClientId(2)]","v":0,"name":"crucible","level":30,"time":"2025-01-29T05:19:04.934205976Z","hostname":"w-01JJR7GCCH0R2F5T18F3DFC8YY","pid":1246,"":"mend","":"downstairs","":"downstairs","session_id":"041f7efc-ed37-46d8-99c9-df961754a65a"}
5332025-01-29T05:19:06.099Z{"msg":"extent 2 needs reconciliation: ExtentMetadata { gen: 32, flush: 3996, dirty: false } ExtentMetadata { gen: 32, flush: 3996, dirty: false } ExtentMetadata { gen: 31, flush: 3995, dirty: false }","v":0,"name":"crucible","level":30,"time":"2025-01-29T05:19:04.934221874Z","hostname":"w-01JJR7GCCH0R2F5T18F3DFC8YY","pid":1246,"":"mend","":"downstairs","":"downstairs","session_id":"041f7efc-ed37-46d8-99c9-df961754a65a"}
5342025-01-29T05:19:06.099Z{"msg":"extent:0 [ExtentMetadata { gen: 32, flush: 3996, dirty: false }, ExtentMetadata { gen: 32, flush: 3996, dirty: false }, ExtentMetadata { gen: 31, flush: 3995, dirty: false }] => 0","v":0,"name":"crucible","level":30,"time":"2025-01-29T05:19:04.934252421Z","hostname":"w-01JJR7GCCH0R2F5T18F3DFC8YY","pid":1246,"":"mend","":"downstairs","":"downstairs","session_id":"041f7efc-ed37-46d8-99c9-df961754a65a"}
5352025-01-29T05:19:06.099Z{"msg":"found dest for source 0 for extent at index 2 => [ClientId(2)]","v":0,"name":"crucible","level":30,"time":"2025-01-29T05:19:04.934267929Z","hostname":"w-01JJR7GCCH0R2F5T18F3DFC8YY","pid":1246,"":"mend","":"downstairs","":"downstairs","session_id":"041f7efc-ed37-46d8-99c9-df961754a65a"}
5362025-01-29T05:19:06.099Z{"msg":"extent 3 needs reconciliation: ExtentMetadata { gen: 32, flush: 3996, dirty: false } ExtentMetadata { gen: 32, flush: 3996, dirty: false } ExtentMetadata { gen: 31, flush: 3995, dirty: false }","v":0,"name":"crucible","level":30,"time":"2025-01-29T05:19:04.934290947Z","hostname":"w-01JJR7GCCH0R2F5T18F3DFC8YY","pid":1246,"":"mend","":"downstairs","":"downstairs","session_id":"041f7efc-ed37-46d8-99c9-df961754a65a"}
5372025-01-29T05:19:06.099Z{"msg":"extent:0 [ExtentMetadata { gen: 32, flush: 3996, dirty: false }, ExtentMetadata { gen: 32, flush: 3996, dirty: false }, ExtentMetadata { gen: 31, flush: 3995, dirty: false }] => 0","v":0,"name":"crucible","level":30,"time":"2025-01-29T05:19:04.934306705Z","hostname":"w-01JJR7GCCH0R2F5T18F3DFC8YY","pid":1246,"":"mend","":"downstairs","":"downstairs","session_id":"041f7efc-ed37-46d8-99c9-df961754a65a"}
5382025-01-29T05:19:06.099Z{"msg":"found dest for source 0 for extent at index 3 => [ClientId(2)]","v":0,"name":"crucible","level":30,"time":"2025-01-29T05:19:04.934326803Z","hostname":"w-01JJR7GCCH0R2F5T18F3DFC8YY","pid":1246,"":"mend","":"downstairs","":"downstairs","session_id":"041f7efc-ed37-46d8-99c9-df961754a65a"}
5392025-01-29T05:19:06.099Z{"msg":"extent 4 needs reconciliation: ExtentMetadata { gen: 32, flush: 3996, dirty: false } ExtentMetadata { gen: 32, flush: 3996, dirty: false } ExtentMetadata { gen: 31, flush: 3995, dirty: false }","v":0,"name":"crucible","level":30,"time":"2025-01-29T05:19:04.934343121Z","hostname":"w-01JJR7GCCH0R2F5T18F3DFC8YY","pid":1246,"":"mend","":"downstairs","":"downstairs","session_id":"041f7efc-ed37-46d8-99c9-df961754a65a"}
5402025-01-29T05:19:06.099Z{"msg":"extent:0 [ExtentMetadata { gen: 32, flush: 3996, dirty: false }, ExtentMetadata { gen: 32, flush: 3996, dirty: false }, ExtentMetadata { gen: 31, flush: 3995, dirty: false }] => 0","v":0,"name":"crucible","level":30,"time":"2025-01-29T05:19:04.934365539Z","hostname":"w-01JJR7GCCH0R2F5T18F3DFC8YY","pid":1246,"":"mend","":"downstairs","":"downstairs","session_id":"041f7efc-ed37-46d8-99c9-df961754a65a"}
5412025-01-29T05:19:06.099Z{"msg":"found dest for source 0 for extent at index 4 => [ClientId(2)]","v":0,"name":"crucible","level":30,"time":"2025-01-29T05:19:04.934379357Z","hostname":"w-01JJR7GCCH0R2F5T18F3DFC8YY","pid":1246,"":"mend","":"downstairs","":"downstairs","session_id":"041f7efc-ed37-46d8-99c9-df961754a65a"}
5422025-01-29T05:19:06.099Z{"msg":"Transition from Connecting { state: WaitQuorum, mode: New } to Reconcile","v":0,"name":"crucible","level":30,"time":"2025-01-29T05:19:04.934407644Z","hostname":"w-01JJR7GCCH0R2F5T18F3DFC8YY","pid":1246,"client":"0","":"downstairs","session_id":"041f7efc-ed37-46d8-99c9-df961754a65a"}
5432025-01-29T05:19:06.099Z{"msg":"Transition from Connecting { state: WaitQuorum, mode: New } to Reconcile","v":0,"name":"crucible","level":30,"time":"2025-01-29T05:19:04.934430821Z","hostname":"w-01JJR7GCCH0R2F5T18F3DFC8YY","pid":1246,"client":"1","":"downstairs","session_id":"041f7efc-ed37-46d8-99c9-df961754a65a"}
5442025-01-29T05:19:06.099Z{"msg":"Transition from Connecting { state: WaitQuorum, mode: New } to Reconcile","v":0,"name":"crucible","level":30,"time":"2025-01-29T05:19:04.934495985Z","hostname":"w-01JJR7GCCH0R2F5T18F3DFC8YY","pid":1246,"client":"2","":"downstairs","session_id":"041f7efc-ed37-46d8-99c9-df961754a65a"}
5452025-01-29T05:19:06.099Z{"msg":"Full repair list: {ExtentId(1): ExtentFix { source: ClientId(0), dest: [ClientId(2)] }, ExtentId(2): ExtentFix { source: ClientId(0), dest: [ClientId(2)] }, ExtentId(0): ExtentFix { source: ClientId(0), dest: [ClientId(2)] }, ExtentId(3): ExtentFix { source: ClientId(0), dest: [ClientId(2)] }, ExtentId(4): ExtentFix { source: ClientId(0), dest: [ClientId(2)] }}","v":0,"name":"crucible","level":30,"time":"2025-01-29T05:19:04.934525171Z","hostname":"w-01JJR7GCCH0R2F5T18F3DFC8YY","pid":1246,"":"downstairs","":"downstairs","session_id":"041f7efc-ed37-46d8-99c9-df961754a65a"}
5462025-01-29T05:19:06.102Z{"msg":"Task list: [ReconcileIO { id: ReconciliationId(0), op: ExtentFlush { repair_id: ReconciliationId(0), extent_id: ExtentId(1), client_id: ClientId(0), flush_number: 3997, gen_number: 33 }, state: ClientData([New, New, New]) }, ReconcileIO { id: ReconciliationId(1), op: ExtentClose { repair_id: ReconciliationId(1), extent_id: ExtentId(1) }, state: ClientData([New, New, New]) }, ReconcileIO { id: ReconciliationId(2), op: ExtentRepair { repair_id: ReconciliationId(2), extent_id: ExtentId(1), source_client_id: ClientId(0), source_repair_address: 0.0.0.0:12810, dest_clients: [ClientId(2)] }, state: ClientData([New, New, New]) }, ReconcileIO { id: ReconciliationId(3), op: ExtentReopen { repair_id: ReconciliationId(3), extent_id: ExtentId(1) }, state: ClientData([New, New, New]) }, ReconcileIO { id: ReconciliationId(4), op: ExtentFlush { repair_id: ReconciliationId(4), extent_id: ExtentId(2), client_id: ClientId(0), flush_number: 3997, gen_number: 33 }, state: ClientData([New, New, New]) }, ReconcileIO { id: ReconciliationId(5), op: ExtentClose { repair_id: ReconciliationId(5), extent_id: ExtentId(2) }, state: ClientData([New, New, New]) }, ReconcileIO { id: ReconciliationId(6), op: ExtentRepair { repair_id: ReconciliationId(6), 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(7), op: ExtentReopen { repair_id: ReconciliationId(7), extent_id: ExtentId(2) }, state: ClientData([New, New, New]) }, ReconcileIO { id: ReconciliationId(8), op: ExtentFlush { repair_id: ReconciliationId(8), extent_id: ExtentId(0), client_id: ClientId(0), flush_number: 3997, gen_number: 33 }, state: ClientData([New, New, New]) }, ReconcileIO { id: ReconciliationId(9), op: ExtentClose { repair_id: ReconciliationId(9), extent_id: ExtentId(0) }, state: ClientData([New, New, New]) }, ReconcileIO { id: ReconciliationId(10), op: ExtentRepair { repair_id: ReconciliationId(10), extent_id: ExtentId(0), source_client_id: ClientId(0), source_repair_address: 0.0.0.0:12810, dest_clients: [ClientId(2)] }, state: ClientData([New, New, New]) }, ReconcileIO { id: ReconciliationId(11), op: ExtentReopen { repair_id: ReconciliationId(11), extent_id: ExtentId(0) }, state: ClientData([New, New, New]) }, ReconcileIO { id: ReconciliationId(12), op: ExtentFlush { repair_id: ReconciliationId(12), extent_id: ExtentId(3), client_id: ClientId(0), flush_number: 3997, gen_number: 33 }, state: ClientData([New, New, New]) }, ReconcileIO { id: ReconciliationId(13), op: ExtentClose { repair_id: ReconciliationId(13), extent_id: ExtentId(3) }, state: ClientData([New, New, New]) }, ReconcileIO { id: ReconciliationId(14), op: ExtentRepair { repair_id: ReconciliationId(14), extent_id: ExtentId(3), source_client_id: ClientId(0), source_repair_address: 0.0.0.0:12810, dest_clients: [ClientId(2)] }, state: ClientData([New, New, New]) }, ReconcileIO { id: ReconciliationId(15), op: ExtentReopen { repair_id: ReconciliationId(15), extent_id: ExtentId(3) }, state: ClientData([New, New, New]) }, ReconcileIO { id: ReconciliationId(16), op: ExtentFlush { repair_id: ReconciliationId(16), extent_id: ExtentId(4), client_id: ClientId(0), flush_number: 3997, gen_number: 33 }, state: ClientData([New, New, New]) }, ReconcileIO { id: ReconciliationId(17), op: ExtentClose { repair_id: ReconciliationId(17), extent_id: ExtentId(4) }, state: ClientData([New, New, New]) }, ReconcileIO { id: ReconciliationId(18), op: ExtentRepair { repair_id: ReconciliationId(18), extent_id: ExtentId(4), source_client_id: ClientId(0), source_repair_address: 0.0.0.0:12810, dest_clients: [ClientId(2)] }, state: ClientData([New, New, New]) }, ReconcileIO { id: ReconciliationId(19), op: ExtentReopen { repair_id: ReconciliationId(19), extent_id: ExtentId(4) }, state: ClientData([New, New, New]) }]","v":0,"name":"crucible","level":30,"time":"2025-01-29T05:19:04.934661527Z","hostname":"w-01JJR7GCCH0R2F5T18F3DFC8YY","pid":1246,"":"downstairs","":"downstairs","session_id":"041f7efc-ed37-46d8-99c9-df961754a65a"}
5472025-01-29T05:19:06.102Z{"msg":"starting reconciliation b63d27f6-cb27-4a9e-94a0-af9b59910d76: found 20 extents that need repair","v":0,"name":"crucible","level":30,"time":"2025-01-29T05:19:04.934711181Z","hostname":"w-01JJR7GCCH0R2F5T18F3DFC8YY","pid":1246,"":"downstairs","":"downstairs","session_id":"041f7efc-ed37-46d8-99c9-df961754a65a"}
5482025-01-29T05:19:06.102Z{"msg":"sending reconcile request ReconciliationId(2)","v":0,"name":"crucible","level":30,"time":"2025-01-29T05:19:04.934871274Z","hostname":"w-01JJR7GCCH0R2F5T18F3DFC8YY","pid":1246,"client":"2","":"downstairs","session_id":"041f7efc-ed37-46d8-99c9-df961754a65a"}
5492025-01-29T05:19:06.106Z{"msg":"sending reconcile request ReconciliationId(6)","v":0,"name":"crucible","level":30,"time":"2025-01-29T05:19:04.943741998Z","hostname":"w-01JJR7GCCH0R2F5T18F3DFC8YY","pid":1246,"client":"2","":"downstairs","session_id":"041f7efc-ed37-46d8-99c9-df961754a65a"}
5502025-01-29T05:19:06.111Z{"msg":"sending reconcile request ReconciliationId(10)","v":0,"name":"crucible","level":30,"time":"2025-01-29T05:19:04.947635248Z","hostname":"w-01JJR7GCCH0R2F5T18F3DFC8YY","pid":1246,"client":"2","":"downstairs","session_id":"041f7efc-ed37-46d8-99c9-df961754a65a"}
5512025-01-29T05:19:06.114Z{"msg":"sending reconcile request ReconciliationId(14)","v":0,"name":"crucible","level":30,"time":"2025-01-29T05:19:04.951454527Z","hostname":"w-01JJR7GCCH0R2F5T18F3DFC8YY","pid":1246,"client":"2","":"downstairs","session_id":"041f7efc-ed37-46d8-99c9-df961754a65a"}
5522025-01-29T05:19:06.117Z{"msg":"sending reconcile request ReconciliationId(18)","v":0,"name":"crucible","level":30,"time":"2025-01-29T05:19:04.955154328Z","hostname":"w-01JJR7GCCH0R2F5T18F3DFC8YY","pid":1246,"client":"2","":"downstairs","session_id":"041f7efc-ed37-46d8-99c9-df961754a65a"}
5532025-01-29T05:19:06.120Z{"msg":"done with reconciliation","v":0,"name":"crucible","level":30,"time":"2025-01-29T05:19:04.95828977Z","hostname":"w-01JJR7GCCH0R2F5T18F3DFC8YY","pid":1246,"":"downstairs","":"downstairs","session_id":"041f7efc-ed37-46d8-99c9-df961754a65a"}
5542025-01-29T05:19:06.120Z{"msg":"Transition from Reconcile to Active","v":0,"name":"crucible","level":30,"time":"2025-01-29T05:19:04.958328806Z","hostname":"w-01JJR7GCCH0R2F5T18F3DFC8YY","pid":1246,"client":"0","":"downstairs","session_id":"041f7efc-ed37-46d8-99c9-df961754a65a"}
5552025-01-29T05:19:06.123Z{"msg":"Transition from Reconcile to Active","v":0,"name":"crucible","level":30,"time":"2025-01-29T05:19:04.958345804Z","hostname":"w-01JJR7GCCH0R2F5T18F3DFC8YY","pid":1246,"client":"1","":"downstairs","session_id":"041f7efc-ed37-46d8-99c9-df961754a65a"}
5562025-01-29T05:19:06.123Z{"msg":"Transition from Reconcile to Active","v":0,"name":"crucible","level":30,"time":"2025-01-29T05:19:04.958369412Z","hostname":"w-01JJR7GCCH0R2F5T18F3DFC8YY","pid":1246,"client":"2","":"downstairs","session_id":"041f7efc-ed37-46d8-99c9-df961754a65a"}
5572025-01-29T05:19:06.123Z{"msg":"All required reconciliation work is completed","v":0,"name":"crucible","level":30,"time":"2025-01-29T05:19:04.95838453Z","hostname":"w-01JJR7GCCH0R2F5T18F3DFC8YY","pid":1246,"session_id":"041f7efc-ed37-46d8-99c9-df961754a65a"}
5582025-01-29T05:19:06.123Z{"msg":"Set Downstairs and Upstairs active after reconciliation","v":0,"name":"crucible","level":30,"time":"2025-01-29T05:19:04.958400168Z","hostname":"w-01JJR7GCCH0R2F5T18F3DFC8YY","pid":1246,"session_id":"041f7efc-ed37-46d8-99c9-df961754a65a"}
5592025-01-29T05:19:06.124Z{"msg":"aabd67c9-c40f-46d7-af73-3f2fd95245c1 is now active with session: 041f7efc-ed37-46d8-99c9-df961754a65a","v":0,"name":"crucible","level":30,"time":"2025-01-29T05:19:04.958418936Z","hostname":"w-01JJR7GCCH0R2F5T18F3DFC8YY","pid":1246,"session_id":"041f7efc-ed37-46d8-99c9-df961754a65a"}
5602025-01-29T05:19:06.124Z{"msg":"The guest has finished waiting for activation with:33","v":0,"name":"crucible","level":30,"time":"2025-01-29T05:19:04.958432035Z","hostname":"w-01JJR7GCCH0R2F5T18F3DFC8YY","pid":1246}
5612025-01-29T05:19:06.124Z{"msg":"The guest has requested activation with gen:33","v":0,"name":"crucible","level":30,"time":"2025-01-29T05:19:04.958443833Z","hostname":"w-01JJR7GCCH0R2F5T18F3DFC8YY","pid":1246}
5622025-01-29T05:19:06.124Z{"msg":"aabd67c9-c40f-46d7-af73-3f2fd95245c1 active request set","v":0,"name":"crucible","level":30,"time":"2025-01-29T05:19:04.958464921Z","hostname":"w-01JJR7GCCH0R2F5T18F3DFC8YY","pid":1246,"session_id":"a6fd3390-f12a-4723-9426-0dc6961f280a"}
5632025-01-29T05:19:06.124Z{"msg":"sending connect oneshot to client","v":0,"name":"crucible","level":30,"time":"2025-01-29T05:19:04.95847773Z","hostname":"w-01JJR7GCCH0R2F5T18F3DFC8YY","pid":1246,"client":"0","":"downstairs","session_id":"a6fd3390-f12a-4723-9426-0dc6961f280a"}
5642025-01-29T05:19:06.124Z{"msg":"client set_active_request while in Connecting { state: Start { auto_promote: true }, mode: New }; waiting...","v":0,"name":"crucible","level":30,"time":"2025-01-29T05:19:04.958492058Z","hostname":"w-01JJR7GCCH0R2F5T18F3DFC8YY","pid":1246,"client":"0","":"downstairs","session_id":"a6fd3390-f12a-4723-9426-0dc6961f280a"}
5652025-01-29T05:19:06.124Z{"msg":"sending connect oneshot to client","v":0,"name":"crucible","level":30,"time":"2025-01-29T05:19:04.958516856Z","hostname":"w-01JJR7GCCH0R2F5T18F3DFC8YY","pid":1246,"client":"1","":"downstairs","session_id":"a6fd3390-f12a-4723-9426-0dc6961f280a"}
5662025-01-29T05:19:06.124Z{"msg":"client set_active_request while in Connecting { state: Start { auto_promote: true }, mode: New }; waiting...","v":0,"name":"crucible","level":30,"time":"2025-01-29T05:19:04.958542873Z","hostname":"w-01JJR7GCCH0R2F5T18F3DFC8YY","pid":1246,"client":"1","":"downstairs","session_id":"a6fd3390-f12a-4723-9426-0dc6961f280a"}
5672025-01-29T05:19:06.124Z{"msg":"sending connect oneshot to client","v":0,"name":"crucible","level":30,"time":"2025-01-29T05:19:04.958598507Z","hostname":"w-01JJR7GCCH0R2F5T18F3DFC8YY","pid":1246,"client":"2","":"downstairs","session_id":"a6fd3390-f12a-4723-9426-0dc6961f280a"}
5682025-01-29T05:19:06.124Z{"msg":"client set_active_request while in Connecting { state: Start { auto_promote: true }, mode: New }; waiting...","v":0,"name":"crucible","level":30,"time":"2025-01-29T05:19:04.958625904Z","hostname":"w-01JJR7GCCH0R2F5T18F3DFC8YY","pid":1246,"client":"2","":"downstairs","session_id":"a6fd3390-f12a-4723-9426-0dc6961f280a"}
5692025-01-29T05:19:06.124Z{"msg":"connecting to 127.0.0.1:8860","v":0,"name":"crucible","level":30,"time":"2025-01-29T05:19:04.958647671Z","hostname":"w-01JJR7GCCH0R2F5T18F3DFC8YY","pid":1246,"":"io task","client":"2","":"downstairs","session_id":"a6fd3390-f12a-4723-9426-0dc6961f280a"}
5702025-01-29T05:19:06.124Z{"msg":"connecting to 127.0.0.1:8840","v":0,"name":"crucible","level":30,"time":"2025-01-29T05:19:04.958672369Z","hostname":"w-01JJR7GCCH0R2F5T18F3DFC8YY","pid":1246,"":"io task","client":"0","":"downstairs","session_id":"a6fd3390-f12a-4723-9426-0dc6961f280a"}
5712025-01-29T05:19:06.124Z{"msg":"connecting to 127.0.0.1:8850","v":0,"name":"crucible","level":30,"time":"2025-01-29T05:19:04.958696906Z","hostname":"w-01JJR7GCCH0R2F5T18F3DFC8YY","pid":1246,"":"io task","client":"1","":"downstairs","session_id":"a6fd3390-f12a-4723-9426-0dc6961f280a"}
5722025-01-29T05:19:06.124Z{"msg":"ds_connection connected from Ok(127.0.0.1:52612)","v":0,"name":"crucible","level":30,"time":"2025-01-29T05:19:04.958724033Z","hostname":"w-01JJR7GCCH0R2F5T18F3DFC8YY","pid":1246,"":"io task","client":"2","":"downstairs","session_id":"a6fd3390-f12a-4723-9426-0dc6961f280a"}
5732025-01-29T05:19:06.124Z{"msg":"ds_connection connected from Ok(127.0.0.1:36445)","v":0,"name":"crucible","level":30,"time":"2025-01-29T05:19:04.95875333Z","hostname":"w-01JJR7GCCH0R2F5T18F3DFC8YY","pid":1246,"":"io task","client":"0","":"downstairs","session_id":"a6fd3390-f12a-4723-9426-0dc6961f280a"}
5742025-01-29T05:19:06.124Z{"msg":"ds_connection connected from Ok(127.0.0.1:48974)","v":0,"name":"crucible","level":30,"time":"2025-01-29T05:19:04.958781377Z","hostname":"w-01JJR7GCCH0R2F5T18F3DFC8YY","pid":1246,"":"io task","client":"1","":"downstairs","session_id":"a6fd3390-f12a-4723-9426-0dc6961f280a"}
5752025-01-29T05:19:06.124Z{"msg":"version negotiation from state Connecting { state: WaitForPromote, mode: New }","v":0,"name":"crucible","level":30,"time":"2025-01-29T05:19:04.959091444Z","hostname":"w-01JJR7GCCH0R2F5T18F3DFC8YY","pid":1246,"client":"1","":"downstairs","session_id":"a6fd3390-f12a-4723-9426-0dc6961f280a"}
5762025-01-29T05:19:06.124Z{"msg":"version negotiation from state Connecting { state: WaitForPromote, mode: New }","v":0,"name":"crucible","level":30,"time":"2025-01-29T05:19:04.959130879Z","hostname":"w-01JJR7GCCH0R2F5T18F3DFC8YY","pid":1246,"client":"2","":"downstairs","session_id":"a6fd3390-f12a-4723-9426-0dc6961f280a"}
5772025-01-29T05:19:06.125Z{"msg":"version negotiation from state Connecting { state: WaitForPromote, mode: New }","v":0,"name":"crucible","level":30,"time":"2025-01-29T05:19:04.959147118Z","hostname":"w-01JJR7GCCH0R2F5T18F3DFC8YY","pid":1246,"client":"0","":"downstairs","session_id":"a6fd3390-f12a-4723-9426-0dc6961f280a"}
5782025-01-29T05:19:06.125Z{"msg":"downstairs client at Some(127.0.0.1:8850) has region UUID 12345678-0000-0000-0000-000000008850","v":0,"name":"crucible","level":30,"time":"2025-01-29T05:19:04.959575791Z","hostname":"w-01JJR7GCCH0R2F5T18F3DFC8YY","pid":1246,"client":"1","":"downstairs","session_id":"a6fd3390-f12a-4723-9426-0dc6961f280a"}
5792025-01-29T05:19:06.125Z{"msg":"downstairs client at Some(127.0.0.1:8840) has region UUID 12345678-0000-0000-0000-000000008840","v":0,"name":"crucible","level":30,"time":"2025-01-29T05:19:04.959659352Z","hostname":"w-01JJR7GCCH0R2F5T18F3DFC8YY","pid":1246,"client":"0","":"downstairs","session_id":"a6fd3390-f12a-4723-9426-0dc6961f280a"}
5802025-01-29T05:19:06.125Z{"msg":"downstairs client at Some(127.0.0.1:8860) has region UUID 12345678-0000-0000-0000-000000008860","v":0,"name":"crucible","level":30,"time":"2025-01-29T05:19:04.959850592Z","hostname":"w-01JJR7GCCH0R2F5T18F3DFC8YY","pid":1246,"client":"2","":"downstairs","session_id":"a6fd3390-f12a-4723-9426-0dc6961f280a"}
5812025-01-29T05:19:06.125Z{"msg":"Waiting for more clients to be ready","v":0,"name":"crucible","level":30,"time":"2025-01-29T05:19:04.959922994Z","hostname":"w-01JJR7GCCH0R2F5T18F3DFC8YY","pid":1246,"session_id":"a6fd3390-f12a-4723-9426-0dc6961f280a"}
5822025-01-29T05:19:06.125Z{"msg":"Waiting for more clients to be ready","v":0,"name":"crucible","level":30,"time":"2025-01-29T05:19:04.959984877Z","hostname":"w-01JJR7GCCH0R2F5T18F3DFC8YY","pid":1246,"session_id":"a6fd3390-f12a-4723-9426-0dc6961f280a"}
5832025-01-29T05:19:06.125Z{"msg":"[0]R flush_numbers: [5316, 5316, 5316, 5316, 5316]","v":0,"name":"crucible","level":30,"time":"2025-01-29T05:19:04.960165408Z","hostname":"w-01JJR7GCCH0R2F5T18F3DFC8YY","pid":1246,"":"downstairs","":"downstairs","session_id":"a6fd3390-f12a-4723-9426-0dc6961f280a"}
5842025-01-29T05:19:06.125Z{"msg":"[0]R generation: [32, 32, 32, 32, 32]","v":0,"name":"crucible","level":30,"time":"2025-01-29T05:19:04.960212203Z","hostname":"w-01JJR7GCCH0R2F5T18F3DFC8YY","pid":1246,"":"downstairs","":"downstairs","session_id":"a6fd3390-f12a-4723-9426-0dc6961f280a"}
5852025-01-29T05:19:06.125Z{"msg":"[0]R dirty: [false, false, false, false, false]","v":0,"name":"crucible","level":30,"time":"2025-01-29T05:19:04.960244129Z","hostname":"w-01JJR7GCCH0R2F5T18F3DFC8YY","pid":1246,"":"Wait for a query_work_queue command to finish before sending IO
5862025-01-29T05:19:06.125Zdownstairs","":"downstairs","session_id":"a6fd3390-f12a-4723-9426-0dc6961f280a"}
5872025-01-29T05:19:06.125Z{"msg":"[1]R flush_numbers: [5316, 5316, 5316, 5316, 5316]","v":0,"name":"crucible","level":30,"time":"2025-01-29T05:19:04.960299293Z","hostname":"w-01JJR7GCCH0R2F5T18F3DFC8YY","pid":1246,"":"downstairs","":"downstairs","session_id":"a6fd3390-f12a-4723-9426-0dc6961f280a"}
5882025-01-29T05:19:06.125Z{"msg":"[1]R generation: [32, 32, 32, 32, 32]","v":0,"name":"crucible","level":30,"time":"2025-01-29T05:19:04.96033185Z","hostname":"w-01JJR7GCCH0R2F5T18F3DFC8YY","pid":1246,"":"downstairs","":"downstairs","session_id":"a6fd3390-f12a-4723-9426-0dc6961f280a"}
5892025-01-29T05:19:06.125Z{"msg":"[1]R dirty: [false, false, false, false, false]","v":0,"name":"crucible","level":30,"time":"2025-01-29T05:19:04.960347658Z","hostname":"w-01JJR7GCCH0R2F5T18F3DFC8YY","pid":1246,"":"downstairs","":"downstairs","session_id":"a6fd3390-f12a-4723-9426-0dc6961f280a"}
5902025-01-29T05:19:06.125Z{"msg":"[2]R flush_numbers: [5316, 5316, 5316, 5316, 5316]","v":0,"name":"crucible","level":30,"time":"2025-01-29T05:19:04.960362077Z","hostname":"w-01JJR7GCCH0R2F5T18F3DFC8YY","pid":1246,"":"downstairs","":"downstairs","session_id":"a6fd3390-f12a-4723-9426-0dc6961f280a"}
5912025-01-29T05:19:06.125Z{"msg":"[2]R generation: [32, 32, 32, 32, 32]","v":0,"name":"crucible","level":30,"time":"2025-01-29T05:19:04.960392983Z","hostname":"w-01JJR7GCCH0R2F5T18F3DFC8YY","pid":1246,"":"downstairs","":"downstairs","session_id":"a6fd3390-f12a-4723-9426-0dc6961f280a"}
5922025-01-29T05:19:06.125Z{"msg":"[2]R dirty: [false, false, false, false, false]","v":0,"name":"crucible","level":30,"time":"2025-01-29T05:19:04.960411421Z","hostname":"w-01JJR7GCCH0R2F5T18F3DFC8YY","pid":1246,"":"downstairs","":"downstairs","session_id":"a6fd3390-f12a-4723-9426-0dc6961f280a"}
5932025-01-29T05:19:06.125Z{"msg":"Max found gen is 33","v":0,"name":"crucible","level":30,"time":"2025-01-29T05:19:04.960440978Z","hostname":"w-01JJR7GCCH0R2F5T18F3DFC8YY","pid":1246,"":"downstairs","":"downstairs","session_id":"a6fd3390-f12a-4723-9426-0dc6961f280a"}
5942025-01-29T05:19:06.125Z{"msg":"Generation requested: 33 >= found:33","v":0,"name":"crucible","level":30,"time":"2025-01-29T05:19:04.960459626Z","hostname":"w-01JJR7GCCH0R2F5T18F3DFC8YY","pid":1246,"":"downstairs","":"downstairs","session_id":"a6fd3390-f12a-4723-9426-0dc6961f280a"}
5952025-01-29T05:19:06.125Z{"msg":"Next flush: 5317","v":0,"name":"crucible","level":30,"time":"2025-01-29T05:19:04.960488513Z","hostname":"w-01JJR7GCCH0R2F5T18F3DFC8YY","pid":1246,"":"downstairs","":"downstairs","session_id":"a6fd3390-f12a-4723-9426-0dc6961f280a"}
5962025-01-29T05:19:06.125Z{"msg":"All extents match","v":0,"name":"crucible","level":30,"time":"2025-01-29T05:19:04.960508581Z","hostname":"w-01JJR7GCCH0R2F5T18F3DFC8YY","pid":1246,"":"downstairs","":"downstairs","session_id":"a6fd3390-f12a-4723-9426-0dc6961f280a"}
5972025-01-29T05:19:06.125Z{"msg":"No downstairs reconciliation required","v":0,"name":"crucible","level":30,"time":"2025-01-29T05:19:04.960537288Z","hostname":"w-01JJR7GCCH0R2F5T18F3DFC8YY","pid":1246,"session_id":"a6fd3390-f12a-4723-9426-0dc6961f280a"}
5982025-01-29T05:19:06.125Z{"msg":"Transition from WaitQuorum to Active","v":0,"name":"crucible","level":30,"time":"2025-01-29T05:19:04.960554636Z","hostname":"w-01JJR7GCCH0R2F5T18F3DFC8YY","pid":1246,"client":"0","":"downstairs","session_id":"a6fd3390-f12a-4723-9426-0dc6961f280a"}
5992025-01-29T05:19:06.125ZDisk: sv:2 bs:4096 ts:409600 tb:100 max_io:100 or 409600
6002025-01-29T05:19:06.125Z{"msg":"Transition from WaitQuorum to Active","v":0,"name":"crucible","level":30,"time":"2025-01-29T05:19:04.960587582Z","hostname":"w-01JJR7GCCH0R2F5T18F3DFC8YY","pid":1246,"client":"1","":"downstairs","session_id":"a6fd3390-f12a-4723-9426-0dc6961f280a"}
6012025-01-29T05:19:06.125Z{"msg":"Transition from WaitQuorum to Active","v":0,"name":"crucible","level":30,"time":"2025-01-29T05:19:04.960619099Z","hostname":"w-01JJR7GCCH0R2F5T18F3DFC8YY","pid":1246,"client":"2","":"downstairs","session_id":"a6fd3390-f12a-4723-9426-0dc6961f280a"}
6022025-01-29T05:19:06.125Z{"msg":"All required reconciliation work is completed","v":0,"name":"crucible","level":30,"time":"2025-01-29T05:19:04.960651415Z","hostname":"w-01JJR7GCCH0R2F5T18F3DFC8YY","pid":1246,"session_id":"a6fd3390-f12a-4723-9426-0dc6961f280a"}
6032025-01-29T05:19:06.125Z{"msg":"Set Downstairs and Upstairs active after reconciliation","v":0,"name":"crucible","level":30,"time":"2025-01-29T05:19:04.960681772Z","hostname":"w-01JJR7GCCH0R2F5T18F3DFC8YY","pid":1246,"session_id":"a6fd3390-f12a-4723-9426-0dc6961f280a"}
6042025-01-29T05:19:06.125Z{"msg":"aabd67c9-c40f-46d7-af73-3f2fd95245c1 is now active with session: a6fd3390-f12a-4723-9426-0dc6961f280a","v":0,"name":"crucible","level":30,"time":"2025-01-29T05:19:04.960713359Z","hostname":"w-01JJR7GCCH0R2F5T18F3DFC8YY","pid":1246,"session_id":"a6fd3390-f12a-4723-9426-0dc6961f280a"}
6052025-01-29T05:19:06.125ZLoading write count information from file "/var/tmp/test_up-build/verify_file"
6062025-01-29T05:19:06.125Z{"msg":"Set Active after no reconciliation","v":0,"name":"crucible","level":30,"time":"2025-01-29T05:19:04.960746385Z","hostname":"w-01JJR7GCCH0R2F5T18F3DFC8YY","pid":1246,"session_id":"a6fd3390-f12a-4723-9426-0dc6961f280a"}
6072025-01-29T05:19:06.125Z{"msg":"The guest has finished waiting for activation with:33","v":0,"name":"crucible","level":30Read and Verify all blocks (0..100 range:true)
6082025-01-29T05:19:06.125Z,"time":"2025-01-29T05:19:04.960766973Z","hostname":"w-01JJR7GCCH0R2F5T18F3DFC8YY","pid":1246}
6092025-01-29T05:19:06.213ZWrote out file "/var/tmp/test_up-build/verify_file"
6102025-01-29T05:19:06.213ZVerify test completed
6112025-01-29T05:19:06.217ZWrote out file "/var/tmp/test_up-build/verify_file"
6122025-01-29T05:19:06.217ZCLIENT: Tests done. All submitted work has been ACK'd
6132025-01-29T05:19:06.217Z----------------------------------------------------------------
6142025-01-29T05:19:06.217Z Crucible gen:33 GIO:true work queues: Upstairs:0 downstairs:1
6152025-01-29T05:19:06.217ZStates: Active Active Active
6162025-01-29T05:19:06.217ZJOBID ACK TYPE BKS/EXT DS:0 DS:1 DS:2 REPLAY
6172025-01-29T05:19:06.217Z 1000 Acked Read 50 Done Done Done false
6182025-01-29T05:19:06.217Z STATES DS:0 DS:1 DS:2 TOTAL
6192025-01-29T05:19:06.217Z Sent 0 0 0 0
6202025-01-29T05:19:06.217Z Done 1 1 1 3
6212025-01-29T05:19:06.217Z Skipped 0 0 0 0
6222025-01-29T05:19:06.217Z Error 0 0 0 0
6232025-01-29T05:19:06.217ZLast Flush: None None None
6242025-01-29T05:19:06.217ZDownstairs last five completed:
6252025-01-29T05:19:06.217ZUpstairs last five completed: 1000
6262025-01-29T05:19:06.217Z----------------------------------------------------------------
6272025-01-29T05:19:06.217Z Crucible gen:33 GIO:true work queues: Upstairs:0 downstairs:1
6282025-01-29T05:19:06.217ZStates: Active Active Active
6292025-01-29T05:19:06.217ZJOBID ACK TYPE BKS/EXT DS:0 DS:1 DS:2 REPLAY
6302025-01-29T05:19:06.217Z 1000 Acked Read 50 Done Done Done false
6312025-01-29T05:19:06.217Z STATES DS:0 DS:1 DS:2 TOTAL
6322025-01-29T05:19:06.217Z Sent 0 0 0 0
6332025-01-29T05:19:06.217Z Done 1 1 1 3
6342025-01-29T05:19:06.217Z Skipped 0 0 0 0
6352025-01-29T05:19:06.217Z Error 0 0 0 0
6362025-01-29T05:19:06.217ZLast Flush: None None None
6372025-01-29T05:19:06.217ZDownstairs last five completed:
6382025-01-29T05:19:06.217ZUpstairs last five completed: 1000
6392025-01-29T05:19:06.217ZCLIENT: Up:0 ds:2 act:6
6402025-01-29T05:19:10.216Z----------------------------------------------------------------
6412025-01-29T05:19:10.216Z Crucible gen:33 GIO:true work queues: Upstairs:0 downstairs:0
6422025-01-29T05:19:10.216ZDownstairs last five completed: 1001 1000
6432025-01-29T05:19:10.216ZUpstairs last five completed: 1001 1000
6442025-01-29T05:19:10.216Z----------------------------------------------------------------
6452025-01-29T05:19:10.218Z Crucible gen:33 GIO:true work queues: Upstairs:0 downstairs:0
6462025-01-29T05:19:10.218ZDownstairs last five completed: 1001 1000
6472025-01-29T05:19:10.219ZUpstairs last five completed: 1001 1000
6482025-01-29T05:19:10.219ZCLIENT: Up:0 ds:0 act:6
6492025-01-29T05:19:10.219ZCLIENT: All crucible jobs finished, exiting program
6502025-01-29T05:19:10.224ZRepair part 2 passed
6512025-01-29T05:19:10.227Z/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
6522025-01-29T05:19:10.242ZEXT BLOCKS GEN0 GEN1 GEN2 FL0 FL1 FL2 D0 D1 D2 DIFF
6532025-01-29T05:19:10.245Z 0 000-009 32 32 32 3996 3996 3996 F F F
6542025-01-29T05:19:10.245Z 1 010-019 32 32 32 3996 3996 3996 F F F
6552025-01-29T05:19:10.245Z 2 020-029 32 32 32 3996 3996 3996 F F F
6562025-01-29T05:19:10.245Z 3 030-039 32 32 32 3996 3996 3996 F F F
6572025-01-29T05:19:10.245Z 4 040-049 32 32 32 3996 3996 3996 F F F
6582025-01-29T05:19:10.245ZMax gen: 32, Max flush: 3996
6592025-01-29T05:19:10.248Zdump test passed
6602025-01-29T05:19:10.248Z/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
6612025-01-29T05:19:10.263Z Extent 1
6622025-01-29T05:19:10.266ZGEN 32 32 32
6632025-01-29T05:19:10.266ZFLUSH_ID 3996 3996 3996
6642025-01-29T05:19:10.266ZDIRTY
6652025-01-29T05:19:10.266Z
6662025-01-29T05:19:10.266ZBLOCK D0 D1 D2 C0 C1 C2 DIFF
6672025-01-29T05:19:10.266Z010 A A A A A A
6682025-01-29T05:19:10.269Z011 A A A A A A
6692025-01-29T05:19:10.269Z012 A A A A A A
6702025-01-29T05:19:10.271Z013 A A A A A A
6712025-01-29T05:19:10.271Z014 A A A A A A
6722025-01-29T05:19:10.274Z015 A A A A A A
6732025-01-29T05:19:10.274Z016 A A A A A A
6742025-01-29T05:19:10.277Z017 A A A A A A
6752025-01-29T05:19:10.277Z018 A A A A A A
6762025-01-29T05:19:10.279Z019 A A A A A A
6772025-01-29T05:19:10.282Zdump extent test passed
6782025-01-29T05:19:10.285Z/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
6792025-01-29T05:19:10.299ZExtent 2 Block in extent 0 Actual block 20
6802025-01-29T05:19:10.299Z
6812025-01-29T05:19:10.302Z DATA SHA256 VER
6822025-01-29T05:19:10.302Z------ ---------------------------------------------------------------- ---
6832025-01-29T05:19:10.302Z 0 3cd831e86158e4dae6b81a1b0991cfa9983fd2b274c4c3668f7d0236d08b3b50 A
6842025-01-29T05:19:10.304Z 1 3cd831e86158e4dae6b81a1b0991cfa9983fd2b274c4c3668f7d0236d08b3b50 A
6852025-01-29T05:19:10.304Z 2 3cd831e86158e4dae6b81a1b0991cfa9983fd2b274c4c3668f7d0236d08b3b50 A
6862025-01-29T05:19:10.304Z
6872025-01-29T05:19:10.304ZNONCES 0 1 2 DIFF
6882025-01-29T05:19:10.304Z------ ------------------------ ------------------------ ------------------------ -----
6892025-01-29T05:19:10.304Z 0 4813e03943149a317464d568 4813e03943149a317464d568 4813e03943149a317464d568
6902025-01-29T05:19:10.304Z
6912025-01-29T05:19:10.305Z TAGS 0 1 2 DIFF
6922025-01-29T05:19:10.305Z------ -------------------------------- -------------------------------- -------------------------------- -----
6932025-01-29T05:19:10.305Z 0 c685a4444176aa5f97b1e67b4f323570 c685a4444176aa5f97b1e67b4f323570 c685a4444176aa5f97b1e67b4f323570
6942025-01-29T05:19:10.305Z
6952025-01-29T05:19:10.305ZHASHES 0 1 2 DIFF
6962025-01-29T05:19:10.305Z------ ---------------- ---------------- ---------------- -----
6972025-01-29T05:19:10.305Z
6982025-01-29T05:19:10.308Zdump block test passed
6992025-01-29T05:19:10.308ZInitial upstairs tests have completed, stopping all downstairs
7002025-01-29T05:19:15.377ZCreating 7 larger downstairs regions
7012025-01-29T05:19:15.566ZStarting 7 downstairs
7022025-01-29T05:19:20.575Zdsc restarted at PID: 1262
7032025-01-29T05:19:20.987ZNow do the replace-reconcile test
7042025-01-29T05:19:21.046ZUsing 8870 for the replacement port
7052025-01-29T05:21:58.405ZCompleted test: replace-reconcile
7062025-01-29T05:21:58.406ZNow do the replace-before-active test
7072025-01-29T05:25:32.049ZCompleted test: replace-before-active
7082025-01-29T05:25:32.052ZAll tests have completed, stopping all downstairs
7092025-01-29T05:25:32.111Z
7102025-01-29T05:25:32.111ZAll Tests have passed
7112025-01-29T05:25:32.115Z13:20 Test duration
7122025-01-29T05:25:32.115Z
7132025-01-29T05:25:32.115Zreal 13:19.990654097
7142025-01-29T05:25:32.115Zuser 18:34.568483071
7152025-01-29T05:25:32.115Zsys 25.995726898
7162025-01-29T05:25:32.115Ztrap 0.553020799
7172025-01-29T05:25:32.115Ztflt 0.048307569
7182025-01-29T05:25:32.115Zdflt 0.037375174
7192025-01-29T05:25:32.115Zkflt 0.001214468
7202025-01-29T05:25:32.116Zlock 25:21:01.951825547
7212025-01-29T05:25:32.116Zslp 1:13:54.381210531
7222025-01-29T05:25:32.116Zlat 2:03.060469913
7232025-01-29T05:25:32.116Zstop 0.210249586
7242025-01-29T05:25:32.116Z+ echo 'test-up-2region-encrypted ends'
7252025-01-29T05:25:32.116Ztest-up-2region-encrypted ends
7262025-01-29T05:25:37.118Zprocess exited: duration 808149 ms, exit code 0
7272025-01-29T05:25:37.118Zexec warning: : stdio descriptors remain open after task exit; waiting 60 seconds for them to close
7282025-01-29T05:26:37.177Zexec warning: : stdout descriptor may be held open by a background process; giving up!
7292025-01-29T05:26:37.177Zexec warning: : stderr descriptor may be held open by a background process; giving up!
 
7302025-01-29T05:26:37.188Zfound 17 output files
7312025-01-29T05:26:37.188Zuploading: /tmp/test_up-build/dsc-out.txt (48489 bytes)
7322025-01-29T05:26:38.200Zuploaded: /tmp/test_up-build/dsc-out.txt
7332025-01-29T05:26:38.200Zuploading: /tmp/test_up-build/test_up_out.txt (8469517 bytes)
7342025-01-29T05:26:39.340Zuploaded: /tmp/test_up-build/test_up_out.txt
7352025-01-29T05:26:39.340Zuploading: /tmp/test_up-build/dsc/downstairs-8810.txt (147237 bytes)
7362025-01-29T05:26:40.358Zuploaded: /tmp/test_up-build/dsc/downstairs-8810.txt
7372025-01-29T05:26:40.361Zuploading: /tmp/test_up-build/dsc/downstairs-8820.txt (144630 bytes)
7382025-01-29T05:26:41.376Zuploaded: /tmp/test_up-build/dsc/downstairs-8820.txt
7392025-01-29T05:26:41.379Zuploading: /tmp/test_up-build/dsc/downstairs-8830.txt (251028 bytes)
7402025-01-29T05:26:42.400Zuploaded: /tmp/test_up-build/dsc/downstairs-8830.txt
7412025-01-29T05:26:42.403Zuploading: /tmp/test_up-build/dsc/downstairs-8840.txt (139392 bytes)
7422025-01-29T05:26:43.419Zuploaded: /tmp/test_up-build/dsc/downstairs-8840.txt
7432025-01-29T05:26:43.422Zuploading: /tmp/test_up-build/dsc/downstairs-8850.txt (358206 bytes)
7442025-01-29T05:26:44.446Zuploaded: /tmp/test_up-build/dsc/downstairs-8850.txt
7452025-01-29T05:26:44.446Zuploading: /tmp/test_up-build/dsc/downstairs-8860.txt (33772 bytes)
7462025-01-29T05:26:45.458Zuploaded: /tmp/test_up-build/dsc/downstairs-8860.txt
7472025-01-29T05:26:45.458Zuploading: /tmp/test_up-build/dsc/downstairs-8870.txt (735805 bytes)
7482025-01-29T05:26:46.495Zuploaded: /tmp/test_up-build/dsc/downstairs-8870.txt
7492025-01-29T05:26:46.498Zuploading: /tmp/debug/df.txt (1270 bytes)
7502025-01-29T05:26:47.505Zuploaded: /tmp/debug/df.txt
7512025-01-29T05:26:47.508Zuploading: /tmp/debug/dtrace.txt (985973 bytes)
7522025-01-29T05:26:48.548Zuploaded: /tmp/debug/dtrace.txt
7532025-01-29T05:26:48.550Zuploading: /tmp/debug/iostat.txt (259858 bytes)
7542025-01-29T05:26:48.567Zupload warning: file "/tmp/debug/iostat.txt" changed size mid upload: 259858 -> 263158
7552025-01-29T05:26:49.572Zuploaded: /tmp/debug/iostat.txt
7562025-01-29T05:26:49.575Zuploading: /tmp/debug/mpstat.txt (631326 bytes)
7572025-01-29T05:26:49.603Zupload warning: file "/tmp/debug/mpstat.txt" changed size mid upload: 631326 -> 640074
7582025-01-29T05:26:50.610Zuploaded: /tmp/debug/mpstat.txt
7592025-01-29T05:26:50.610Zuploading: /tmp/debug/paging.txt (113336 bytes)
7602025-01-29T05:26:50.623Zupload warning: file "/tmp/debug/paging.txt" changed size mid upload: 113336 -> 114989
7612025-01-29T05:26:51.629Zuploaded: /tmp/debug/paging.txt
7622025-01-29T05:26:51.629Zuploading: /tmp/debug/prstat.txt (1228280 bytes)
7632025-01-29T05:26:51.673Zupload warning: file "/tmp/debug/prstat.txt" changed size mid upload: 1228280 -> 1246367
7642025-01-29T05:26:52.681Zuploaded: /tmp/debug/prstat.txt
7652025-01-29T05:26:52.684Zuploading: /tmp/debug/psrinfo.txt (1528 bytes)
7662025-01-29T05:26:53.691Zuploaded: /tmp/debug/psrinfo.txt
7672025-01-29T05:26:53.693Zuploading: /tmp/debug/upstairs-info.txt (176770 bytes)
7682025-01-29T05:26:54.710Zuploaded: /tmp/debug/upstairs-info.txt