01JJPX9QN89D8R9SDM3Z2Q6E5Y: 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: 01JJPXACAN09G7JM6MKS2J8F0D

Tags:

Artefacts:

Output:

SEQ GLOBAL TIME DETAILS
12025-01-28T17:07:37.587Zjob dependencies complete; ready to run (waiting for 13 m 59 s)
22025-01-28T17:08:49.931Zjob assigned to worker 01JJPY42J7TJ48QYFMTCCVFBHG [factory aws, i-0c01004bc792689b7] (queued for 1 m 12 s)
32025-01-28T17:08:57.187Zdownloading input: /input/build/work/bins/crucible-downstairs.gz
42025-01-28T17:08:58.297Zdownloaded input: /input/build/work/bins/crucible-downstairs.gz
52025-01-28T17:08:58.297Zdownloading input: /input/build/work/bins/crucible-hammer.gz
62025-01-28T17:08:59.351Zdownloaded input: /input/build/work/bins/crucible-hammer.gz
72025-01-28T17:08:59.351Zdownloading input: /input/build/work/bins/crutest.gz
82025-01-28T17:09:00.491Zdownloaded input: /input/build/work/bins/crutest.gz
92025-01-28T17:09:00.491Zdownloading input: /input/build/work/bins/dsc.gz
102025-01-28T17:09:01.186Zdownloaded input: /input/build/work/bins/dsc.gz
112025-01-28T17:09:01.190Zdownloading input: /input/build/work/scripts/perf-downstairs-tick.d
122025-01-28T17:09:01.206Zdownloaded input: /input/build/work/scripts/perf-downstairs-tick.d
132025-01-28T17:09:01.206Zdownloading input: /input/build/work/scripts/test_ds.sh
142025-01-28T17:09:01.225Zdownloaded input: /input/build/work/scripts/test_ds.sh
152025-01-28T17:09:01.225Zdownloading input: /input/build/work/scripts/test_live_repair.sh
162025-01-28T17:09:01.243Zdownloaded input: /input/build/work/scripts/test_live_repair.sh
172025-01-28T17:09:01.243Zdownloading input: /input/build/work/scripts/test_repair.sh
182025-01-28T17:09:01.258Zdownloaded input: /input/build/work/scripts/test_repair.sh
192025-01-28T17:09:01.258Zdownloading input: /input/build/work/scripts/test_replay.sh
202025-01-28T17:09:01.276Zdownloaded input: /input/build/work/scripts/test_replay.sh
212025-01-28T17:09:01.276Zdownloading input: /input/build/work/scripts/test_up.sh
222025-01-28T17:09:01.294Zdownloaded input: /input/build/work/scripts/test_up.sh
232025-01-28T17:09:01.294Zdownloading input: /input/build/work/scripts/upstairs_info.d
242025-01-28T17:09:01.313Zdownloaded input: /input/build/work/scripts/upstairs_info.d
252025-01-28T17:09:01.315Zdownloading input: /input/build/tmp/cargo-test-out.log
262025-01-28T17:09:02.020Zdownloaded input: /input/build/tmp/cargo-test-out.log
 
272025-01-28T17:09:02.020Zstarting task 0: "setup"
282025-01-28T17:09:02.027Z++ uname -s
292025-01-28T17:09:02.030Z+ kern=SunOS
302025-01-28T17:09:02.030Z+ case "$kern" in
312025-01-28T17:09:02.030Z+ groupadd -g 12345 build
322025-01-28T17:09:02.033Z+ useradd -u 12345 -g build -d /home/build -s /bin/bash -c build -P 'Primary Administrator' build
332025-01-28T17:09:04.041Z+ zfs create -o mountpoint=/work rpool/work
342025-01-28T17:09:04.202Z++ awk '$2 == "/home" { print $3 }' /etc/mnttab
352025-01-28T17:09:04.205Z+ home_fs=zfs
362025-01-28T17:09:04.205Z+ [[ zfs == autofs ]]
372025-01-28T17:09:04.205Z+ mkdir -p /home/build
382025-01-28T17:09:04.208Z+ chown build:build /home/build /work
392025-01-28T17:09:06.209Z+ chmod 0700 /home/build /work
402025-01-28T17:09:06.212Zprocess exited: duration 4196 ms, exit code 0
 
412025-01-28T17:09:06.218Zstarting task 1: "authentication"
422025-01-28T17:09:06.235Zprocess exited: duration 17 ms, exit code 0
 
432025-01-28T17:09:06.243Zstarting task 2: "build"
442025-01-28T17:09:06.247Z+ banner cores
452025-01-28T17:09:06.250Z
462025-01-28T17:09:06.250Z #### #### ##### ###### ####
472025-01-28T17:09:06.250Z # # # # # # # #
482025-01-28T17:09:06.250Z # # # # # ##### ####
492025-01-28T17:09:06.250Z # # # ##### # #
502025-01-28T17:09:06.250Z # # # # # # # # #
512025-01-28T17:09:06.250Z #### #### # # ###### ####
522025-01-28T17:09:06.250Z
532025-01-28T17:09:06.250Z+ pfexec coreadm -i /tmp/core.%f.%p -g /tmp/core.%f.%p -e global -e log -e proc-setid -e global-setid
542025-01-28T17:09:06.258Z+ banner unpack
552025-01-28T17:09:06.261Z
562025-01-28T17:09:06.261Z # # # # ##### ## #### # #
572025-01-28T17:09:06.261Z # # ## # # # # # # # # #
582025-01-28T17:09:06.261Z # # # # # # # # # # ####
592025-01-28T17:09:06.261Z # # # # # ##### ###### # # #
602025-01-28T17:09:06.261Z # # # ## # # # # # # #
612025-01-28T17:09:06.261Z #### # # # # # #### # #
622025-01-28T17:09:06.261Z
632025-01-28T17:09:06.261Z+ mkdir -p /var/tmp/bins
642025-01-28T17:09:06.264Z+ for t in "$input/bins/"*.gz
652025-01-28T17:09:06.264Z++ basename /input/build/work/bins/crucible-downstairs.gz
662025-01-28T17:09:06.264Z+ b=crucible-downstairs.gz
672025-01-28T17:09:06.265Z+ b=crucible-downstairs
682025-01-28T17:09:06.265Z+ gunzip
692025-01-28T17:09:08.511Z+ chmod +x /var/tmp/bins/crucible-downstairs
702025-01-28T17:09:08.515Z+ for t in "$input/bins/"*.gz
712025-01-28T17:09:08.517Z++ basename /input/build/work/bins/crucible-hammer.gz
722025-01-28T17:09:08.518Z+ b=crucible-hammer.gz
732025-01-28T17:09:08.518Z+ b=crucible-hammer
742025-01-28T17:09:08.518Z+ gunzip
752025-01-28T17:09:10.645Z+ chmod +x /var/tmp/bins/crucible-hammer
762025-01-28T17:09:10.648Z+ for t in "$input/bins/"*.gz
772025-01-28T17:09:10.650Z++ basename /input/build/work/bins/crutest.gz
782025-01-28T17:09:10.651Z+ b=crutest.gz
792025-01-28T17:09:10.651Z+ b=crutest
802025-01-28T17:09:10.651Z+ gunzip
812025-01-28T17:09:13.037Z+ chmod +x /var/tmp/bins/crutest
822025-01-28T17:09:13.040Z+ for t in "$input/bins/"*.gz
832025-01-28T17:09:13.040Z++ basename /input/build/work/bins/dsc.gz
842025-01-28T17:09:13.040Z+ b=dsc.gz
852025-01-28T17:09:13.040Z+ b=dsc
862025-01-28T17:09:13.043Z+ gunzip
872025-01-28T17:09:14.413Z+ chmod +x /var/tmp/bins/dsc
882025-01-28T17:09:14.416Z+ export BINDIR=/var/tmp/bins
892025-01-28T17:09:14.416Z+ BINDIR=/var/tmp/bins
902025-01-28T17:09:14.416Z+ jobpid=1141
912025-01-28T17:09:14.418Z+ echo 'Setup debug logging'
922025-01-28T17:09:14.418ZSetup debug logging
932025-01-28T17:09:14.419Z+ mkdir /tmp/debug
942025-01-28T17:09:14.419Z+ sleep 3600
952025-01-28T17:09:14.419Z+ psrinfo -v
962025-01-28T17:09:14.422Z+ df -h
972025-01-28T17:09:14.430Z+ prstat -d d -mLc 1
982025-01-28T17:09:14.432Z+ iostat -T d -xn 1
992025-01-28T17:09:14.432Z+ mpstat -T d 1
1002025-01-28T17:09:14.432Z+ vmstat -T d -p 1
1012025-01-28T17:09:14.435Z+ pfexec dtrace -Z -s /input/build/work/scripts/perf-downstairs-tick.d
1022025-01-28T17:09:14.435Z+ banner test_up_2r_encrypted
1032025-01-28T17:09:14.435Z+ pfexec dtrace -Z -s /input/build/work/scripts/upstairs_info.d
1042025-01-28T17:09:14.438Z #####
1052025-01-28T17:09:14.438Z ##### ###### #### ##### # # ##### # # #####
1062025-01-28T17:09:14.438Z # # # # # # # # # # #
1072025-01-28T17:09:14.438Z # ##### #### # # # # # ##### # #
1082025-01-28T17:09:14.438Z # # # # # # ##### # #####
1092025-01-28T17:09:14.438Z # # # # # # # # # # #
1102025-01-28T17:09:14.438Z # ###### #### # ####### #### # ####### ####### # #
1112025-01-28T17:09:14.438Z
1122025-01-28T17:09:14.438Z+ ptime -m bash /input/build/work/scripts/test_up.sh -r 2 -N encrypted
1132025-01-28T17:09:14.447Z/input/build/work
1142025-01-28T17:09:14.459ZUsing 2 region sets
1152025-01-28T17:09:14.459ZTurn off color for downstairs dump
1162025-01-28T17:09:14.475ZUpstairs using key: 9q52nrwZdyxSwBF6A/1uxpEIrPl6wZEZ1P9sUqSfLyg=
1172025-01-28T17:09:14.478Zdsc output goes to /tmp/test_up-build/dsc-out.txt
1182025-01-28T17:09:14.478ZCreating 6 downstairs regions
1192025-01-28T17:09:14.833ZStarting 6 downstairs
1202025-01-28T17:09:14.836Zdsc started at PID: 1189
1212025-01-28T17:09:20.171ZDisable automatic restart on all downstairs
1222025-01-28T17:09:20.224Z
1232025-01-28T17:09:20.224ZBegin tests, output goes to /tmp/test_up-build/test_up_out.txt
1242025-01-28T17:09:20.228ZRunning test: span
1252025-01-28T17:09:24.394ZCompleted test: span
1262025-01-28T17:09:29.401ZRunning test: big
1272025-01-28T17:09:33.981ZCompleted test: big
1282025-01-28T17:09:38.989ZRunning test: dep
1292025-01-28T17:10:12.570ZCompleted test: dep
1302025-01-28T17:10:17.578ZRunning test: balloon
1312025-01-28T17:14:35.547ZCompleted test: balloon
1322025-01-28T17:14:40.556ZRunning test: deactivate
1332025-01-28T17:15:35.249ZCompleted test: deactivate
1342025-01-28T17:15:40.257ZRunning hammer
1352025-01-28T17:15:53.323ZRun repair tests
1362025-01-28T17:15:53.328Z/var/tmp/bins/crutest fill -g 31 -q --key 9q52nrwZdyxSwBF6A/1uxpEIrPl6wZEZ1P9sUqSfLyg= --dsc 127.0.0.1:9998 --verify-out /var/tmp/test_up-build/verify_file
1372025-01-28T17:15:53.392Z{"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-28T17:15:52.538933412Z","hostname":"w-01JJPY42J7TJ48QYFMTCCVFBHG","pid":1232,"task":"crutest"}
1382025-01-28T17:15:53.394Z{"msg":"dsc has 6 regions. This means 2 sub_volumes","v":0,"name":"crucible","level":30,"time":"2025-01-28T17:15:52.539537356Z","hostname":"w-01JJPY42J7TJ48QYFMTCCVFBHG","pid":1232,"task":"crutest"}
1392025-01-28T17:15:53.395Z{"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-28T17:15:52.541280451Z","hostname":"w-01JJPY42J7TJ48QYFMTCCVFBHG","pid":1232,"task":"crutest"}
1402025-01-28T17:15:53.395Z{"msg":"Upstairs starts","v":0,"name":"crucible","level":30,"time":"2025-01-28T17:15:52.541516664Z","hostname":"w-01JJPY42J7TJ48QYFMTCCVFBHG","pid":1232}
1412025-01-28T17:15:53.395Z{"msg":"Crucible Version: BuildInfo {\n version: \"0.0.1\",\n git_sha: \"752fd3e208a28c201ec7c5e297caafe64bf1aaf2\",\n git_commit_timestamp: \"2025-01-28T16:52:48.000000000Z\",\n git_branch: \"alan/where-my-writes-at\",\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-28T17:15:52.541579624Z","hostname":"w-01JJPY42J7TJ48QYFMTCCVFBHG","pid":1232}
1422025-01-28T17:15:53.395Z{"msg":"Upstairs <-> Downstairs Message Version: 13","v":0,"name":"crucible","level":30,"time":"2025-01-28T17:15:52.541617338Z","hostname":"w-01JJPY42J7TJ48QYFMTCCVFBHG","pid":1232}
1432025-01-28T17:15:53.395Z{"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-28T17:15:52.541639115Z","hostname":"w-01JJPY42J7TJ48QYFMTCCVFBHG","pid":1232}
1442025-01-28T17:15:53.400Z{"msg":"Crucible dd290b06-4ca0-4eb0-864b-c8c377f118ba has session id: 91d2e55c-b1f8-4102-bcf8-bf6cb85d3762","v":0,"name":"crucible","level":30,"time":"2025-01-28T17:15:52.54230291Z","hostname":"w-01JJPY42J7TJ48QYFMTCCVFBHG","pid":1232,"session_id":"91d2e55c-b1f8-4102-bcf8-bf6cb85d3762"}
1452025-01-28T17:15:53.400Z{"msg":"Upstairs opts: Upstairs UUID: dd290b06-4ca0-4eb0-864b-c8c377f118ba, 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-28T17:15:52.542369139Z","hostname":"w-01JJPY42J7TJ48QYFMTCCVFBHG","pid":1232,"session_id":"91d2e55c-b1f8-4102-bcf8-bf6cb85d3762"}
1462025-01-28T17:15:53.400Z{"msg":"Crucible stats registered with UUID: dd290b06-4ca0-4eb0-864b-c8c377f118ba","v":0,"name":"crucible","level":30,"time":"2025-01-28T17:15:52.542395055Z","hostname":"w-01JJPY42J7TJ48QYFMTCCVFBHG","pid":1232,"session_id":"91d2e55c-b1f8-4102-bcf8-bf6cb85d3762"}
1472025-01-28T17:15:53.400Z{"msg":"could not find Downstairs address for Nexus","v":0,"name":"crucible","level":40,"time":"2025-01-28T17:15:52.542412813Z","hostname":"w-01JJPY42J7TJ48QYFMTCCVFBHG","pid":1232,"session_id":"91d2e55c-b1f8-4102-bcf8-bf6cb85d3762"}
1482025-01-28T17:15:53.400Z{"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-28T17:15:52.544494614Z","hostname":"w-01JJPY42J7TJ48QYFMTCCVFBHG","pid":1232,"task":"crutest"}
1492025-01-28T17:15:53.400Z{"msg":"Upstairs starts","v":0,"name":"crucible","level":30,"time":"2025-01-28T17:15:52.544609906Z","hostname":"w-01JJPY42J7TJ48QYFMTCCVFBHG","pid":1232}
1502025-01-28T17:15:53.400Z{"msg":"Crucible Version: BuildInfo {\n version: \"0.0.1\",\n git_sha: \"752fd3e208a28c201ec7c5e297caafe64bf1aaf2\",\n git_commit_timestamp: \"2025-01-28T16:52:48.000000000Z\",\n git_branch: \"alan/where-my-writes-at\",\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-28T17:15:52.54464881Z","hostname":"w-01JJPY42J7TJ48QYFMTCCVFBHG","pid":1232}
1512025-01-28T17:15:53.400Z{"msg":"Upstairs <-> Downstairs Message Version: 13","v":0,"name":"crucible","level":30,"time":"2025-01-28T17:15:52.544670097Z","hostname":"w-01JJPY42J7TJ48QYFMTCCVFBHG","pid":1232}
1522025-01-28T17:15:53.400Z{"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-28T17:15:52.544684494Z","hostname":"w-01JJPY42J7TJ48QYFMTCCVFBHG","pid":1232}
1532025-01-28T17:15:53.400Z{"msg":"Crucible dd290b06-4ca0-4eb0-864b-c8c377f118ba has session id: e2c09312-b196-4128-a2c3-44b3415d2bc6","v":0,"name":"crucible","level":30,"time":"2025-01-28T17:15:52.545110327Z","hostname":"w-01JJPY42J7TJ48QYFMTCCVFBHG","pid":1232,"session_id":"e2c09312-b196-4128-a2c3-44b3415d2bc6"}
1542025-01-28T17:15:53.400Z{"msg":"Upstairs opts: Upstairs UUID: dd290b06-4ca0-4eb0-864b-c8c377f118ba, 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-28T17:15:52.545151951Z","hostname":"w-01JJPY42J7TJ48QYFMTCCVFBHG","pid":1232,"session_id":"e2c09312-b196-4128-a2c3-44b3415d2bc6"}
1552025-01-28T17:15:53.400Z{"msg":"Crucible stats registered with UUID: dd290b06-4ca0-4eb0-864b-c8c377f118ba","v":0,"name":"crucible","level":30,"time":"2025-01-28T17:15:52.545180846Z","hostname":"w-01JJPY42J7TJ48QYFMTCCVFBHG","pid":1232,"session_id":"e2c09312-b196-4128-a2c3-44b3415d2bc6"}
1562025-01-28T17:15:53.400Z{"msg":"could not find Downstairs address for Nexus","v":0,"name":"crucible","level":40,"time":"2025-01-28T17:15:52.54521865Z","hostname":"w-01JJPY42J7TJ48QYFMTCCVFBHG","pid":1232,"session_id":"e2c09312-b196-4128-a2c3-44b3415d2bc6"}
1572025-01-28T17:15:53.400Z{"msg":"Downstairs in volume = 6","v":0,"name":"crucible","level":30,"time":"2025-01-28T17:15:52.546187517Z","hostname":"w-01JJPY42J7TJ48QYFMTCCVFBHG","pid":1232,"task":"crutest"}
1582025-01-28T17:15:53.400Z{"msg":"The guest has requested activation with gen:31","v":0,"name":"crucible","level":30,"time":"2025-01-28T17:15:52.546237259Z","hostname":"w-01JJPY42J7TJ48QYFMTCCVFBHG","pid":1232}
1592025-01-28T17:15:53.400Z{"msg":"dd290b06-4ca0-4eb0-864b-c8c377f118ba active request set","v":0,"name":"crucible","level":30,"time":"2025-01-28T17:15:52.546281882Z","hostname":"w-01JJPY42J7TJ48QYFMTCCVFBHG","pid":1232,"session_id":"91d2e55c-b1f8-4102-bcf8-bf6cb85d3762"}
1602025-01-28T17:15:53.400Z{"msg":"sending connect oneshot to client","v":0,"name":"crucible","level":30,"time":"2025-01-28T17:15:52.546310188Z","hostname":"w-01JJPY42J7TJ48QYFMTCCVFBHG","pid":1232,"client":"0","":"downstairs","session_id":"91d2e55c-b1f8-4102-bcf8-bf6cb85d3762"}
1612025-01-28T17:15:53.400Z{"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-28T17:15:52.546348722Z","hostname":"w-01JJPY42J7TJ48QYFMTCCVFBHG","pid":1232,"client":"0","":"downstairs","session_id":"91d2e55c-b1f8-4102-bcf8-bf6cb85d3762"}
1622025-01-28T17:15:53.400Z{"msg":"sending connect oneshot to client","v":0,"name":"crucible","level":30,"time":"2025-01-28T17:15:52.546392335Z","hostname":"w-01JJPY42J7TJ48QYFMTCCVFBHG","pid":1232,"client":"1","":"downstairs","session_id":"91d2e55c-b1f8-4102-bcf8-bf6cb85d3762"}
1632025-01-28T17:15:53.400Z{"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-28T17:15:52.546433298Z","hostname":"w-01JJPY42J7TJ48QYFMTCCVFBHG","pid":1232,"client":"1","":"downstairs","session_id":"91d2e55c-b1f8-4102-bcf8-bf6cb85d3762"}
1642025-01-28T17:15:53.400Z{"msg":"sending connect oneshot to client","v":0,"name":"crucible","level":30,"time":"2025-01-28T17:15:52.546461754Z","hostname":"w-01JJPY42J7TJ48QYFMTCCVFBHG","pid":1232,"client":"2","":"downstairs","session_id":"91d2e55c-b1f8-4102-bcf8-bf6cb85d3762"}
1652025-01-28T17:15:53.401Z{"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-28T17:15:52.546498878Z","hostname":"w-01JJPY42J7TJ48QYFMTCCVFBHG","pid":1232,"client":"2","":"downstairs","session_id":"91d2e55c-b1f8-4102-bcf8-bf6cb85d3762"}
1662025-01-28T17:15:53.401Z{"msg":"connecting to 127.0.0.1:8830","v":0,"name":"crucible","level":30,"time":"2025-01-28T17:15:52.546526124Z","hostname":"w-01JJPY42J7TJ48QYFMTCCVFBHG","pid":1232,"":"io task","client":"2","":"downstairs","session_id":"91d2e55c-b1f8-4102-bcf8-bf6cb85d3762"}
1672025-01-28T17:15:53.401Z{"msg":"connecting to 127.0.0.1:8810","v":0,"name":"crucible","level":30,"time":"2025-01-28T17:15:52.546604011Z","hostname":"w-01JJPY42J7TJ48QYFMTCCVFBHG","pid":1232,"":"io task","client":"0","":"downstairs","session_id":"91d2e55c-b1f8-4102-bcf8-bf6cb85d3762"}
1682025-01-28T17:15:53.401Z{"msg":"connecting to 127.0.0.1:8820","v":0,"name":"crucible","level":30,"time":"2025-01-28T17:15:52.546653414Z","hostname":"w-01JJPY42J7TJ48QYFMTCCVFBHG","pid":1232,"":"io task","client":"1","":"downstairs","session_id":"91d2e55c-b1f8-4102-bcf8-bf6cb85d3762"}
1692025-01-28T17:15:53.407Z{"msg":"ds_connection connected from Ok(127.0.0.1:38734)","v":0,"name":"crucible","level":30,"time":"2025-01-28T17:15:52.546815598Z","hostname":"w-01JJPY42J7TJ48QYFMTCCVFBHG","pid":1232,"":"io task","client":"1","":"downstairs","session_id":"91d2e55c-b1f8-4102-bcf8-bf6cb85d3762"}
1702025-01-28T17:15:53.407Z{"msg":"ds_connection connected from Ok(127.0.0.1:53872)","v":0,"name":"crucible","level":30,"time":"2025-01-28T17:15:52.54686778Z","hostname":"w-01JJPY42J7TJ48QYFMTCCVFBHG","pid":1232,"":"io task","client":"2","":"downstairs","session_id":"91d2e55c-b1f8-4102-bcf8-bf6cb85d3762"}
1712025-01-28T17:15:53.407Z{"msg":"ds_connection connected from Ok(127.0.0.1:47517)","v":0,"name":"crucible","level":30,"time":"2025-01-28T17:15:52.546906134Z","hostname":"w-01JJPY42J7TJ48QYFMTCCVFBHG","pid":1232,"":"io task","client":"0","":"downstairs","session_id":"91d2e55c-b1f8-4102-bcf8-bf6cb85d3762"}
1722025-01-28T17:15:53.407Z{"msg":"version negotiation from state Connecting { state: WaitForPromote, mode: New }","v":0,"name":"crucible","level":30,"time":"2025-01-28T17:15:52.547404075Z","hostname":"w-01JJPY42J7TJ48QYFMTCCVFBHG","pid":1232,"client":"1","":"downstairs","session_id":"91d2e55c-b1f8-4102-bcf8-bf6cb85d3762"}
1732025-01-28T17:15:53.407Z{"msg":"version negotiation from state Connecting { state: WaitForPromote, mode: New }","v":0,"name":"crucible","level":30,"time":"2025-01-28T17:15:52.547442539Z","hostname":"w-01JJPY42J7TJ48QYFMTCCVFBHG","pid":1232,"client":"2","":"downstairs","session_id":"91d2e55c-b1f8-4102-bcf8-bf6cb85d3762"}
1742025-01-28T17:15:53.407Z{"msg":"version negotiation from state Connecting { state: WaitForPromote, mode: New }","v":0,"name":"crucible","level":30,"time":"2025-01-28T17:15:52.547505809Z","hostname":"w-01JJPY42J7TJ48QYFMTCCVFBHG","pid":1232,"client":"0","":"downstairs","session_id":"91d2e55c-b1f8-4102-bcf8-bf6cb85d3762"}
1752025-01-28T17:15:53.407Z{"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-28T17:15:52.548125211Z","hostname":"w-01JJPY42J7TJ48QYFMTCCVFBHG","pid":1232,"client":"1","":"downstairs","session_id":"91d2e55c-b1f8-4102-bcf8-bf6cb85d3762"}
1762025-01-28T17:15:53.407Z{"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-28T17:15:52.548168755Z","hostname":"w-01JJPY42J7TJ48QYFMTCCVFBHG","pid":1232,"client":"0","":"downstairs","session_id":"91d2e55c-b1f8-4102-bcf8-bf6cb85d3762"}
1772025-01-28T17:15:53.407Z{"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-28T17:15:52.548194411Z","hostname":"w-01JJPY42J7TJ48QYFMTCCVFBHG","pid":1232,"client":"2","":"downstairs","session_id":"91d2e55c-b1f8-4102-bcf8-bf6cb85d3762"}
1782025-01-28T17:15:53.407Z{"msg":"Waiting for more clients to be ready","v":0,"name":"crucible","level":30,"time":"2025-01-28T17:15:52.548614245Z","hostname":"w-01JJPY42J7TJ48QYFMTCCVFBHG","pid":1232,"session_id":"91d2e55c-b1f8-4102-bcf8-bf6cb85d3762"}
1792025-01-28T17:15:53.407Z{"msg":"Waiting for more clients to be ready","v":0,"name":"crucible","level":30,"time":"2025-01-28T17:15:52.548648839Z","hostname":"w-01JJPY42J7TJ48QYFMTCCVFBHG","pid":1232,"session_id":"91d2e55c-b1f8-4102-bcf8-bf6cb85d3762"}
1802025-01-28T17:15:53.407Z{"msg":"[0]R flush_numbers: [3991, 3991, 3991, 3991, 3991]","v":0,"name":"crucible","level":30,"time":"2025-01-28T17:15:52.548663187Z","hostname":"w-01JJPY42J7TJ48QYFMTCCVFBHG","pid":1232,"":"downstairs","":"downstairs","session_id":"91d2e55c-b1f8-4102-bcf8-bf6cb85d3762"}
1812025-01-28T17:15:53.407Z{"msg":"[0]R generation: [25, 25, 25, 25, 25]","v":0,"name":"crucible","level":30,"time":"2025-01-28T17:15:52.548685113Z","hostname":"w-01JJPY42J7TJ48QYFMTCCVFBHG","pid":1232,"":"downstairs","":"downstairs","session_id":"91d2e55c-b1f8-4102-bcf8-bf6cb85d3762"}
1822025-01-28T17:15:53.407Z{"msg":"[0]R dirty: [false, false, false, false, false]","v":0,"name":"crucible","level":30,"time":"2025-01-28T17:15:52.548699121Z","hostname":"w-01JJPY42J7TJ48QYFMTCCVFBHG","pid":1232,"":"downstairs","":"downstairs","session_id":"91d2e55c-b1f8-4102-bcf8-bf6cb85d3762"}
1832025-01-28T17:15:53.407Z{"msg":"[1]R flush_numbers: [3991, 3991, 3991, 3991, 3991]","v":0,"name":"crucible","level":30,"time":"2025-01-28T17:15:52.548720778Z","hostname":"w-01JJPY42J7TJ48QYFMTCCVFBHG","pid":1232,"":"downstairs","":"downstairs","session_id":"91d2e55c-b1f8-4102-bcf8-bf6cb85d3762"}
1842025-01-28T17:15:53.407Z{"msg":"[1]R generation: [25, 25, 25, 25, 25]","v":0,"name":"crucible","level":30,"time":"2025-01-28T17:15:52.548734706Z","hostname":"w-01JJPY42J7TJ48QYFMTCCVFBHG","pid":1232,"":"downstairs","":"downstairs","session_id":"91d2e55c-b1f8-4102-bcf8-bf6cb85d3762"}
1852025-01-28T17:15:53.407Z{"msg":"[1]R dirty: [false, false, false, false, false]","v":0,"name":"crucible","level":30,"time":"2025-01-28T17:15:52.548755352Z","hostname":"w-01JJPY42J7TJ48QYFMTCCVFBHG","pid":1232,"":"downstairs","":"downstairs","session_id":"91d2e55c-b1f8-4102-bcf8-bf6cb85d3762"}
1862025-01-28T17:15:53.407Z{"msg":"[2]R flush_numbers: [3991, 3991, 3991, 3991, 3991]","v":0,"name":"crucible","level":30,"time":"2025-01-28T17:15:52.54876889Z","hostname":"w-01JJPY42J7TJ48QYFMTCCVFBHG","pid":1232,"":"downstairs","":"downstairs","session_id":"91d2e55c-b1f8-4102-bcf8-bf6cb85d3762"}
1872025-01-28T17:15:53.407Z{"msg":"[2]R generation: [25, 25, 25, 25, 25]","v":0,"name":"crucible","level":30,"time":"2025-01-28T17:15:52.548782118Z","hostname":"w-01JJPY42J7TJ48QYFMTCCVFBHG","pid":1232,"":"downstairs","":"downstairs","session_id":"91d2e55c-b1f8-4102-bcf8-bf6cb85d3762"}
1882025-01-28T17:15:53.407Z{"msg":"[2]R dirty: [false, false, false, false, false]","v":0,"name":"crucible","level":30,"time":"2025-01-28T17:15:52.548795256Z","hostname":"w-01JJPY42J7TJ48QYFMTCCVFBHG","pid":1232,"":"downstairs","":"downstairs","session_id":"91d2e55c-b1f8-4102-bcf8-bf6cb85d3762"}
1892025-01-28T17:15:53.407Z{"msg":"Max found gen is 26","v":0,"name":"crucible","level":30,"time":"2025-01-28T17:15:52.548815433Z","hostname":"w-01JJPY42J7TJ48QYFMTCCVFBHG","pid":1232,"":"downstairs","":"downstairs","session_id":"91d2e55c-b1f8-4102-bcf8-bf6cb85d3762"}
1902025-01-28T17:15:53.407Z{"msg":"Generation requested: 31 >= found:26","v":0,"name":"crucible","level":30,"time":"2025-01-28T17:15:52.548828831Z","hostname":"w-01JJPY42J7TJ48QYFMTCCVFBHG","pid":1232,"":"downstairs","":"downstairs","session_id":"91d2e55c-b1f8-4102-bcf8-bf6cb85d3762"}
1912025-01-28T17:15:53.407Z{"msg":"Next flush: 3992","v":0,"name":"crucible","level":30,"time":"2025-01-28T17:15:52.548841738Z","hostname":"w-01JJPY42J7TJ48QYFMTCCVFBHG","pid":1232,"":"downstairs","":"downstairs","session_id":"91d2e55c-b1f8-4102-bcf8-bf6cb85d3762"}
1922025-01-28T17:15:53.407Z{"msg":"All extents match","v":0,"name":"crucible","level":30,"time":"2025-01-28T17:15:52.548861415Z","hostname":"w-01JJPY42J7TJ48QYFMTCCVFBHG","pid":1232,"":"downstairs","":"downstairs","session_id":"91d2e55c-b1f8-4102-bcf8-bf6cb85d3762"}
1932025-01-28T17:15:53.407Z{"msg":"No downstairs reconciliation required","v":0,"name":"crucible","level":30,"time":"2025-01-28T17:15:52.548874363Z","hostname":"w-01JJPY42J7TJ48QYFMTCCVFBHG","pid":1232,"session_id":"91d2e55c-b1f8-4102-bcf8-bf6cb85d3762"}
1942025-01-28T17:15:53.407Z{"msg":"Transition from WaitQuorum to Active","v":0,"name":"crucible","level":30,"time":"2025-01-28T17:15:52.548893081Z","hostname":"w-01JJPY42J7TJ48QYFMTCCVFBHG","pid":1232,"client":"0","":"downstairs","session_id":"91d2e55c-b1f8-4102-bcf8-bf6cb85d3762"}
1952025-01-28T17:15:53.407Z{"msg":"Transition from WaitQuorum to Active","v":0,"name":"crucible","level":30,"time":"2025-01-28T17:15:52.548918766Z","hostname":"w-01JJPY42J7TJ48QYFMTCCVFBHG","pid":1232,"client":"1","":"downstairs","session_id":"91d2e55c-b1f8-4102-bcf8-bf6cb85d3762"}
1962025-01-28T17:15:53.408Z{"msg":"Transition from WaitQuorum to Active","v":0,"name":"crucible","level":30,"time":"2025-01-28T17:15:52.548932344Z","hostname":"w-01JJPY42J7TJ48QYFMTCCVFBHG","pid":1232,"client":"2","":"downstairs","session_id":"91d2e55c-b1f8-4102-bcf8-bf6cb85d3762"}
1972025-01-28T17:15:53.408Z{"msg":"All required reconciliation work is completed","v":0,"name":"crucible","level":30,"time":"2025-01-28T17:15:52.54896105Z","hostname":"w-01JJPY42J7TJ48QYFMTCCVFBHG","pid":1232,"session_id":"91d2e55c-b1f8-4102-bcf8-bf6cb85d3762"}
1982025-01-28T17:15:53.408Z{"msg":"Set Downstairs and Upstairs active after reconciliation","v":0,"name":"crucible","level":30,"time":"2025-01-28T17:15:52.548984916Z","hostname":"w-01JJPY42J7TJ48QYFMTCCVFBHG","pid":1232,"session_id":"91d2e55c-b1f8-4102-bcf8-bf6cb85d3762"}
1992025-01-28T17:15:53.408Z{"msg":"dd290b06-4ca0-4eb0-864b-c8c377f118ba is now active with session: 91d2e55c-b1f8-4102-bcf8-bf6cb85d3762","v":0,"name":"crucible","level":30,"time":"2025-01-28T17:15:52.549045477Z","hostname":"w-01JJPY42J7TJ48QYFMTCCVFBHG","pid":1232,"session_id":"91d2e55c-b1f8-4102-bcf8-bf6cb85d3762"}
2002025-01-28T17:15:53.408Z{"msg":"Set Active after no reconciliation","v":0,"name":"crucible","level":30,"time":"2025-01-28T17:15:52.549059274Z","hostname":"w-01JJPY42J7TJ48QYFMTCCVFBHG","pid":1232,"session_id":"91d2e55c-b1f8-4102-bcf8-bf6cb85d3762"}
2012025-01-28T17:15:53.408Z{"msg":"The guest has finished waiting for activation with:31","v":0,"name":"crucible","level":30,"time":"2025-01-28T17:15:52.549128313Z","hostname":"w-01JJPY42J7TJ48QYFMTCCVFBHG","pid":1232}
2022025-01-28T17:15:53.408Z{"msg":"The guest has requested activation with gen:31","v":0,"name":"crucible","level":30,"time":"2025-01-28T17:15:52.549231787Z","hostname":"w-01JJPY42J7TJ48QYFMTCCVFBHG","pid":1232}
2032025-01-28T17:15:53.408Z{"msg":"dd290b06-4ca0-4eb0-864b-c8c377f118ba active request set","v":0,"name":"crucible","level":30,"time":"2025-01-28T17:15:52.549251804Z","hostname":"w-01JJPY42J7TJ48QYFMTCCVFBHG","pid":1232,"session_id":"e2c09312-b196-4128-a2c3-44b3415d2bc6"}
2042025-01-28T17:15:53.408Z{"msg":"sending connect oneshot to client","v":0,"name":"crucible","level":30,"time":"2025-01-28T17:15:52.549285999Z","hostname":"w-01JJPY42J7TJ48QYFMTCCVFBHG","pid":1232,"client":"0","":"downstairs","session_id":"e2c09312-b196-4128-a2c3-44b3415d2bc6"}
2052025-01-28T17:15:53.408Z{"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-28T17:15:52.549315974Z","hostname":"w-01JJPY42J7TJ48QYFMTCCVFBHG","pid":1232,"client":"0","":"downstairs","session_id":"e2c09312-b196-4128-a2c3-44b3415d2bc6"}
2062025-01-28T17:15:53.408Z{"msg":"sending connect oneshot to client","v":0,"name":"crucible","level":30,"time":"2025-01-28T17:15:52.549345179Z","hostname":"w-01JJPY42J7TJ48QYFMTCCVFBHG","pid":1232,"client":"1","":"downstairs","session_id":"e2c09312-b196-4128-a2c3-44b3415d2bc6"}
2072025-01-28T17:15:53.408Z{"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-28T17:15:52.549374854Z","hostname":"w-01JJPY42J7TJ48QYFMTCCVFBHG","pid":1232,"client":"1","":"downstairs","session_id":"e2c09312-b196-4128-a2c3-44b3415d2bc6"}
2082025-01-28T17:15:53.408Z{"msg":"sending connect oneshot to client","v":0,"name":"crucible","level":30,"time":"2025-01-28T17:15:52.549399741Z","hostname":"w-01JJPY42J7TJ48QYFMTCCVFBHG","pid":1232,"client":"2","":"downstairs","session_id":"e2c09312-b196-4128-a2c3-44b3415d2bc6"}
2092025-01-28T17:15:53.408Z{"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-28T17:15:52.549414618Z","hostname":"w-01JJPY42J7TJ48QYFMTCCVFBHG","pid":1232,"client":"2","":"downstairs","session_id":"e2c09312-b196-4128-a2c3-44b3415d2bc6"}
2102025-01-28T17:15:53.408Z{"msg":"connecting to 127.0.0.1:8860","v":0,"name":"crucible","level":30,"time":"2025-01-28T17:15:52.549428626Z","hostname":"w-01JJPY42J7TJ48QYFMTCCVFBHG","pid":1232,"":"io task","client":"2","":"downstairs","session_id":"e2c09312-b196-4128-a2c3-44b3415d2bc6"}
2112025-01-28T17:15:53.408Z{"msg":"connecting to 127.0.0.1:8840","v":0,"name":"crucible","level":30,"time":"2025-01-28T17:15:52.549455682Z","hostname":"w-01JJPY42J7TJ48QYFMTCCVFBHG","pid":1232,"":"io task","client":"0","":"downstairs","session_id":"e2c09312-b196-4128-a2c3-44b3415d2bc6"}
2122025-01-28T17:15:53.408Z{"msg":"connecting to 127.0.0.1:8850","v":0,"name":"crucible","level":30,"time":"2025-01-28T17:15:52.549481538Z","hostname":"w-01JJPY42J7TJ48QYFMTCCVFBHG","pid":1232,"":"io task","client":"1","":"downstairs","session_id":"e2c09312-b196-4128-a2c3-44b3415d2bc6"}
2132025-01-28T17:15:53.408Z{"msg":"ds_connection connected from Ok(127.0.0.1:52031)","v":0,"name":"crucible","level":30,"time":"2025-01-28T17:15:52.549509003Z","hostname":"w-01JJPY42J7TJ48QYFMTCCVFBHG","pid":1232,"":"io task","client":"0","":"downstairs","session_id":"e2c09312-b196-4128-a2c3-44b3415d2bc6"}
2142025-01-28T17:15:53.408Z{"msg":"ds_connection connected from Ok(127.0.0.1:56308)","v":0,"name":"crucible","level":30,"time":"2025-01-28T17:15:52.549534679Z","hostname":"w-01JJPY42J7TJ48QYFMTCCVFBHG","pid":1232,"":"io task","client":"2","":"downstairs","session_id":"e2c09312-b196-4128-a2c3-44b3415d2bc6"}
2152025-01-28T17:15:53.408Z{"msg":"ds_connection connected from Ok(127.0.0.1:57759)","v":0,"name":"crucible","level":30,"time":"2025-01-28T17:15:52.549585341Z","hostname":"w-01JJPY42J7TJ48QYFMTCCVFBHG","pid":1232,"":"io task","client":"1","":"downstairs","session_id":"e2c09312-b196-4128-a2c3-44b3415d2bc6"}
2162025-01-28T17:15:53.408Z{"msg":"version negotiation from state Connecting { state: WaitForPromote, mode: New }","v":0,"name":"crucible","level":30,"time":"2025-01-28T17:15:52.549627754Z","hostname":"w-01JJPY42J7TJ48QYFMTCCVFBHG","pid":1232,"client":"2","":"downstairs","session_id":"e2c09312-b196-4128-a2c3-44b3415d2bc6"}
2172025-01-28T17:15:53.408Z{"msg":"version negotiation from state Connecting { state: WaitForPromote, mode: New }","v":0,"name":"crucible","level":30,"time":"2025-01-28T17:15:52.549669518Z","hostname":"w-01JJPY42J7TJ48QYFMTCCVFBHG","pid":1232,"client":"0","":"downstairs","session_id":"e2c09312-b196-4128-a2c3-44b3415d2bc6"}
2182025-01-28T17:15:53.408Z{"msg":"version negotiation from state Connecting { state: WaitForPromote, mode: New }","v":0,"name":"crucible","level":30,"time":"2025-01-28T17:15:52.549796898Z","hostname":"w-01JJPY42J7TJ48QYFMTCCVFBHG","pid":1232,"client":"1","":"downstairs","session_id":"e2c09312-b196-4128-a2c3-44b3415d2bc6"}
2192025-01-28T17:15:53.408Z{"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-28T17:15:52.550139184Z","hostname":"w-01JJPY42J7TJ48QYFMTCCVFBHG","pid":1232,"client":"2","":"downstairs","session_id":"e2c09312-b196-4128-a2c3-44b3415d2bc6"}
2202025-01-28T17:15:53.408Z{"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-28T17:15:52.550383605Z","hostname":"w-01JJPY42J7TJ48QYFMTCCVFBHG","pid":1232,"client":"0","":"downstairs","session_id":"e2c09312-b196-4128-a2c3-44b3415d2bc6"}
2212025-01-28T17:15:53.408Z{"msg":"Waiting for more clients to be ready","v":0,"name":"crucible","level":30,"time":"2025-01-28T17:15:52.550497227Z","hostname":"w-01JJPY42J7TJ48QYFMTCCVFBHG","pid":1232,"session_id":"e2c09312-b196-4128-a2c3-44b3415d2bc6"}
2222025-01-28T17:15:53.408Z{"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-28T17:15:52.55054506Z","hostname":"w-01JJPY42J7TJ48QYFMTCCVFBHG","pid":1232,"client":"1","":"downstairs","session_id":"e2c09312-b196-4128-a2c3-44b3415d2bc6"}
2232025-01-28T17:15:53.408Z{"msg":"Waiting for more clients to be ready","v":0,"name":"crucible","level":30,"time":"2025-01-28T17:15:52.550663681Z","hostname":"w-01JJPY42J7TJ48QYFMTCCVFBHG","pid":1232,"session_id":"e2c09312-b196-4128-a2c3-44b3415d2bc6"}
2242025-01-28T17:15:53.408Z{"msg":"[0]R flush_numbers: [5316, 5316, 5316, 5314, 5314]","v":0,"name":"crucible","level":30,"time":"2025-01-28T17:15:52.550872938Z","hostname":"w-01JJPY42J7TJ48QYFMTCCVFBHG","pid":1232,"":"downstairs","":"downstairs","session_id":"e2c09312-b196-4128-a2c3-44b3415d2bc6"}
2252025-01-28T17:15:53.408Z{"msg":"[0]R generation: [14, 14, 14, 13, 13]","v":0,"name":"crucible","level":30,"time":"2025-01-28T17:15:52.550902164Z","hostname":"w-01JJPY42J7TJ48QYFMTCCVFBHG","pid":1232,"":"downstairs","":"downstairs","session_id":"e2c09312-b196-4128-a2c3-44b3415d2bc6"}
2262025-01-28T17:15:53.408Z{"msg":"[0]R dirty: [false, false, false, false, false]","v":0,"name":"crucible","level":30,"time":"2025-01-28T17:15:52.550930619Z","hostname":"w-01JJPY42J7TJ48QYFMTCCVFBHG","pid":1232,"":"downstairs","":"downstairs","session_id":"e2c09312-b196-4128-a2c3-44b3415d2bc6"}
2272025-01-28T17:15:53.408Z{"msg":"[1]R flush_numbers: [5316, 5316, 5316, 5314, 5314]","v":0,"name":"crucible","level":30,"time":"2025-01-28T17:15:52.550952525Z","hostname":"w-01JJPY42J7TJ48QYFMTCCVFBHG","pid":1232,"":"downstairs","":"downstairs","session_id":"e2c09312-b196-4128-a2c3-44b3415d2bc6"}
2282025-01-28T17:15:53.408Z{"msg":"[1]R generation: [14, 14, 14, 13, 13]","v":0,"name":"crucible","level":30,"time":"2025-01-28T17:15:52.550967533Z","hostname":"w-01JJPY42J7TJ48QYFMTCCVFBHG","pid":1232,"":"downstairs","":"downstairs","session_id":"e2c09312-b196-4128-a2c3-44b3415d2bc6"}
2292025-01-28T17:15:53.408Z{"msg":"[1]R dirty: [false, false, false, false, false]","v"Wait for a query_work_queue command to finish before sending IO
2302025-01-28T17:15:53.408Z:0,"name":"crucible","level":30,"time":"2025-01-28T17:15:52.550997358Z","hostname":"w-01JJPY42J7TJ48QYFMTCCVFBHG","pid":1232,"":"downstairs","":"downstairs","session_id":"e2c09312-b196-4128-a2c3-44b3415d2bc6"}
2312025-01-28T17:15:53.408Z{"msg":"[2]R flush_numbers: [5316, 5316, 5316, 5314, 5314]","v":0,"name":"crucible","level":30,"time":"2025-01-28T17:15:52.551012306Z","hostname":"w-01JJPY42J7TJ48QYFMTCCVFBHG","pid":1232,"":"downstairs","":"downstairs","session_id":"e2c09312-b196-4128-a2c3-44b3415d2bc6"}
2322025-01-28T17:15:53.408Z{"msg":"[2]R generation: [14, 14, 14, 13, 13]","v":0,"name":"crucible","level":30,"time":"2025-01-28T17:15:52.551034643Z","hostname":"w-01JJPY42J7TJ48QYFMTCCVFBHG","pid":1232,"":"downstairs","":"downstairs","session_id":"e2c09312-b196-4128-a2c3-44b3415d2bc6"}
2332025-01-28T17:15:53.408Z{"msg":"[2]R dirty: [false, false, false, false, false]","v":0,"name":"crucible","level":30,"time":"2025-01-28T17:15:52.551048321Z","hostname":"w-01JJPY42J7TJ48QYFMTCCVFBHG","pid":1232,"":"downstairs","":"downstairs","session_id":"e2c09312-b196-4128-a2c3-44b3415d2bc6"}
2342025-01-28T17:15:53.408Z{"msg":"Max found gen is 15","v":0,"name":"crucible","level":30,"time":"2025-01-28T17:15:52.551062378Z","hostname":"w-01JJPY42J7TJ48QYFMTCCVFBHG","pid":1232,"":"downstairs","":"downstairs","session_id":"e2c09312-b196-4128-a2c3-44b3415d2bc6"}
2352025-01-28T17:15:53.409Z{"msg":"Generation requested: 31 >= found:15","v":0,"name":"crucible","level":30,"time":"2025-01-28T17:15:52.551082455Z","hostname":"w-01JJPY42J7TJ48QYFMTCCVFBHG","pid":1232,"":"downstairs","":"downstairs","session_id":"e2c09312-b196-4128-a2c3-44b3415d2bc6"}
2362025-01-28T17:15:53.409Z{"msg":"Next flush: 5317","v":0,"name":"crucible","level":30,"time":"2025-01-28T17:15:52.551096233Z","hostname":"w-01JJPY42J7TJ48QYFMTCCVFBHG","pid":1232,"":"downstairs","":"downstairs","session_id":"e2c09312-b196-4128-a2c3-44b3415d2bc6"}
2372025-01-28T17:15:53.409Z{"msg":"All extents match","v":0,"name":"crucible","level":30,"time":"2025-01-28T17:15:52.55111644Z","hostname":"w-01JJPY42J7TJ48QYFMTCCVFBHG","pid":1232,"":"downstairs","":"downstairs","session_id":"e2c09312-b196-4128-a2c3-44b3415d2bc6"}
2382025-01-28T17:15:53.409Z{"msg":"No downstairs reconciliation required","v":0,"name":"crucible","level":30,"time":"2025-01-28T17:15:52.551130677Z","hostname":"w-01JJPY42J7TJ48QYFMTCCVFBHG","pid":1232,"session_id":"e2c09312-b196-4128-a2c3-44b3415d2bc6"}
2392025-01-28T17:15:53.409Z{"msg":"Transition from WaitQuorum to Active","v":0,"name":"crucible","level":30,"time":"2025-01-28T17:15:52.551142666Z","hostname":"w-01JJPY42J7TJ48QYFMTCCVFBHG","pid":1232,"client":"0","":"downstairs","session_id":"e2c09312-b196-4128-a2c3-44b3415d2bc6"}
2402025-01-28T17:15:53.409Z{"msg":"Transition from WaitQuorum to Active","v":0,"name":"crucible","level":30,"time":"2025-01-28T17:15:52.551155644Z","hostname":"w-01JJPY42J7TJ48QYFMTCCVFBHG","pid":1232,"client":"1","":"downstairs","session_id":"e2c09312-b196-4128-a2c3-44b3415d2bc6"}
2412025-01-28T17:15:53.409Z{"msg":"Transition from WaitQuorum to Active","v":0,"name":"crucible","level":30,"time":"2025-01-28T17:15:52.55117588Z","hostname":"w-01JJPY42J7TJ48QYFMTCCVFBHG","pid":1232,"client":"2","":"downstairs","session_id":"e2c09312-b196-4128-a2c3-44b3415d2bc6"}
2422025-01-28T17:15:53.409Z{"msg":"All required reconciliation work is completed","v":0,"name":"crucible","level":30,"time":"2025-01-28T17:15:52.551189398Z","hostname":"w-01JJPY42J7TJ48QYFMTCCVFBHG","pid":1232,"session_id":"e2c09312-b196-4128-a2c3-44b3415d2bc6"}
2432025-01-28T17:15:53.409Z{"msg":"Set Downstairs and Upstairs active after reconciliation","v":0,"name":"crucible","level":30,"time":"2025-01-28T17:15:52.551201406Z","hostname":"w-01JJPY42J7TJ48QYFMTCCVFBHG","pid":1232,"session_id":"e2c09312-b196-4128-a2c3-44b3415d2bc6"}
2442025-01-28T17:15:53.409Z{"msg":"dd290b06-4ca0-4eb0-864b-c8c377f118ba is now active with session: e2c09312-b196-4128-a2c3-44b3415d2bc6","v":0,"name":"crucible","level":30,"time":"2025-01-28T17:15:52.551214094Z","hostname":"w-01JJPY42J7TJ48QYFMTCCVFBHG","pid":1232,"session_id":"e2c09312-b196-4128-a2c3-44b3415d2bc6"}
2452025-01-28T17:15:53.409Z{"msg":"Set Active after no reconciliation","v":0,"name":"crucible","level":30,"time":"2025-01-28T17:15:52.551225733Z","hostname":"w-01JJPY42J7TJ48QYFMTCCVFBHG","pid":1232,"session_id":"e2c09312-b196-4128-a2c3-44b3415d2bc6"}
2462025-01-28T17:15:53.409Z{"msg":"The guest has finished waiting for activation with:31","v":0,"name":"crucible","level":30,"time":"2025-01-28T17:15:52.55123896Z","hostname":"w-01JJPY42J7TJ48QYFMTCCVFBHG","pid":1232}
2472025-01-28T17:15:53.409ZDisk: sv:2 bs:4096 ts:409600 tb:100 max_io:100 or 409600
2482025-01-28T17:15:53.409ZFill test
2492025-01-28T17:15:53.448ZRead and Verify all blocks (0..100 range:false)
2502025-01-28T17:15:53.529ZWrote out file "/var/tmp/test_up-build/verify_file"
2512025-01-28T17:15:53.529ZCLIENT: Tests done. All submitted work has been ACK'd
2522025-01-28T17:15:53.532Z----------------------------------------------------------------
2532025-01-28T17:15:53.532Z Crucible gen:31 GIO:true work queues: Upstairs:0 downstairs:1
2542025-01-28T17:15:53.532ZStates: Active Active Active
2552025-01-28T17:15:53.532ZJOBID ACK TYPE BKS/EXT DS:0 DS:1 DS:2 REPLAY
2562025-01-28T17:15:53.532Z 1002 Acked Read 50 Done Done Done false
2572025-01-28T17:15:53.532Z STATES DS:0 DS:1 DS:2 TOTAL
2582025-01-28T17:15:53.532Z Sent 0 0 0 0
2592025-01-28T17:15:53.532Z Done 1 1 1 3
2602025-01-28T17:15:53.532Z Skipped 0 0 0 0
2612025-01-28T17:15:53.532Z Error 0 0 0 0
2622025-01-28T17:15:53.532ZLast Flush: Some(JobId(1001)) Some(JobId(1001)) Some(JobId(1001))
2632025-01-28T17:15:53.532ZDownstairs last five completed: 1001 1000
2642025-01-28T17:15:53.532ZUpstairs last five completed: 1002 1001 1000
2652025-01-28T17:15:53.532Z----------------------------------------------------------------
2662025-01-28T17:15:53.532Z Crucible gen:31 GIO:true work queues: Upstairs:0 downstairs:1
2672025-01-28T17:15:53.532ZStates: Active Active Active
2682025-01-28T17:15:53.532ZJOBID ACK TYPE BKS/EXT DS:0 DS:1 DS:2 REPLAY
2692025-01-28T17:15:53.532Z 1002 Acked Read 50 Done Done Done false
2702025-01-28T17:15:53.532Z STATES DS:0 DS:1 DS:2 TOTAL
2712025-01-28T17:15:53.532Z Sent 0 0 0 0
2722025-01-28T17:15:53.532Z Done 1 1 1 3
2732025-01-28T17:15:53.532Z Skipped 0 0 0 0
2742025-01-28T17:15:53.532Z Error 0 0 0 0
2752025-01-28T17:15:53.532ZLast Flush: Some(JobId(1001)) Some(JobId(1001)) Some(JobId(1001))
2762025-01-28T17:15:53.532ZDownstairs last five completed: 1001 1000
2772025-01-28T17:15:53.532ZUpstairs last five completed: 1002 1001 1000
2782025-01-28T17:15:53.532ZCLIENT: Up:0 ds:2 act:6
2792025-01-28T17:15:57.531Z----------------------------------------------------------------
2802025-01-28T17:15:57.531Z Crucible gen:31 GIO:true work queues: Upstairs:0 downstairs:0
2812025-01-28T17:15:57.531ZDownstairs last five completed: 1003 1002 1001 1000
2822025-01-28T17:15:57.531ZUpstairs last five completed: 1003 1002 1001 1000
2832025-01-28T17:15:57.531Z----------------------------------------------------------------
2842025-01-28T17:15:57.531Z Crucible gen:31 GIO:true work queues: Upstairs:0 downstairs:0
2852025-01-28T17:15:57.532ZDownstairs last five completed: 1003 1002 1001 1000
2862025-01-28T17:15:57.532ZUpstairs last five completed: 1003 1002 1001 1000
2872025-01-28T17:15:57.535ZCLIENT: Up:0 ds:0 act:6
2882025-01-28T17:15:57.535ZCLIENT: All crucible jobs finished, exiting program
2892025-01-28T17:15:57.535Z{"msg":"Guest handle has been dropped","v":0,"name":"crucible","level":40,"time":"2025-01-28T17:15:56.678590429Z","hostname":"w-01JJPY42J7TJ48QYFMTCCVFBHG","pid":1232}
2902025-01-28T17:15:57.544ZRepair setup passed
2912025-01-28T17:15:57.548ZCopy the region for /var/tmp/test_up-build/8830
2922025-01-28T17:15:57.551Zcp -r /var/tmp/test_up-build/8830 /var/tmp/test_up-build/previous
2932025-01-28T17:15:57.553Z/var/tmp/bins/crutest fill -g 32 -q --key 9q52nrwZdyxSwBF6A/1uxpEIrPl6wZEZ1P9sUqSfLyg= --dsc 127.0.0.1:9998 --verify-out /var/tmp/test_up-build/verify_file --verify-in /var/tmp/test_up-build/verify_file
2942025-01-28T17:15:57.614Z{"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-28T17:15:56.760143665Z","hostname":"w-01JJPY42J7TJ48QYFMTCCVFBHG","pid":1238,"task":"crutest"}
2952025-01-28T17:15:57.617Z{"msg":"dsc has 6 regions. This means 2 sub_volumes","v":0,"name":"crucible","level":30,"time":"2025-01-28T17:15:56.760764807Z","hostname":"w-01JJPY42J7TJ48QYFMTCCVFBHG","pid":1238,"task":"crutest"}
2962025-01-28T17:15:57.617Z{"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-28T17:15:56.762427724Z","hostname":"w-01JJPY42J7TJ48QYFMTCCVFBHG","pid":1238,"task":"crutest"}
2972025-01-28T17:15:57.617Z{"msg":"Upstairs starts","v":0,"name":"crucible","level":30,"time":"2025-01-28T17:15:56.762664967Z","hostname":"w-01JJPY42J7TJ48QYFMTCCVFBHG","pid":1238}
2982025-01-28T17:15:57.617Z{"msg":"Crucible Version: BuildInfo {\n version: \"0.0.1\",\n git_sha: \"752fd3e208a28c201ec7c5e297caafe64bf1aaf2\",\n git_commit_timestamp: \"2025-01-28T16:52:48.000000000Z\",\n git_branch: \"alan/where-my-writes-at\",\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-28T17:15:56.762718498Z","hostname":"w-01JJPY42J7TJ48QYFMTCCVFBHG","pid":1238}
2992025-01-28T17:15:57.617Z{"msg":"Upstairs <-> Downstairs Message Version: 13","v":0,"name":"crucible","level":30,"time":"2025-01-28T17:15:56.762743234Z","hostname":"w-01JJPY42J7TJ48QYFMTCCVFBHG","pid":1238}
3002025-01-28T17:15:57.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-28T17:15:56.762758992Z","hostname":"w-01JJPY42J7TJ48QYFMTCCVFBHG","pid":1238}
3012025-01-28T17:15:57.618Z{"msg":"Crucible a5335ce3-b249-490c-a581-0c02c7b15ee8 has session id: 79a82e2b-0bde-4c92-b1fe-c1ad859cac62","v":0,"name":"crucible","level":30,"time":"2025-01-28T17:15:56.763396072Z","hostname":"w-01JJPY42J7TJ48QYFMTCCVFBHG","pid":1238,"session_id":"79a82e2b-0bde-4c92-b1fe-c1ad859cac62"}
3022025-01-28T17:15:57.618Z{"msg":"Upstairs opts: Upstairs UUID: a5335ce3-b249-490c-a581-0c02c7b15ee8, 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-28T17:15:56.763444984Z","hostname":"w-01JJPY42J7TJ48QYFMTCCVFBHG","pid":1238,"session_id":"79a82e2b-0bde-4c92-b1fe-c1ad859cac62"}
3032025-01-28T17:15:57.618Z{"msg":"Crucible stats registered with UUID: a5335ce3-b249-490c-a581-0c02c7b15ee8","v":0,"name":"crucible","level":30,"time":"2025-01-28T17:15:56.763462701Z","hostname":"w-01JJPY42J7TJ48QYFMTCCVFBHG","pid":1238,"session_id":"79a82e2b-0bde-4c92-b1fe-c1ad859cac62"}
3042025-01-28T17:15:57.618Z{"msg":"could not find Downstairs address for Nexus","v":0,"name":"crucible","level":40,"time":"2025-01-28T17:15:56.763484408Z","hostname":"w-01JJPY42J7TJ48QYFMTCCVFBHG","pid":1238,"session_id":"79a82e2b-0bde-4c92-b1fe-c1ad859cac62"}
3052025-01-28T17:15:57.621Z{"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-28T17:15:56.765581957Z","hostname":"w-01JJPY42J7TJ48QYFMTCCVFBHG","pid":1238,"task":"crutest"}
3062025-01-28T17:15:57.621Z{"msg":"Upstairs starts","v":0,"name":"crucible","level":30,"time":"2025-01-28T17:15:56.76568485Z","hostname":"w-01JJPY42J7TJ48QYFMTCCVFBHG","pid":1238}
3072025-01-28T17:15:57.621Z{"msg":"Crucible Version: BuildInfo {\n version: \"0.0.1\",\n git_sha: \"752fd3e208a28c201ec7c5e297caafe64bf1aaf2\",\n git_commit_timestamp: \"2025-01-28T16:52:48.000000000Z\",\n git_branch: \"alan/where-my-writes-at\",\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-28T17:15:56.765730383Z","hostname":"w-01JJPY42J7TJ48QYFMTCCVFBHG","pid":1238}
3082025-01-28T17:15:57.621Z{"msg":"Upstairs <-> Downstairs Message Version: 13","v":0,"name":"crucible","level":30,"time":"2025-01-28T17:15:56.76575151Z","hostname":"w-01JJPY42J7TJ48QYFMTCCVFBHG","pid":1238}
3092025-01-28T17:15:57.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-28T17:15:56.765766448Z","hostname":"w-01JJPY42J7TJ48QYFMTCCVFBHG","pid":1238}
3102025-01-28T17:15:57.621Z{"msg":"Crucible a5335ce3-b249-490c-a581-0c02c7b15ee8 has session id: 9eea4de8-b9e4-42d2-89da-e97192fb2bab","v":0,"name":"crucible","level":30,"time":"2025-01-28T17:15:56.766163575Z","hostname":"w-01JJPY42J7TJ48QYFMTCCVFBHG","pid":1238,"session_id":"9eea4de8-b9e4-42d2-89da-e97192fb2bab"}
3112025-01-28T17:15:57.621Z{"msg":"Upstairs opts: Upstairs UUID: a5335ce3-b249-490c-a581-0c02c7b15ee8, 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-28T17:15:56.766220046Z","hostname":"w-01JJPY42J7TJ48QYFMTCCVFBHG","pid":1238,"session_id":"9eea4de8-b9e4-42d2-89da-e97192fb2bab"}
3122025-01-28T17:15:57.621Z{"msg":"Crucible stats registered with UUID: a5335ce3-b249-490c-a581-0c02c7b15ee8","v":0,"name":"crucible","level":30,"time":"2025-01-28T17:15:56.76625858Z","hostname":"w-01JJPY42J7TJ48QYFMTCCVFBHG","pid":1238,"session_id":"9eea4de8-b9e4-42d2-89da-e97192fb2bab"}
3132025-01-28T17:15:57.621Z{"msg":"could not find Downstairs address for Nexus","v":0,"name":"crucible","level":40,"time":"2025-01-28T17:15:56.766283776Z","hostname":"w-01JJPY42J7TJ48QYFMTCCVFBHG","pid":1238,"session_id":"9eea4de8-b9e4-42d2-89da-e97192fb2bab"}
3142025-01-28T17:15:57.621Z{"msg":"Downstairs in volume = 6","v":0,"name":"crucible","level":30,"time":"2025-01-28T17:15:56.767298356Z","hostname":"w-01JJPY42J7TJ48QYFMTCCVFBHG","pid":1238,"task":"crutest"}
3152025-01-28T17:15:57.621Z{"msg":"The guest has requested activation with gen:32","v":0,"name":"crucible","level":30,"time":"2025-01-28T17:15:56.767330871Z","hostname":"w-01JJPY42J7TJ48QYFMTCCVFBHG","pid":1238}
3162025-01-28T17:15:57.621Z{"msg":"a5335ce3-b249-490c-a581-0c02c7b15ee8 active request set","v":0,"name":"crucible","level":30,"time":"2025-01-28T17:15:56.767393561Z","hostname":"w-01JJPY42J7TJ48QYFMTCCVFBHG","pid":1238,"session_id":"79a82e2b-0bde-4c92-b1fe-c1ad859cac62"}
3172025-01-28T17:15:57.621Z{"msg":"sending connect oneshot to client","v":0,"name":"crucible","level":30,"time":"2025-01-28T17:15:56.767421887Z","hostname":"w-01JJPY42J7TJ48QYFMTCCVFBHG","pid":1238,"client":"0","":"downstairs","session_id":"79a82e2b-0bde-4c92-b1fe-c1ad859cac62"}
3182025-01-28T17:15:57.621Z{"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-28T17:15:56.767446693Z","hostname":"w-01JJPY42J7TJ48QYFMTCCVFBHG","pid":1238,"client":"0","":"downstairs","session_id":"79a82e2b-0bde-4c92-b1fe-c1ad859cac62"}
3192025-01-28T17:15:57.621Z{"msg":"sending connect oneshot to client","v":0,"name":"crucible","level":30,"time":"2025-01-28T17:15:56.767517352Z","hostname":"w-01JJPY42J7TJ48QYFMTCCVFBHG","pid":1238,"client":"1","":"downstairs","session_id":"79a82e2b-0bde-4c92-b1fe-c1ad859cac62"}
3202025-01-28T17:15:57.621Z{"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-28T17:15:56.767547147Z","hostname":"w-01JJPY42J7TJ48QYFMTCCVFBHG","pid":1238,"client":"1","":"downstairs","session_id":"79a82e2b-0bde-4c92-b1fe-c1ad859cac62"}
3212025-01-28T17:15:57.622Z{"msg":"sending connect oneshot to client","v":0,"name":"crucible","level":30,"time":"2025-01-28T17:15:56.767596909Z","hostname":"w-01JJPY42J7TJ48QYFMTCCVFBHG","pid":1238,"client":"2","":"downstairs","session_id":"79a82e2b-0bde-4c92-b1fe-c1ad859cac62"}
3222025-01-28T17:15:57.622Z{"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-28T17:15:56.767643302Z","hostname":"w-01JJPY42J7TJ48QYFMTCCVFBHG","pid":1238,"client":"2","":"downstairs","session_id":"79a82e2b-0bde-4c92-b1fe-c1ad859cac62"}
3232025-01-28T17:15:57.622Z{"msg":"connecting to 127.0.0.1:8810","v":0,"name":"crucible","level":30,"time":"2025-01-28T17:15:56.767670028Z","hostname":"w-01JJPY42J7TJ48QYFMTCCVFBHG","pid":1238,"":"io task","client":"0","":"downstairs","session_id":"79a82e2b-0bde-4c92-b1fe-c1ad859cac62"}
3242025-01-28T17:15:57.622Z{"msg":"connecting to 127.0.0.1:8830","v":0,"name":"crucible","level":30,"time":"2025-01-28T17:15:56.767704432Z","hostname":"w-01JJPY42J7TJ48QYFMTCCVFBHG","pid":1238,"":"io task","client":"2","":"downstairs","session_id":"79a82e2b-0bde-4c92-b1fe-c1ad859cac62"}
3252025-01-28T17:15:57.622Z{"msg":"connecting to 127.0.0.1:8820","v":0,"name":"crucible","level":30,"time":"2025-01-28T17:15:56.767730968Z","hostname":"w-01JJPY42J7TJ48QYFMTCCVFBHG","pid":1238,"":"io task","client":"1","":"downstairs","session_id":"79a82e2b-0bde-4c92-b1fe-c1ad859cac62"}
3262025-01-28T17:15:57.622Z{"msg":"ds_connection connected from Ok(127.0.0.1:63675)","v":0,"name":"crucible","level":30,"time":"2025-01-28T17:15:56.767755044Z","hostname":"w-01JJPY42J7TJ48QYFMTCCVFBHG","pid":1238,"":"io task","client":"0","":"downstairs","session_id":"79a82e2b-0bde-4c92-b1fe-c1ad859cac62"}
3272025-01-28T17:15:57.622Z{"msg":"ds_connection connected from Ok(127.0.0.1:62968)","v":0,"name":"crucible","level":30,"time":"2025-01-28T17:15:56.76778123Z","hostname":"w-01JJPY42J7TJ48QYFMTCCVFBHG","pid":1238,"":"io task","client":"2","":"downstairs","session_id":"79a82e2b-0bde-4c92-b1fe-c1ad859cac62"}
3282025-01-28T17:15:57.622Z{"msg":"ds_connection connected from Ok(127.0.0.1:40129)","v":0,"name":"crucible","level":30,"time":"2025-01-28T17:15:56.767806476Z","hostname":"w-01JJPY42J7TJ48QYFMTCCVFBHG","pid":1238,"":"io task","client":"1","":"downstairs","session_id":"79a82e2b-0bde-4c92-b1fe-c1ad859cac62"}
3292025-01-28T17:15:57.625Z{"msg":"version negotiation from state Connecting { state: WaitForPromote, mode: New }","v":0,"name":"crucible","level":30,"time":"2025-01-28T17:15:56.768517364Z","hostname":"w-01JJPY42J7TJ48QYFMTCCVFBHG","pid":1238,"client":"0","":"downstairs","session_id":"79a82e2b-0bde-4c92-b1fe-c1ad859cac62"}
3302025-01-28T17:15:57.625Z{"msg":"version negotiation from state Connecting { state: WaitForPromote, mode: New }","v":0,"name":"crucible","level":30,"time":"2025-01-28T17:15:56.768560337Z","hostname":"w-01JJPY42J7TJ48QYFMTCCVFBHG","pid":1238,"client":"2","":"downstairs","session_id":"79a82e2b-0bde-4c92-b1fe-c1ad859cac62"}
3312025-01-28T17:15:57.625Z{"msg":"version negotiation from state Connecting { state: WaitForPromote, mode: New }","v":0,"name":"crucible","level":30,"time":"2025-01-28T17:15:56.768599361Z","hostname":"w-01JJPY42J7TJ48QYFMTCCVFBHG","pid":1238,"client":"1","":"downstairs","session_id":"79a82e2b-0bde-4c92-b1fe-c1ad859cac62"}
3322025-01-28T17:15:57.625Z{"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-28T17:15:56.769122848Z","hostname":"w-01JJPY42J7TJ48QYFMTCCVFBHG","pid":1238,"client":"1","":"downstairs","session_id":"79a82e2b-0bde-4c92-b1fe-c1ad859cac62"}
3332025-01-28T17:15:57.625Z{"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-28T17:15:56.769260946Z","hostname":"w-01JJPY42J7TJ48QYFMTCCVFBHG","pid":1238,"client":"2","":"downstairs","session_id":"79a82e2b-0bde-4c92-b1fe-c1ad859cac62"}
3342025-01-28T17:15:57.625Z{"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-28T17:15:56.769356451Z","hostname":"w-01JJPY42J7TJ48QYFMTCCVFBHG","pid":1238,"client":"0","":"downstairs","session_id":"79a82e2b-0bde-4c92-b1fe-c1ad859cac62"}
3352025-01-28T17:15:57.625Z{"msg":"Waiting for more clients to be ready","v":0,"name":"crucible","level":30,"time":"2025-01-28T17:15:56.769501639Z","hostname":"w-01JJPY42J7TJ48QYFMTCCVFBHG","pid":1238,"session_id":"79a82e2b-0bde-4c92-b1fe-c1ad859cac62"}
3362025-01-28T17:15:57.626Z{"msg":"Waiting for more clients to be ready","v":0,"name":"crucible","level":30,"time":"2025-01-28T17:15:56.769594944Z","hostname":"w-01JJPY42J7TJ48QYFMTCCVFBHG","pid":1238,"session_id":"79a82e2b-0bde-4c92-b1fe-c1ad859cac62"}
3372025-01-28T17:15:57.626Z{"msg":"[0]R flush_numbers: [3992, 3992, 3992, 3992, 3992]","v":0,"name":"crucible","level":30,"time":"2025-01-28T17:15:56.769727963Z","hostname":"w-01JJPY42J7TJ48QYFMTCCVFBHG","pid":1238,"":"downstairs","":"downstairs","session_id":"79a82e2b-0bde-4c92-b1fe-c1ad859cac62"}
3382025-01-28T17:15:57.626Z{"msg":"[0]R generation: [31, 31, 31, 31, 31]","v":0,"name":"crucible","level":30,"time":"2025-01-28T17:15:56.769756298Z","hostname":"w-01JJPY42J7TJ48QYFMTCCVFBHG","pid":1238,"":"downstairs","":"downstairs","session_id":"79a82e2b-0bde-4c92-b1fe-c1ad859cac62"}
3392025-01-28T17:15:57.626Z{"msg":"[0]R dirty: [false, false, false, false, false]","v":0,"name":"crucible","level":30,"time":"2025-01-28T17:15:56.769771866Z","hostname":"w-01JJPY42J7TJ48QYFMTCCVFBHG","pid":1238,"":"downstairs","":"downstairs","session_id":"79a82e2b-0bde-4c92-b1fe-c1ad859cac62"}
3402025-01-28T17:15:57.626Z{"msg":"[1]R flush_numbers: [3992, 3992, 3992, 3992, 3992]","v":0,"name":"crucible","level":30,"time":"2025-01-28T17:15:56.769785634Z","hostname":"w-01JJPY42J7TJ48QYFMTCCVFBHG","pid":1238,"":"downstairs","":"downstairs","session_id":"79a82e2b-0bde-4c92-b1fe-c1ad859cac62"}
3412025-01-28T17:15:57.626Z{"msg":"[1]R generation: [31, 31, 31, 31, 31]","v":0,"name":"crucible","level":30,"time":"2025-01-28T17:15:56.769806231Z","hostname":"w-01JJPY42J7TJ48QYFMTCCVFBHG","pid":1238,"":"downstairs","":"downstairs","session_id":"79a82e2b-0bde-4c92-b1fe-c1ad859cac62"}
3422025-01-28T17:15:57.626Z{"msg":"[1]R dirty: [false, false, false, false, false]","v":0,"name":"crucible","level":30,"time":"2025-01-28T17:15:56.769820928Z","hostname":"w-01JJPY42J7TJ48QYFMTCCVFBHG","pid":1238,"":"downstairs","":"downstairs","session_id":"79a82e2b-0bde-4c92-b1fe-c1ad859cac62"}
3432025-01-28T17:15:57.626Z{"msg":"[2]R flush_numbers: [3992, 3992, 3992, 3992, 3992]","v":0,"name":"crucible","level":30,"time":"2025-01-28T17:15:56.769836156Z","hostname":"w-01JJPY42J7TJ48QYFMTCCVFBHG","pid":1238,"":"downstairs","":"downstairs","session_id":"79a82e2b-0bde-4c92-b1fe-c1ad859cac62"}
3442025-01-28T17:15:57.626Z{"msg":"[2]R generation: [31, 31, 31, 31, 31]","v":0,"name":"crucible","level":30,"time":"2025-01-28T17:15:56.769869561Z","hostname":"w-01JJPY42J7TJ48QYFMTCCVFBHG","pid":1238,"":"downstairs","":"downstairs","session_id":"79a82e2b-0bde-4c92-b1fe-c1ad859cac62"}
3452025-01-28T17:15:57.626Z{"msg":"[2]R dirty: [false, false, false, false, false]","v":0,"name":"crucible","level":30,"time":"2025-01-28T17:15:56.769901755Z","hostname":"w-01JJPY42J7TJ48QYFMTCCVFBHG","pid":1238,"":"downstairs","":"downstairs","session_id":"79a82e2b-0bde-4c92-b1fe-c1ad859cac62"}
3462025-01-28T17:15:57.626Z{"msg":"Max found gen is 32","v":0,"name":"crucible","level":30,"time":"2025-01-28T17:15:56.76993564Z","hostname":"w-01JJPY42J7TJ48QYFMTCCVFBHG","pid":1238,"":"downstairs","":"downstairs","session_id":"79a82e2b-0bde-4c92-b1fe-c1ad859cac62"}
3472025-01-28T17:15:57.626Z{"msg":"Generation requested: 32 >= found:32","v":0,"name":"crucible","level":30,"time":"2025-01-28T17:15:56.769958626Z","hostname":"w-01JJPY42J7TJ48QYFMTCCVFBHG","pid":1238,"":"downstairs","":"downstairs","session_id":"79a82e2b-0bde-4c92-b1fe-c1ad859cac62"}
3482025-01-28T17:15:57.626Z{"msg":"Next flush: 3993","v":0,"name":"crucible","level":30,"time":"2025-01-28T17:15:56.769992001Z","hostname":"w-01JJPY42J7TJ48QYFMTCCVFBHG","pid":1238,"":"downstairs","":"downstairs","session_id":"79a82e2b-0bde-4c92-b1fe-c1ad859cac62"}
3492025-01-28T17:15:57.626Z{"msg":"All extents match","v":0,"name":"crucible","level":30,"time":"2025-01-28T17:15:56.770030025Z","hostname":"w-01JJPY42J7TJ48QYFMTCCVFBHG","pid":1238,"":"downstairs","":"downstairs","session_id":"79a82e2b-0bde-4c92-b1fe-c1ad859cac62"}
3502025-01-28T17:15:57.626Z{"msg":"No downstairs reconciliation required","v":0,"name":"crucible","level":30,"time":"2025-01-28T17:15:56.770068259Z","hostname":"w-01JJPY42J7TJ48QYFMTCCVFBHG","pid":1238,"session_id":"79a82e2b-0bde-4c92-b1fe-c1ad859cac62"}
3512025-01-28T17:15:57.626Z{"msg":"Transition from WaitQuorum to Active","v":0,"name":"crucible","level":30,"time":"2025-01-28T17:15:56.770106223Z","hostname":"w-01JJPY42J7TJ48QYFMTCCVFBHG","pid":1238,"client":"0","":"downstairs","session_id":"79a82e2b-0bde-4c92-b1fe-c1ad859cac62"}
3522025-01-28T17:15:57.626Z{"msg":"Transition from WaitQuorum to Active","v":0,"name":"crucible","level":30,"time":"2025-01-28T17:15:56.770134509Z","hostname":"w-01JJPY42J7TJ48QYFMTCCVFBHG","pid":1238,"client":"1","":"downstairs","session_id":"79a82e2b-0bde-4c92-b1fe-c1ad859cac62"}
3532025-01-28T17:15:57.626Z{"msg":"Transition from WaitQuorum to Active","v":0,"name":"crucible","level":30,"time":"2025-01-28T17:15:56.770172663Z","hostname":"w-01JJPY42J7TJ48QYFMTCCVFBHG","pid":1238,"client":"2","":"downstairs","session_id":"79a82e2b-0bde-4c92-b1fe-c1ad859cac62"}
3542025-01-28T17:15:57.626Z{"msg":"All required reconciliation work is completed","v":0,"name":"crucible","level":30,"time":"2025-01-28T17:15:56.770209197Z","hostname":"w-01JJPY42J7TJ48QYFMTCCVFBHG","pid":1238,"session_id":"79a82e2b-0bde-4c92-b1fe-c1ad859cac62"}
3552025-01-28T17:15:57.626Z{"msg":"Set Downstairs and Upstairs active after reconciliation","v":0,"name":"crucible","level":30,"time":"2025-01-28T17:15:56.770232883Z","hostname":"w-01JJPY42J7TJ48QYFMTCCVFBHG","pid":1238,"session_id":"79a82e2b-0bde-4c92-b1fe-c1ad859cac62"}
3562025-01-28T17:15:57.626Z{"msg":"a5335ce3-b249-490c-a581-0c02c7b15ee8 is now active with session: 79a82e2b-0bde-4c92-b1fe-c1ad859cac62","v":0,"name":"crucible","level":30,"time":"2025-01-28T17:15:56.770420034Z","hostname":"w-01JJPY42J7TJ48QYFMTCCVFBHG","pid":1238,"session_id":"79a82e2b-0bde-4c92-b1fe-c1ad859cac62"}
3572025-01-28T17:15:57.626Z{"msg":"Set Active after no reconciliation","v":0,"name":"crucible","level":30,"time":"2025-01-28T17:15:56.77044463Z","hostname":"w-01JJPY42J7TJ48QYFMTCCVFBHG","pid":1238,"session_id":"79a82e2b-0bde-4c92-b1fe-c1ad859cac62"}
3582025-01-28T17:15:57.626Z{"msg":"The guest has finished waiting for activation with:32","v":0,"name":"crucible","level":30,"time":"2025-01-28T17:15:56.770465746Z","hostname":"w-01JJPY42J7TJ48QYFMTCCVFBHG","pid":1238}
3592025-01-28T17:15:57.626Z{"msg":"The guest has requested activation with gen:32","v":0,"name":"crucible","level":30,"time":"2025-01-28T17:15:56.77050822Z","hostname":"w-01JJPY42J7TJ48QYFMTCCVFBHG","pid":1238}
3602025-01-28T17:15:57.626Z{"msg":"a5335ce3-b249-490c-a581-0c02c7b15ee8 active request set","v":0,"name":"crucible","level":30,"time":"2025-01-28T17:15:56.770531926Z","hostname":"w-01JJPY42J7TJ48QYFMTCCVFBHG","pid":1238,"session_id":"9eea4de8-b9e4-42d2-89da-e97192fb2bab"}
3612025-01-28T17:15:57.626Z{"msg":"sending connect oneshot to client","v":0,"name":"crucible","level":30,"time":"2025-01-28T17:15:56.770553493Z","hostname":"w-01JJPY42J7TJ48QYFMTCCVFBHG","pid":1238,"client":"0","":"downstairs","session_id":"9eea4de8-b9e4-42d2-89da-e97192fb2bab"}
3622025-01-28T17:15:57.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-28T17:15:56.770577799Z","hostname":"w-01JJPY42J7TJ48QYFMTCCVFBHG","pid":1238,"client":"0","":"downstairs","session_id":"9eea4de8-b9e4-42d2-89da-e97192fb2bab"}
3632025-01-28T17:15:57.626Z{"msg":"sending connect oneshot to client","v":0,"name":"crucible","level":30,"time":"2025-01-28T17:15:56.770600715Z","hostname":"w-01JJPY42J7TJ48QYFMTCCVFBHG","pid":1238,"client":"1","":"downstairs","session_id":"9eea4de8-b9e4-42d2-89da-e97192fb2bab"}
3642025-01-28T17:15:57.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-28T17:15:56.770641879Z","hostname":"w-01JJPY42J7TJ48QYFMTCCVFBHG","pid":1238,"client":"1","":"downstairs","session_id":"9eea4de8-b9e4-42d2-89da-e97192fb2bab"}
3652025-01-28T17:15:57.626Z{"msg":"sending connect oneshot to client","v":0,"name":"crucible","level":30,"time":"2025-01-28T17:15:56.770684812Z","hostname":"w-01JJPY42J7TJ48QYFMTCCVFBHG","pid":1238,"client":"2","":"downstairs","session_id":"9eea4de8-b9e4-42d2-89da-e97192fb2bab"}
3662025-01-28T17:15:57.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-28T17:15:56.770715217Z","hostname":"w-01JJPY42J7TJ48QYFMTCCVFBHG","pid":1238,"client":"2","":"downstairs","session_id":"9eea4de8-b9e4-42d2-89da-e97192fb2bab"}
3672025-01-28T17:15:57.626Z{"msg":"connecting to 127.0.0.1:8860","v":0,"name":"crucible","level":30,"time":"2025-01-28T17:15:56.770748002Z","hostname":"w-01JJPY42J7TJ48QYFMTCCVFBHG","pid":1238,"":"io task","client":"2","":"downstairs","session_id":"9eea4de8-b9e4-42d2-89da-e97192fb2bab"}
3682025-01-28T17:15:57.626Z{"msg":"connecting to 127.0.0.1:8840","v":0,"name":"crucible","level":30,"time":"2025-01-28T17:15:56.770775638Z","hostname":"w-01JJPY42J7TJ48QYFMTCCVFBHG","pid":1238,"":"io task","client":"0","":"downstairs","session_id":"9eea4de8-b9e4-42d2-89da-e97192fb2bab"}
3692025-01-28T17:15:57.626Z{"msg":"connecting to 127.0.0.1:8850","v":0,"name":"crucible","level":30,"time":"2025-01-28T17:15:56.770809272Z","hostname":"w-01JJPY42J7TJ48QYFMTCCVFBHG","pid":1238,"":"io task","client":"1","":"downstairs","session_id":"9eea4de8-b9e4-42d2-89da-e97192fb2bab"}
3702025-01-28T17:15:57.626Z{"msg":"ds_connection connected from Ok(127.0.0.1:34076)","v":0,"name":"crucible","level":30,"time":"2025-01-28T17:15:56.770834948Z","hostname":"w-01JJPY42J7TJ48QYFMTCCVFBHG","pid":1238,"":"io task","client":"2","":"downstairs","session_id":"9eea4de8-b9e4-42d2-89da-e97192fb2bab"}
3712025-01-28T17:15:57.626Z{"msg":"ds_connection connected from Ok(127.0.0.1:44916)","v":0,"name":"crucible","level":30,"time":"2025-01-28T17:15:56.770870023Z","hostname":"w-01JJPY42J7TJ48QYFMTCCVFBHG","pid":1238,"":"io task","client":"0","":"downstairs","session_id":"9eea4de8-b9e4-42d2-89da-e97192fb2bab"}
3722025-01-28T17:15:57.626Z{"msg":"ds_connection connected from Ok(127.0.0.1:58581)","v":0,"name":"crucible","level":30,"time":"2025-01-28T17:15:56.770898038Z","hostname":"w-01JJPY42J7TJ48QYFMTCCVFBHG","pid":1238,"":"io task","client":"1","":"downstairs","session_id":"9eea4de8-b9e4-42d2-89da-e97192fb2bab"}
3732025-01-28T17:15:57.626Z{"msg":"version negotiation from state Connecting { state: WaitForPromote, mode: New }","v":0,"name":"crucible","level":30,"time":"2025-01-28T17:15:56.770933733Z","hostname":"w-01JJPY42J7TJ48QYFMTCCVFBHG","pid":1238,"client":"1","":"downstairs","session_id":"9eea4de8-b9e4-42d2-89da-e97192fb2bab"}
3742025-01-28T17:15:57.627Z{"msg":"version negotiation from state Connecting { state: WaitForPromote, mode: New }","v":0,"name":"crucible","level":30,"time":"2025-01-28T17:15:56.770975706Z","hostname":"w-01JJPY42J7TJ48QYFMTCCVFBHG","pid":1238,"client":"2","":"downstairs","session_id":"9eea4de8-b9e4-42d2-89da-e97192fb2bab"}
3752025-01-28T17:15:57.627Z{"msg":"version negotiation from state Connecting { state: WaitForPromote, mode: New }","v":0,"name":"crucible","level":30,"time":"2025-01-28T17:15:56.771010761Z","hostname":"w-01JJPY42J7TJ48QYFMTCCVFBHG","pid":1238,"client":"0","":"downstairs","session_id":"9eea4de8-b9e4-42d2-89da-e97192fb2bab"}
3762025-01-28T17:15:57.627Z{"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-28T17:15:56.771118993Z","hostname":"w-01JJPY42J7TJ48QYFMTCCVFBHG","pid":1238,"client":"1","":"downstairs","session_id":"9eea4de8-b9e4-42d2-89da-e97192fb2bab"}
3772025-01-28T17:15:57.627Z{"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-28T17:15:56.771290786Z","hostname":"w-01JJPY42J7TJ48QYFMTCCVFBHG","pid":1238,"client":"0","":"downstairs","session_id":"9eea4de8-b9e4-42d2-89da-e97192fb2bab"}
3782025-01-28T17:15:57.627Z{"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-28T17:15:56.771355336Z","hostname":"w-01JJPY42J7TJ48QYFMTCCVFBHG","pid":1238,"client":"2","":"downstairs","session_id":"9eea4de8-b9e4-42d2-89da-e97192fb2bab"}
3792025-01-28T17:15:57.627Z{"msg":"Waiting for more clients to be ready","v":0,"name":"crucible","level":30,"time":"2025-01-28T17:15:56.771475847Z","hostname":"w-01JJPY42J7TJ48QYFMTCCVFBHG","pid":1238,"session_id":"9eea4de8-b9e4-42d2-89da-e97192fb2bab"}
3802025-01-28T17:15:57.627Z{"msg":"Waiting for more clients to be ready","v":0,"name":"crucible","level":30,"time":"2025-01-28T17:15:56.771662418Z","hostname":"w-01JJPY42J7TJ48QYFMTCCVFBHG","pid":1238,"session_id":"9eea4de8-b9e4-42d2-89da-e97192fb2bab"}
3812025-01-28T17:15:57.627Z{"msg":"[0]R flush_numbers: [5317, 5317, 5317, 5317, 5317]","v":0,"name":"crucible","level":30,"time":"2025-01-28T17:15:56.771767531Z","hostname":"w-01JJPY42J7TJ48QYFMTCCVFBHG","pid":1238,"":"downstairs","":"downstairs","session_id":"9eea4de8-b9e4-42d2-89da-e97192fb2bab"}
3822025-01-28T17:15:57.627Z{"msg":"[0]R generation: [31, 31, 31, 31, 31]","v":0,"name":"crucible","level":30,"time":"2025-01-28T17:15:56.771795567Z","hostname":"w-01JJPY42J7TJ48QYFMTCCVFBHG","pid":1238,"":"downstairs","":"downstairs","session_id":"9eea4de8-b9e4-42d2-89da-e97192fb2bab"}
3832025-01-28T17:15:57.627Z{"msg":"[0]R dirty: [false, false, false, false, false]","v":0,"name":"crucible","level":30,"time":"2025-01-28T17:15:56.771810774Z","hostname":"w-01JJPY42J7TJ48QYFMTCCVFBHG","pid":1238,"":"downstairs","":"downstairs","session_id":"9eea4de8-b9e4-42d2-89da-e97192fb2bab"}
3842025-01-28T17:15:57.627Z{"msg":"[1]R flush_numbers: [5317, 5317, 5317, 5317, 5317]","v":0,"name":"crucible","level":30,"time":"2025-01-28T17:15:56.771831331Z","hostname":"w-01JJPY42J7TJ48QYFMTCCVFBHG","pid":1238,"":"downstairs","":"downstairs","session_id":"9eea4de8-b9e4-42d2-89da-e97192fb2bab"}
3852025-01-28T17:15:57.627Z{"msg":"[1]R generation: [31, 31, 31, 31, 31]","v":0,"name":"crucible","level":30,"time":"2025-01-28T17:15:56.771845139Z","hostname":"w-01JJPY42J7TJ48QYFMTCCVFBHG","pid":1238,"":"downstairs","":"downstairs","session_id":"9eea4de8-b9e4-42d2-89da-e97192fb2bab"}
3862025-01-28T17:15:57.627Z{"msg":"[1]R dirty: [false, false, false, false, false]","v":0,"name":"crucible","level":30,"time":"2025-01-28T17:15:56.771858337Z","hostname":"w-01JJPY42J7TJ48QYFMTCCVFBHG","pid":1238,"":"downstairs","":"downstairs","session_id":"9eea4de8-b9e4-42d2-89da-e97192fb2bab"}
3872025-01-28T17:15:57.627Z{"msg":"[2]R flush_numbers: [5317, 5317, 5317, 5317, 5317]","v":0,"name":"crucible","level":30,"time":"2025-01-28T17:15:56.771878273Z","hostname":"w-01JJPY42J7TJ48QYFMTCCVFBHG","pid":1238,"":"downstairs","":"downstairs","session_id":"9eea4de8-b9e4-42d2-89da-e97192fb2bab"}
3882025-01-28T17:15:57.627Z{"msg":"[2]R generation: [31, 31, 31, 31, 31]","v":0,"name":"crucible","level":30,"time":"2025-01-28T17:15:56.771891291Z","hostname":"w-01JJPY42J7TJ48QYFMTCCVFBHG","pid":1238,"":"downstairs","":"downstairs","session_id":"9eea4de8-b9e4-42d2-89da-e97192fb2bab"}
3892025-01-28T17:15:57.630Z{"msg":"[2]R dirty: [false, false, false, false, false]","v":0,"name":"crucible","level":30,"time":"2025-01-28T17:15:56.77190456Z","hostname":"w-01JJPY42J7TJ48QYFMTCCVFBHG","pid":1238,"":"downstairs","":"downstairs","session_id":"9eea4de8-b9e4-42d2-89da-e97192fb2bab"}
3902025-01-28T17:15:57.630Z{"msg":"Max found gen is 32"Wait for a query_work_queue command to finish before sending IO
3912025-01-28T17:15:57.630Z,"v":0,"name":"crucible","level":30,"time":"2025-01-28T17:15:56.771933115Z","hostname":"w-01JJPY42J7TJ48QYFMTCCVFBHG","pid":1238,"":"downstairs","":"downstairs","session_id":"9eea4de8-b9e4-42d2-89da-e97192fb2bab"}
3922025-01-28T17:15:57.630Z{"msg":"Generation requested: 32 >= found:32","v":0,"name":"crucible","level":30,"time":"2025-01-28T17:15:56.771947163Z","hostname":"w-01JJPY42J7TJ48QYFMTCCVFBHG","pid":1238,"":"downstairs","":"downstairs","session_id":"9eea4de8-b9e4-42d2-89da-e97192fb2bab"}
3932025-01-28T17:15:57.631Z{"msg":"Next flush: 5318","v":0,"name":"crucible","level":30,"time":"2025-01-28T17:15:56.771960481Z","hostname":"w-01JJPY42J7TJ48QYFMTCCVFBHG","pid":1238,"":"downstairs","":"downstairs","session_id":"9eea4de8-b9e4-42d2-89da-e97192fb2bab"}
3942025-01-28T17:15:57.631Z{"msg":"All extents match","v":0,"name":"crucible","level":30,"time":"2025-01-28T17:15:56.771973358Z","hostname":"w-01JJPY42J7TJ48QYFMTCCVFBHG","pid":1238,"":"downstairs","":"downstairs","session_id":"9eea4de8-b9e4-42d2-89da-e97192fb2bab"}
3952025-01-28T17:15:57.631Z{"msg":"No downstairs reconciliation required","v":0,"name":"crucible","level":30,"time":"2025-01-28T17:15:56.771993326Z","hostname":"w-01JJPY42J7TJ48QYFMTCCVFBHG","pid":1238,"session_id":"9eea4de8-b9e4-42d2-89da-e97192fb2bab"}
3962025-01-28T17:15:57.631Z{"msg":"Transition from WaitQuorum to Active","v":0,"name":"crucible","level":30,"time":"2025-01-28T17:15:56.772005964Z","hostname":"w-01JJPY42J7TJ48QYFMTCCVFBHG","pid":1238,"client":"0","":"downstairs","session_id":"9eea4de8-b9e4-42d2-89da-e97192fb2bab"}
3972025-01-28T17:15:57.631Z{"msg":"Transition from WaitQuorum to Active","v":0,"name":"crucible","level":30,"time":"2025-01-28T17:15:56.772019201Z","hostname":"w-01JJPY42J7TJ48QYFMTCCVFBHG","pid":1238,"client":"1","":"downstairs","session_id":"9eea4de8-b9e4-42d2-89da-e97192fb2bab"}
3982025-01-28T17:15:57.631Z{"msg":"Transition from WaitQuorum to Active","v":0,"name":"crucible","level":30,"time":"2025-01-28T17:15:56.772032209Z","hostname":"w-01JJPY42J7TJ48QYFMTCCVFBHG","pid":1238,"client":"2","":"downstairs","session_id":"9eea4de8-b9e4-42d2-89da-e97192fb2bab"}
3992025-01-28T17:15:57.631Z{"msg":"All required reconciliation work is completed","v":0,"name":"crucible","level":30,"time":"2025-01-28T17:15:56.772045207Z","hostname":"w-01JJPY42J7TJ48QYFMTCCVFBHG","pid":1238,"session_id":"9eea4de8-b9e4-42d2-89da-e97192fb2bab"}
4002025-01-28T17:15:57.631Z{"msg":"Set Downstairs and Upstairs active after reconciliation","v":0,"name":"crucible","level":30,"time":"2025-01-28T17:15:56.772057265Z","hostname":"w-01JJPY42J7TJ48QYFMTCCVFBHG","pid":1238,"session_id":"9eea4de8-b9e4-42d2-89da-e97192fb2bab"}
4012025-01-28T17:15:57.631Z{"msg":"a5335ce3-b249-490c-a581-0c02c7b15ee8 is now active with session: 9eea4de8-b9e4-42d2-89da-e97192fb2bab","v":0,"name":"crucible","level":30,"time":"2025-01-28T17:15:56.772082021Z","hostname":"w-01JJPY42J7TJ48QYFMTCCVFBHG","pid":1238,"session_id":"9eea4de8-b9e4-42d2-89da-e97192fb2bab"}
4022025-01-28T17:15:57.631Z{"msg":"Set Active after no reconciliation","v":0,"name":"crucible","level":30,"time":"2025-01-28T17:15:56.772105788Z","hostname":"w-01JJPY42J7TJ48QYFMTCCVFBHG","pid":1238,"session_id":"9eea4de8-b9e4-42d2-89da-e97192fb2bab"}
4032025-01-28T17:15:57.631Z{"msg":"The guest has finished waiting for activation with:32","v":0,"name":"crucible","level":30,"time":"2025-01-28T17:15:56.772118536Z","hostname":"w-01JJPY42J7TJ48QYFMTCCVFBHG","pid":1238}
4042025-01-28T17:15:57.631ZDisk: sv:2 bs:4096 ts:409600 tb:100 max_io:100 or 409600
4052025-01-28T17:15:57.631ZLoading write count information from file "/var/tmp/test_up-build/verify_file"
4062025-01-28T17:15:57.631ZFill test
4072025-01-28T17:15:57.670ZRead and Verify all blocks (0..100 range:false)
4082025-01-28T17:15:57.750ZWrote out file "/var/tmp/test_up-build/verify_file"
4092025-01-28T17:15:57.750ZCLIENT: Tests done. All submitted work has been ACK'd
4102025-01-28T17:15:57.753Z----------------------------------------------------------------
4112025-01-28T17:15:57.753Z Crucible gen:32 GIO:true work queues: Upstairs:0 downstairs:1
4122025-01-28T17:15:57.753ZStates: Active Active Active
4132025-01-28T17:15:57.753ZJOBID ACK TYPE BKS/EXT DS:0 DS:1 DS:2 REPLAY
4142025-01-28T17:15:57.753Z 1002 Acked Read 50 Done Done Done false
4152025-01-28T17:15:57.753Z STATES DS:0 DS:1 DS:2 TOTAL
4162025-01-28T17:15:57.753Z Sent 0 0 0 0
4172025-01-28T17:15:57.753Z Done 1 1 1 3
4182025-01-28T17:15:57.753Z Skipped 0 0 0 0
4192025-01-28T17:15:57.753Z Error 0 0 0 0
4202025-01-28T17:15:57.753ZLast Flush: Some(JobId(1001)) Some(JobId(1001)) Some(JobId(1001))
4212025-01-28T17:15:57.753ZDownstairs last five completed: 1001 1000
4222025-01-28T17:15:57.753ZUpstairs last five completed: 1002 1001 1000
4232025-01-28T17:15:57.753Z----------------------------------------------------------------
4242025-01-28T17:15:57.753Z Crucible gen:32 GIO:true work queues: Upstairs:0 downstairs:1
4252025-01-28T17:15:57.753ZStates: Active Active Active
4262025-01-28T17:15:57.753ZJOBID ACK TYPE BKS/EXT DS:0 DS:1 DS:2 REPLAY
4272025-01-28T17:15:57.753Z 1002 Acked Read 50 Done Done Done false
4282025-01-28T17:15:57.753Z STATES DS:0 DS:1 DS:2 TOTAL
4292025-01-28T17:15:57.754Z Sent 0 0 0 0
4302025-01-28T17:15:57.754Z Done 1 1 1 3
4312025-01-28T17:15:57.754Z Skipped 0 0 0 0
4322025-01-28T17:15:57.754Z Error 0 0 0 0
4332025-01-28T17:15:57.754ZLast Flush: Some(JobId(1001)) Some(JobId(1001)) Some(JobId(1001))
4342025-01-28T17:15:57.754ZDownstairs last five completed: 1001 1000
4352025-01-28T17:15:57.754ZUpstairs last five completed: 1002 1001 1000
4362025-01-28T17:15:57.754ZCLIENT: Up:0 ds:2 act:6
4372025-01-28T17:16:01.752Z----------------------------------------------------------------
4382025-01-28T17:16:01.752Z Crucible gen:32 GIO:true work queues: Upstairs:0 downstairs:0
4392025-01-28T17:16:01.752ZDownstairs last five completed: 1003 1002 1001 1000
4402025-01-28T17:16:01.752ZUpstairs last five completed: 1003 1002 1001 1000
4412025-01-28T17:16:01.752Z----------------------------------------------------------------
4422025-01-28T17:16:01.753Z Crucible gen:32 GIO:true work queues: Upstairs:0 downstairs:0
4432025-01-28T17:16:01.753ZDownstairs last five completed: 1003 1002 1001 1000
4442025-01-28T17:16:01.753ZUpstairs last five completed: 1003 1002 1001 1000
4452025-01-28T17:16:01.753ZCLIENT: Up:0 ds:0 act:6
4462025-01-28T17:16:01.753ZCLIENT: All crucible jobs finished, exiting program
4472025-01-28T17:16:01.756Z{"msg":"Guest handle has been dropped","v":0,"name":"crucible","level":40,"time":"2025-01-28T17:16:00.89878871Z","hostname":"w-01JJPY42J7TJ48QYFMTCCVFBHG","pid":1238}
4482025-01-28T17:16:01.760ZRepair part 1 passed
4492025-01-28T17:16:01.763Z
4502025-01-28T17:16:01.763ZKill the current downstairs
4512025-01-28T17:16:01.948ZDownstairs 2 stopped
4522025-01-28T17:16:01.948Zmv /var/tmp/test_up-build/8830 /var/tmp/test_up-build/new
4532025-01-28T17:16:01.951ZNow put back the original so we have a mismatch
4542025-01-28T17:16:01.951Zmv /var/tmp/test_up-build/previous /var/tmp/test_up-build/8830
4552025-01-28T17:16:01.954ZRestart downstairs with old directory
4562025-01-28T17:16:02.016Z/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
4572025-01-28T17:16:02.035ZEXT BLOCKS GEN0 GEN1 GEN2 FL0 FL1 FL2 D0 D1 D2 DIFF
4582025-01-28T17:16:02.038Z 0 000-009 32 32 31 3993 3993 3992 F F F <---
4592025-01-28T17:16:02.038Z 1 010-019 32 32 31 3993 3993 3992 F F F <---
4602025-01-28T17:16:02.038Z 2 020-029 32 32 31 3993 3993 3992 F F F <---
4612025-01-28T17:16:02.038Z 3 030-039 32 32 31 3993 3993 3992 F F F <---
4622025-01-28T17:16:02.038Z 4 040-049 32 32 31 3993 3993 3992 F F F <---
4632025-01-28T17:16:02.038ZMax gen: 32, Max flush: 3993
4642025-01-28T17:16:02.038ZError: Difference in extent metadata found!
4652025-01-28T17:16:02.041Zdump test found error as expected
4662025-01-28T17:16:02.041Z
4672025-01-28T17:16:02.041Z
4682025-01-28T17:16:02.041Z/var/tmp/bins/crutest verify --range -g 33 -q --key 9q52nrwZdyxSwBF6A/1uxpEIrPl6wZEZ1P9sUqSfLyg= --dsc 127.0.0.1:9998 --verify-out /var/tmp/test_up-build/verify_file --verify-in /var/tmp/test_up-build/verify_file
4692025-01-28T17:16:02.102Z{"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-28T17:16:01.248094889Z","hostname":"w-01JJPY42J7TJ48QYFMTCCVFBHG","pid":1246,"task":"crutest"}
4702025-01-28T17:16:02.105Z{"msg":"dsc has 6 regions. This means 2 sub_volumes","v":0,"name":"crucible","level":30,"time":"2025-01-28T17:16:01.248578672Z","hostname":"w-01JJPY42J7TJ48QYFMTCCVFBHG","pid":1246,"task":"crutest"}
4712025-01-28T17:16:02.105Z{"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-28T17:16:01.250214534Z","hostname":"w-01JJPY42J7TJ48QYFMTCCVFBHG","pid":1246,"task":"crutest"}
4722025-01-28T17:16:02.105Z{"msg":"Upstairs starts","v":0,"name":"crucible","level":30,"time":"2025-01-28T17:16:01.25043633Z","hostname":"w-01JJPY42J7TJ48QYFMTCCVFBHG","pid":1246}
4732025-01-28T17:16:02.105Z{"msg":"Crucible Version: BuildInfo {\n version: \"0.0.1\",\n git_sha: \"752fd3e208a28c201ec7c5e297caafe64bf1aaf2\",\n git_commit_timestamp: \"2025-01-28T16:52:48.000000000Z\",\n git_branch: \"alan/where-my-writes-at\",\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-28T17:16:01.250486262Z","hostname":"w-01JJPY42J7TJ48QYFMTCCVFBHG","pid":1246}
4742025-01-28T17:16:02.105Z{"msg":"Upstairs <-> Downstairs Message Version: 13","v":0,"name":"crucible","level":30,"time":"2025-01-28T17:16:01.250533704Z","hostname":"w-01JJPY42J7TJ48QYFMTCCVFBHG","pid":1246}
4752025-01-28T17:16:02.105Z{"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-28T17:16:01.250577577Z","hostname":"w-01JJPY42J7TJ48QYFMTCCVFBHG","pid":1246}
4762025-01-28T17:16:02.105Z{"msg":"Crucible 2bc7a807-910d-4572-8469-9bca33563301 has session id: 05ab9ec5-5dfc-41a7-86fb-b32b311c7372","v":0,"name":"crucible","level":30,"time":"2025-01-28T17:16:01.251173193Z","hostname":"w-01JJPY42J7TJ48QYFMTCCVFBHG","pid":1246,"session_id":"05ab9ec5-5dfc-41a7-86fb-b32b311c7372"}
4772025-01-28T17:16:02.105Z{"msg":"Upstairs opts: Upstairs UUID: 2bc7a807-910d-4572-8469-9bca33563301, 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-28T17:16:01.251223875Z","hostname":"w-01JJPY42J7TJ48QYFMTCCVFBHG","pid":1246,"session_id":"05ab9ec5-5dfc-41a7-86fb-b32b311c7372"}
4782025-01-28T17:16:02.105Z{"msg":"Crucible stats registered with UUID: 2bc7a807-910d-4572-8469-9bca33563301","v":0,"name":"crucible","level":30,"time":"2025-01-28T17:16:01.251240723Z","hostname":"w-01JJPY42J7TJ48QYFMTCCVFBHG","pid":1246,"session_id":"05ab9ec5-5dfc-41a7-86fb-b32b311c7372"}
4792025-01-28T17:16:02.106Z{"msg":"could not find Downstairs address for Nexus","v":0,"name":"crucible","level":40,"time":"2025-01-28T17:16:01.251282636Z","hostname":"w-01JJPY42J7TJ48QYFMTCCVFBHG","pid":1246,"session_id":"05ab9ec5-5dfc-41a7-86fb-b32b311c7372"}
4802025-01-28T17:16:02.108Z{"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-28T17:16:01.253227999Z","hostname":"w-01JJPY42J7TJ48QYFMTCCVFBHG","pid":1246,"task":"crutest"}
4812025-01-28T17:16:02.108Z{"msg":"Upstairs starts","v":0,"name":"crucible","level":30,"time":"2025-01-28T17:16:01.253329283Z","hostname":"w-01JJPY42J7TJ48QYFMTCCVFBHG","pid":1246}
4822025-01-28T17:16:02.109Z{"msg":"Crucible Version: BuildInfo {\n version: \"0.0.1\",\n git_sha: \"752fd3e208a28c201ec7c5e297caafe64bf1aaf2\",\n git_commit_timestamp: \"2025-01-28T16:52:48.000000000Z\",\n git_branch: \"alan/where-my-writes-at\",\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-28T17:16:01.253368097Z","hostname":"w-01JJPY42J7TJ48QYFMTCCVFBHG","pid":1246}
4832025-01-28T17:16:02.109Z{"msg":"Upstairs <-> Downstairs Message Version: 13","v":0,"name":"crucible","level":30,"time":"2025-01-28T17:16:01.253399682Z","hostname":"w-01JJPY42J7TJ48QYFMTCCVFBHG","pid":1246}
4842025-01-28T17:16:02.109Z{"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-28T17:16:01.253421648Z","hostname":"w-01JJPY42J7TJ48QYFMTCCVFBHG","pid":1246}
4852025-01-28T17:16:02.109Z{"msg":"Crucible 2bc7a807-910d-4572-8469-9bca33563301 has session id: 822a2999-1329-4fb6-b0c8-4ad0351a1b17","v":0,"name":"crucible","level":30,"time":"2025-01-28T17:16:01.253809787Z","hostname":"w-01JJPY42J7TJ48QYFMTCCVFBHG","pid":1246,"session_id":"822a2999-1329-4fb6-b0c8-4ad0351a1b17"}
4862025-01-28T17:16:02.109Z{"msg":"Upstairs opts: Upstairs UUID: 2bc7a807-910d-4572-8469-9bca33563301, 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-28T17:16:01.253885346Z","hostname":"w-01JJPY42J7TJ48QYFMTCCVFBHG","pid":1246,"session_id":"822a2999-1329-4fb6-b0c8-4ad0351a1b17"}
4872025-01-28T17:16:02.109Z{"msg":"Crucible stats registered with UUID: 2bc7a807-910d-4572-8469-9bca33563301","v":0,"name":"crucible","level":30,"time":"2025-01-28T17:16:01.253932468Z","hostname":"w-01JJPY42J7TJ48QYFMTCCVFBHG","pid":1246,"session_id":"822a2999-1329-4fb6-b0c8-4ad0351a1b17"}
4882025-01-28T17:16:02.109Z{"msg":"could not find Downstairs address for Nexus","v":0,"name":"crucible","level":40,"time":"2025-01-28T17:16:01.253953655Z","hostname":"w-01JJPY42J7TJ48QYFMTCCVFBHG","pid":1246,"session_id":"822a2999-1329-4fb6-b0c8-4ad0351a1b17"}
4892025-01-28T17:16:02.112Z{"msg":"Downstairs in volume = 6","v":0,"name":"crucible","level":30,"time":"2025-01-28T17:16:01.254937129Z","hostname":"w-01JJPY42J7TJ48QYFMTCCVFBHG","pid":1246,"task":"crutest"}
4902025-01-28T17:16:02.112Z{"msg":"The guest has requested activation with gen:33","v":0,"name":"crucible","level":30,"time":"2025-01-28T17:16:01.254991391Z","hostname":"w-01JJPY42J7TJ48QYFMTCCVFBHG","pid":1246}
4912025-01-28T17:16:02.112Z{"msg":"2bc7a807-910d-4572-8469-9bca33563301 active request set","v":0,"name":"crucible","level":30,"time":"2025-01-28T17:16:01.25505867Z","hostname":"w-01JJPY42J7TJ48QYFMTCCVFBHG","pid":1246,"session_id":"05ab9ec5-5dfc-41a7-86fb-b32b311c7372"}
4922025-01-28T17:16:02.112Z{"msg":"sending connect oneshot to client","v":0,"name":"crucible","level":30,"time":"2025-01-28T17:16:01.255085356Z","hostname":"w-01JJPY42J7TJ48QYFMTCCVFBHG","pid":1246,"client":"0","":"downstairs","session_id":"05ab9ec5-5dfc-41a7-86fb-b32b311c7372"}
4932025-01-28T17:16:02.112Z{"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-28T17:16:01.255117751Z","hostname":"w-01JJPY42J7TJ48QYFMTCCVFBHG","pid":1246,"client":"0","":"downstairs","session_id":"05ab9ec5-5dfc-41a7-86fb-b32b311c7372"}
4942025-01-28T17:16:02.112Z{"msg":"sending connect oneshot to client","v":0,"name":"crucible","level":30,"time":"2025-01-28T17:16:01.255133418Z","hostname":"w-01JJPY42J7TJ48QYFMTCCVFBHG","pid":1246,"client":"1","":"downstairs","session_id":"05ab9ec5-5dfc-41a7-86fb-b32b311c7372"}
4952025-01-28T17:16:02.112Z{"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-28T17:16:01.255155315Z","hostname":"w-01JJPY42J7TJ48QYFMTCCVFBHG","pid":1246,"client":"1","":"downstairs","session_id":"05ab9ec5-5dfc-41a7-86fb-b32b311c7372"}
4962025-01-28T17:16:02.112Z{"msg":"sending connect oneshot to client","v":0,"name":"crucible","level":30,"time":"2025-01-28T17:16:01.255169563Z","hostname":"w-01JJPY42J7TJ48QYFMTCCVFBHG","pid":1246,"client":"2","":"downstairs","session_id":"05ab9ec5-5dfc-41a7-86fb-b32b311c7372"}
4972025-01-28T17:16:02.112Z{"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-28T17:16:01.255235233Z","hostname":"w-01JJPY42J7TJ48QYFMTCCVFBHG","pid":1246,"client":"2","":"downstairs","session_id":"05ab9ec5-5dfc-41a7-86fb-b32b311c7372"}
4982025-01-28T17:16:02.112Z{"msg":"connecting to 127.0.0.1:8830","v":0,"name":"crucible","level":30,"time":"2025-01-28T17:16:01.255321669Z","hostname":"w-01JJPY42J7TJ48QYFMTCCVFBHG","pid":1246,"":"io task","client":"2","":"downstairs","session_id":"05ab9ec5-5dfc-41a7-86fb-b32b311c7372"}
4992025-01-28T17:16:02.112Z{"msg":"connecting to 127.0.0.1:8810","v":0,"name":"crucible","level":30,"time":"2025-01-28T17:16:01.255373911Z","hostname":"w-01JJPY42J7TJ48QYFMTCCVFBHG","pid":1246,"":"io task","client":"0","":"downstairs","session_id":"05ab9ec5-5dfc-41a7-86fb-b32b311c7372"}
5002025-01-28T17:16:02.112Z{"msg":"connecting to 127.0.0.1:8820","v":0,"name":"crucible","level":30,"time":"2025-01-28T17:16:01.255420023Z","hostname":"w-01JJPY42J7TJ48QYFMTCCVFBHG","pid":1246,"":"io task","client":"1","":"downstairs","session_id":"05ab9ec5-5dfc-41a7-86fb-b32b311c7372"}
5012025-01-28T17:16:02.112Z{"msg":"ds_connection connected from Ok(127.0.0.1:38488)","v":0,"name":"crucible","level":30,"time":"2025-01-28T17:16:01.255454998Z","hostname":"w-01JJPY42J7TJ48QYFMTCCVFBHG","pid":1246,"":"io task","client":"0","":"downstairs","session_id":"05ab9ec5-5dfc-41a7-86fb-b32b311c7372"}
5022025-01-28T17:16:02.112Z{"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-28T17:16:01.255482663Z","hostname":"w-01JJPY42J7TJ48QYFMTCCVFBHG","pid":1246,"":"io task","client":"2","":"downstairs","session_id":"05ab9ec5-5dfc-41a7-86fb-b32b311c7372"}
5032025-01-28T17:16:02.112Z{"msg":"client task is sending Done(ConnectionFailed(Os { code: 146, kind: ConnectionRefused, message: \"Connection refused\" }))","v":0,"name":"crucible","level":40,"time":"2025-01-28T17:16:01.255519238Z","hostname":"w-01JJPY42J7TJ48QYFMTCCVFBHG","pid":1246,"":"io task","client":"2","":"downstairs","session_id":"05ab9ec5-5dfc-41a7-86fb-b32b311c7372"}
5042025-01-28T17:16:02.112Z{"msg":"ds_connection connected from Ok(127.0.0.1:38222)","v":0,"name":"crucible","level":30,"time":"2025-01-28T17:16:01.255547923Z","hostname":"w-01JJPY42J7TJ48QYFMTCCVFBHG","pid":1246,"":"io task","client":"1","":"downstairs","session_id":"05ab9ec5-5dfc-41a7-86fb-b32b311c7372"}
5052025-01-28T17:16:02.112Z{"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-28T17:16:01.255575709Z","hostname":"w-01JJPY42J7TJ48QYFMTCCVFBHG","pid":1246,"session_id":"05ab9ec5-5dfc-41a7-86fb-b32b311c7372"}
5062025-01-28T17:16:02.112Z{"msg":"client task is exiting","v":0,"name":"crucible","level":30,"time":"2025-01-28T17:16:01.255701749Z","hostname":"w-01JJPY42J7TJ48QYFMTCCVFBHG","pid":1246,"":"io task","client":"2","":"downstairs","session_id":"05ab9ec5-5dfc-41a7-86fb-b32b311c7372"}
5072025-01-28T17:16:02.112Z{"msg":"version negotiation from state Connecting { state: WaitForPromote, mode: New }","v":0,"name":"crucible","level":30,"time":"2025-01-28T17:16:01.256049544Z","hostname":"w-01JJPY42J7TJ48QYFMTCCVFBHG","pid":1246,"client":"0","":"downstairs","session_id":"05ab9ec5-5dfc-41a7-86fb-b32b311c7372"}
5082025-01-28T17:16:02.112Z{"msg":"version negotiation from state Connecting { state: WaitForPromote, mode: New }","v":0,"name":"crucible","level":30,"time":"2025-01-28T17:16:01.256087298Z","hostname":"w-01JJPY42J7TJ48QYFMTCCVFBHG","pid":1246,"client":"1","":"downstairs","session_id":"05ab9ec5-5dfc-41a7-86fb-b32b311c7372"}
5092025-01-28T17:16:02.112Z{"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-28T17:16:01.256655349Z","hostname":"w-01JJPY42J7TJ48QYFMTCCVFBHG","pid":1246,"client":"0","":"downstairs","session_id":"05ab9ec5-5dfc-41a7-86fb-b32b311c7372"}
5102025-01-28T17:16:02.112Z{"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-28T17:16:01.256693212Z","hostname":"w-01JJPY42J7TJ48QYFMTCCVFBHG","pid":1246,"client":"1","":"downstairs","session_id":"05ab9ec5-5dfc-41a7-86fb-b32b311c7372"}
5112025-01-28T17:16:02.112Z{"msg":"Waiting for more clients to be ready","v":0,"name":"crucible","level":30,"time":"2025-01-28T17:16:01.257080291Z","hostname":"w-01JJPY42J7TJ48QYFMTCCVFBHG","pid":1246,"session_id":"05ab9ec5-5dfc-41a7-86fb-b32b311c7372"}
5122025-01-28T17:16:02.112Z{"msg":"Waiting for more clients to be ready","v":0,"name":"crucible","level":30,"time":"2025-01-28T17:16:01.257116046Z","hostname":"w-01JJPY42J7TJ48QYFMTCCVFBHG","pid":1246,"session_id":"05ab9ec5-5dfc-41a7-86fb-b32b311c7372"}
5132025-01-28T17:16:12.113Z{"msg":"connecting to 127.0.0.1:8830","v":0,"name":"crucible","level":30,"time":"2025-01-28T17:16:11.256817696Z","hostname":"w-01JJPY42J7TJ48QYFMTCCVFBHG","pid":1246,"":"io task","client":"2","":"downstairs","session_id":"05ab9ec5-5dfc-41a7-86fb-b32b311c7372"}
5142025-01-28T17:16:12.117Z{"msg":"ds_connection connected from Ok(127.0.0.1:60167)","v":0,"name":"crucible","level":30,"time":"2025-01-28T17:16:11.257041011Z","hostname":"w-01JJPY42J7TJ48QYFMTCCVFBHG","pid":1246,"":"io task","client":"2","":"downstairs","session_id":"05ab9ec5-5dfc-41a7-86fb-b32b311c7372"}
5152025-01-28T17:16:12.117Z{"msg":"version negotiation from state Connecting { state: WaitForPromote, mode: New }","v":0,"name":"crucible","level":30,"time":"2025-01-28T17:16:11.258049172Z","hostname":"w-01JJPY42J7TJ48QYFMTCCVFBHG","pid":1246,"client":"2","":"downstairs","session_id":"05ab9ec5-5dfc-41a7-86fb-b32b311c7372"}
5162025-01-28T17:16:12.117Z{"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-28T17:16:11.258580538Z","hostname":"w-01JJPY42J7TJ48QYFMTCCVFBHG","pid":1246,"client":"2","":"downstairs","session_id":"05ab9ec5-5dfc-41a7-86fb-b32b311c7372"}
5172025-01-28T17:16:12.118Z{"msg":"[0]R flush_numbers: [3993, 3993, 3993, 3993, 3993]","v":0,"name":"crucible","level":30,"time":"2025-01-28T17:16:11.258971346Z","hostname":"w-01JJPY42J7TJ48QYFMTCCVFBHG","pid":1246,"":"downstairs","":"downstairs","session_id":"05ab9ec5-5dfc-41a7-86fb-b32b311c7372"}
5182025-01-28T17:16:12.118Z{"msg":"[0]R generation: [32, 32, 32, 32, 32]","v":0,"name":"crucible","level":30,"time":"2025-01-28T17:16:11.259004111Z","hostname":"w-01JJPY42J7TJ48QYFMTCCVFBHG","pid":1246,"":"downstairs","":"downstairs","session_id":"05ab9ec5-5dfc-41a7-86fb-b32b311c7372"}
5192025-01-28T17:16:12.118Z{"msg":"[0]R dirty: [false, false, false, false, false]","v":0,"name":"crucible","level":30,"time":"2025-01-28T17:16:11.259019998Z","hostname":"w-01JJPY42J7TJ48QYFMTCCVFBHG","pid":1246,"":"downstairs","":"downstairs","session_id":"05ab9ec5-5dfc-41a7-86fb-b32b311c7372"}
5202025-01-28T17:16:12.118Z{"msg":"[1]R flush_numbers: [3993, 3993, 3993, 3993, 3993]","v":0,"name":"crucible","level":30,"time":"2025-01-28T17:16:11.259034346Z","hostname":"w-01JJPY42J7TJ48QYFMTCCVFBHG","pid":1246,"":"downstairs","":"downstairs","session_id":"05ab9ec5-5dfc-41a7-86fb-b32b311c7372"}
5212025-01-28T17:16:12.118Z{"msg":"[1]R generation: [32, 32, 32, 32, 32]","v":0,"name":"crucible","level":30,"time":"2025-01-28T17:16:11.259055473Z","hostname":"w-01JJPY42J7TJ48QYFMTCCVFBHG","pid":1246,"":"downstairs","":"downstairs","session_id":"05ab9ec5-5dfc-41a7-86fb-b32b311c7372"}
5222025-01-28T17:16:12.118Z{"msg":"[1]R dirty: [false, false, false, false, false]","v":0,"name":"crucible","level":30,"time":"2025-01-28T17:16:11.259069511Z","hostname":"w-01JJPY42J7TJ48QYFMTCCVFBHG","pid":1246,"":"downstairs","":"downstairs","session_id":"05ab9ec5-5dfc-41a7-86fb-b32b311c7372"}
5232025-01-28T17:16:12.118Z{"msg":"[2]R flush_numbers: [3992, 3992, 3992, 3992, 3992]","v":0,"name":"crucible","level":30,"time":"2025-01-28T17:16:11.259083928Z","hostname":"w-01JJPY42J7TJ48QYFMTCCVFBHG","pid":1246,"":"downstairs","":"downstairs","session_id":"05ab9ec5-5dfc-41a7-86fb-b32b311c7372"}
5242025-01-28T17:16:12.118Z{"msg":"[2]R generation: [31, 31, 31, 31, 31]","v":0,"name":"crucible","level":30,"time":"2025-01-28T17:16:11.259097176Z","hostname":"w-01JJPY42J7TJ48QYFMTCCVFBHG","pid":1246,"":"downstairs","":"downstairs","session_id":"05ab9ec5-5dfc-41a7-86fb-b32b311c7372"}
5252025-01-28T17:16:12.118Z{"msg":"[2]R dirty: [false, false, false, false, false]","v":0,"name":"crucible","level":30,"time":"2025-01-28T17:16:11.259118173Z","hostname":"w-01JJPY42J7TJ48QYFMTCCVFBHG","pid":1246,"":"downstairs","":"downstairs","session_id":"05ab9ec5-5dfc-41a7-86fb-b32b311c7372"}
5262025-01-28T17:16:12.118Z{"msg":"Max found gen is 33","v":0,"name":"crucible","level":30,"time":"2025-01-28T17:16:11.259131361Z","hostname":"w-01JJPY42J7TJ48QYFMTCCVFBHG","pid":1246,"":"downstairs","":"downstairs","session_id":"05ab9ec5-5dfc-41a7-86fb-b32b311c7372"}
5272025-01-28T17:16:12.118Z{"msg":"Generation requested: 33 >= found:33","v":0,"name":"crucible","level":30,"time":"2025-01-28T17:16:11.259144219Z","hostname":"w-01JJPY42J7TJ48QYFMTCCVFBHG","pid":1246,"":"downstairs","":"downstairs","session_id":"05ab9ec5-5dfc-41a7-86fb-b32b311c7372"}
5282025-01-28T17:16:12.118Z{"msg":"Next flush: 3994","v":0,"name":"crucible","level":30,"time":"2025-01-28T17:16:11.259164385Z","hostname":"w-01JJPY42J7TJ48QYFMTCCVFBHG","pid":1246,"":"downstairs","":"downstairs","session_id":"05ab9ec5-5dfc-41a7-86fb-b32b311c7372"}
5292025-01-28T17:16:12.118Z{"msg":"extent 0 needs reconciliation: ExtentMetadata { gen: 32, flush: 3993, dirty: false } ExtentMetadata { gen: 32, flush: 3993, dirty: false } ExtentMetadata { gen: 31, flush: 3992, dirty: false }","v":0,"name":"crucible","level":30,"time":"2025-01-28T17:16:11.259180143Z","hostname":"w-01JJPY42J7TJ48QYFMTCCVFBHG","pid":1246,"":"mend","":"downstairs","":"downstairs","session_id":"05ab9ec5-5dfc-41a7-86fb-b32b311c7372"}
5302025-01-28T17:16:12.118Z{"msg":"extent:0 [ExtentMetadata { gen: 32, flush: 3993, dirty: false }, ExtentMetadata { gen: 32, flush: 3993, dirty: false }, ExtentMetadata { gen: 31, flush: 3992, dirty: false }] => 0","v":0,"name":"crucible","level":30,"time":"2025-01-28T17:16:11.259202739Z","hostname":"w-01JJPY42J7TJ48QYFMTCCVFBHG","pid":1246,"":"mend","":"downstairs","":"downstairs","session_id":"05ab9ec5-5dfc-41a7-86fb-b32b311c7372"}
5312025-01-28T17:16:12.118Z{"msg":"found dest for source 0 for extent at index 0 => [ClientId(2)]","v":0,"name":"crucible","level":30,"time":"2025-01-28T17:16:11.259217497Z","hostname":"w-01JJPY42J7TJ48QYFMTCCVFBHG","pid":1246,"":"mend","":"downstairs","":"downstairs","session_id":"05ab9ec5-5dfc-41a7-86fb-b32b311c7372"}
5322025-01-28T17:16:12.118Z{"msg":"extent 1 needs reconciliation: ExtentMetadata { gen: 32, flush: 3993, dirty: false } ExtentMetadata { gen: 32, flush: 3993, dirty: false } ExtentMetadata { gen: 31, flush: 3992, dirty: false }","v":0,"name":"crucible","level":30,"time":"2025-01-28T17:16:11.259239754Z","hostname":"w-01JJPY42J7TJ48QYFMTCCVFBHG","pid":1246,"":"mend","":"downstairs","":"downstairs","session_id":"05ab9ec5-5dfc-41a7-86fb-b32b311c7372"}
5332025-01-28T17:16:12.118Z{"msg":"extent:0 [ExtentMetadata { gen: 32, flush: 3993, dirty: false }, ExtentMetadata { gen: 32, flush: 3993, dirty: false }, ExtentMetadata { gen: 31, flush: 3992, dirty: false }] => 0","v":0,"name":"crucible","level":30,"time":"2025-01-28T17:16:11.259255421Z","hostname":"w-01JJPY42J7TJ48QYFMTCCVFBHG","pid":1246,"":"mend","":"downstairs","":"downstairs","session_id":"05ab9ec5-5dfc-41a7-86fb-b32b311c7372"}
5342025-01-28T17:16:12.118Z{"msg":"found dest for source 0 for extent at index 1 => [ClientId(2)]","v":0,"name":"crucible","level":30,"time":"2025-01-28T17:16:11.259276078Z","hostname":"w-01JJPY42J7TJ48QYFMTCCVFBHG","pid":1246,"":"mend","":"downstairs","":"downstairs","session_id":"05ab9ec5-5dfc-41a7-86fb-b32b311c7372"}
5352025-01-28T17:16:12.118Z{"msg":"extent 2 needs reconciliation: ExtentMetadata { gen: 32, flush: 3993, dirty: false } ExtentMetadata { gen: 32, flush: 3993, dirty: false } ExtentMetadata { gen: 31, flush: 3992, dirty: false }","v":0,"name":"crucible","level":30,"time":"2025-01-28T17:16:11.259291876Z","hostname":"w-01JJPY42J7TJ48QYFMTCCVFBHG","pid":1246,"":"mend","":"downstairs","":"downstairs","session_id":"05ab9ec5-5dfc-41a7-86fb-b32b311c7372"}
5362025-01-28T17:16:12.118Z{"msg":"extent:0 [ExtentMetadata { gen: 32, flush: 3993, dirty: false }, ExtentMetadata { gen: 32, flush: 3993, dirty: false }, ExtentMetadata { gen: 31, flush: 3992, dirty: false }] => 0","v":0,"name":"crucible","level":30,"time":"2025-01-28T17:16:11.259314432Z","hostname":"w-01JJPY42J7TJ48QYFMTCCVFBHG","pid":1246,"":"mend","":"downstairs","":"downstairs","session_id":"05ab9ec5-5dfc-41a7-86fb-b32b311c7372"}
5372025-01-28T17:16:12.118Z{"msg":"found dest for source 0 for extent at index 2 => [ClientId(2)]","v":0,"name":"crucible","level":30,"time":"2025-01-28T17:16:11.25932859Z","hostname":"w-01JJPY42J7TJ48QYFMTCCVFBHG","pid":1246,"":"mend","":"downstairs","":"downstairs","session_id":"05ab9ec5-5dfc-41a7-86fb-b32b311c7372"}
5382025-01-28T17:16:12.118Z{"msg":"extent 3 needs reconciliation: ExtentMetadata { gen: 32, flush: 3993, dirty: false } ExtentMetadata { gen: 32, flush: 3993, dirty: false } ExtentMetadata { gen: 31, flush: 3992, dirty: false }","v":0,"name":"crucible","level":30,"time":"2025-01-28T17:16:11.259350716Z","hostname":"w-01JJPY42J7TJ48QYFMTCCVFBHG","pid":1246,"":"mend","":"downstairs","":"downstairs","session_id":"05ab9ec5-5dfc-41a7-86fb-b32b311c7372"}
5392025-01-28T17:16:12.118Z{"msg":"extent:0 [ExtentMetadata { gen: 32, flush: 3993, dirty: false }, ExtentMetadata { gen: 32, flush: 3993, dirty: false }, ExtentMetadata { gen: 31, flush: 3992, dirty: false }] => 0","v":0,"name":"crucible","level":30,"time":"2025-01-28T17:16:11.259366444Z","hostname":"w-01JJPY42J7TJ48QYFMTCCVFBHG","pid":1246,"":"mend","":"downstairs","":"downstairs","session_id":"05ab9ec5-5dfc-41a7-86fb-b32b311c7372"}
5402025-01-28T17:16:12.118Z{"msg":"found dest for source 0 for extent at index 3 => [ClientId(2)]","v":0,"name":"crucible","level":30,"time":"2025-01-28T17:16:11.259386801Z","hostname":"w-01JJPY42J7TJ48QYFMTCCVFBHG","pid":1246,"":"mend","":"downstairs","":"downstairs","session_id":"05ab9ec5-5dfc-41a7-86fb-b32b311c7372"}
5412025-01-28T17:16:12.118Z{"msg":"extent 4 needs reconciliation: ExtentMetadata { gen: 32, flush: 3993, dirty: false } ExtentMetadata { gen: 32, flush: 3993, dirty: false } ExtentMetadata { gen: 31, flush: 3992, dirty: false }","v":0,"name":"crucible","level":30,"time":"2025-01-28T17:16:11.259402268Z","hostname":"w-01JJPY42J7TJ48QYFMTCCVFBHG","pid":1246,"":"mend","":"downstairs","":"downstairs","session_id":"05ab9ec5-5dfc-41a7-86fb-b32b311c7372"}
5422025-01-28T17:16:12.118Z{"msg":"extent:0 [ExtentMetadata { gen: 32, flush: 3993, dirty: false }, ExtentMetadata { gen: 32, flush: 3993, dirty: false }, ExtentMetadata { gen: 31, flush: 3992, dirty: false }] => 0","v":0,"name":"crucible","level":30,"time":"2025-01-28T17:16:11.259424364Z","hostname":"w-01JJPY42J7TJ48QYFMTCCVFBHG","pid":1246,"":"mend","":"downstairs","":"downstairs","session_id":"05ab9ec5-5dfc-41a7-86fb-b32b311c7372"}
5432025-01-28T17:16:12.118Z{"msg":"found dest for source 0 for extent at index 4 => [ClientId(2)]","v":0,"name":"crucible","level":30,"time":"2025-01-28T17:16:11.259439022Z","hostname":"w-01JJPY42J7TJ48QYFMTCCVFBHG","pid":1246,"":"mend","":"downstairs","":"downstairs","session_id":"05ab9ec5-5dfc-41a7-86fb-b32b311c7372"}
5442025-01-28T17:16:12.118Z{"msg":"Transition from Connecting { state: WaitQuorum, mode: New } to Reconcile","v":0,"name":"crucible","level":30,"time":"2025-01-28T17:16:11.259460669Z","hostname":"w-01JJPY42J7TJ48QYFMTCCVFBHG","pid":1246,"client":"0","":"downstairs","session_id":"05ab9ec5-5dfc-41a7-86fb-b32b311c7372"}
5452025-01-28T17:16:12.118Z{"msg":"Transition from Connecting { state: WaitQuorum, mode: New } to Reconcile","v":0,"name":"crucible","level":30,"time":"2025-01-28T17:16:11.259474647Z","hostname":"w-01JJPY42J7TJ48QYFMTCCVFBHG","pid":1246,"client":"1","":"downstairs","session_id":"05ab9ec5-5dfc-41a7-86fb-b32b311c7372"}
5462025-01-28T17:16:12.118Z{"msg":"Transition from Connecting { state: WaitQuorum, mode: New } to Reconcile","v":0,"name":"crucible","level":30,"time":"2025-01-28T17:16:11.259495073Z","hostname":"w-01JJPY42J7TJ48QYFMTCCVFBHG","pid":1246,"client":"2","":"downstairs","session_id":"05ab9ec5-5dfc-41a7-86fb-b32b311c7372"}
5472025-01-28T17:16:12.118Z{"msg":"Full repair list: {ExtentId(1): ExtentFix { source: ClientId(0), dest: [ClientId(2)] }, ExtentId(3): ExtentFix { source: ClientId(0), dest: [ClientId(2)] }, ExtentId(0): ExtentFix { source: ClientId(0), dest: [ClientId(2)] }, ExtentId(2): ExtentFix { source: ClientId(0), dest: [ClientId(2)] }, ExtentId(4): ExtentFix { source: ClientId(0), dest: [ClientId(2)] }}","v":0,"name":"crucible","level":30,"time":"2025-01-28T17:16:11.25951357Z","hostname":"w-01JJPY42J7TJ48QYFMTCCVFBHG","pid":1246,"":"downstairs","":"downstairs","session_id":"05ab9ec5-5dfc-41a7-86fb-b32b311c7372"}
5482025-01-28T17:16:12.118Z{"msg":"Task list: [ReconcileIO { id: ReconciliationId(0), op: ExtentFlush { repair_id: ReconciliationId(0), extent_id: ExtentId(1), client_id: ClientId(0), flush_number: 3994, gen_number: 33 }, state: ClientData([New, New, New]) }, ReconcileIO { id: ReconciliationId(1), op: ExtentClose { repair_id: ReconciliationId(1), extent_id: ExtentId(1) }, state: ClientData([New, New, New]) }, ReconcileIO { id: ReconciliationId(2), op: ExtentRepair { repair_id: ReconciliationId(2), extent_id: ExtentId(1), source_client_id: ClientId(0), source_repair_address: 0.0.0.0:12810, dest_clients: [ClientId(2)] }, state: ClientData([New, New, New]) }, ReconcileIO { id: ReconciliationId(3), op: ExtentReopen { repair_id: ReconciliationId(3), extent_id: ExtentId(1) }, state: ClientData([New, New, New]) }, ReconcileIO { id: ReconciliationId(4), op: ExtentFlush { repair_id: ReconciliationId(4), extent_id: ExtentId(3), client_id: ClientId(0), flush_number: 3994, gen_number: 33 }, state: ClientData([New, New, New]) }, ReconcileIO { id: ReconciliationId(5), op: ExtentClose { repair_id: ReconciliationId(5), extent_id: ExtentId(3) }, state: ClientData([New, New, New]) }, ReconcileIO { id: ReconciliationId(6), op: ExtentRepair { repair_id: ReconciliationId(6), extent_id: ExtentId(3), source_client_id: ClientId(0), source_repair_address: 0.0.0.0:12810, dest_clients: [ClientId(2)] }, state: ClientData([New, New, New]) }, ReconcileIO { id: ReconciliationId(7), op: ExtentReopen { repair_id: ReconciliationId(7), extent_id: ExtentId(3) }, state: ClientData([New, New, New]) }, ReconcileIO { id: ReconciliationId(8), op: ExtentFlush { repair_id: ReconciliationId(8), extent_id: ExtentId(0), client_id: ClientId(0), flush_number: 3994, gen_number: 33 }, state: ClientData([New, New, New]) }, ReconcileIO { id: ReconciliationId(9), op: ExtentClose { repair_id: ReconciliationId(9), extent_id: ExtentId(0) }, state: ClientData([New, New, New]) }, ReconcileIO { id: ReconciliationId(10), op: ExtentRepair { repair_id: ReconciliationId(10), extent_id: ExtentId(0), source_client_id: ClientId(0), source_repair_address: 0.0.0.0:12810, dest_clients: [ClientId(2)] }, state: ClientData([New, New, New]) }, ReconcileIO { id: ReconciliationId(11), op: ExtentReopen { repair_id: ReconciliationId(11), extent_id: ExtentId(0) }, state: ClientData([New, New, New]) }, ReconcileIO { id: ReconciliationId(12), op: ExtentFlush { repair_id: ReconciliationId(12), extent_id: ExtentId(2), client_id: ClientId(0), flush_number: 3994, gen_number: 33 }, state: ClientData([New, New, New]) }, ReconcileIO { id: ReconciliationId(13), op: ExtentClose { repair_id: ReconciliationId(13), extent_id: ExtentId(2) }, state: ClientData([New, New, New]) }, ReconcileIO { id: ReconciliationId(14), op: ExtentRepair { repair_id: ReconciliationId(14), extent_id: ExtentId(2), source_client_id: ClientId(0), source_repair_address: 0.0.0.0:12810, dest_clients: [ClientId(2)] }, state: ClientData([New, New, New]) }, ReconcileIO { id: ReconciliationId(15), op: ExtentReopen { repair_id: ReconciliationId(15), extent_id: ExtentId(2) }, state: ClientData([New, New, New]) }, ReconcileIO { id: ReconciliationId(16), op: ExtentFlush { repair_id: ReconciliationId(16), extent_id: ExtentId(4), client_id: ClientId(0), flush_number: 3994, 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-28T17:16:11.259609875Z","hostname":"w-01JJPY42J7TJ48QYFMTCCVFBHG","pid":1246,"":"downstairs","":"downstairs","session_id":"05ab9ec5-5dfc-41a7-86fb-b32b311c7372"}
5492025-01-28T17:16:12.118Z{"msg":"starting reconciliation c0669abe-9fc9-4dc6-917f-e6978da5d6ba: found 20 extents that need repair","v":0,"name":"crucible","level":30,"time":"2025-01-28T17:16:11.259632372Z","hostname":"w-01JJPY42J7TJ48QYFMTCCVFBHG","pid":1246,"":"downstairs","":"downstairs","session_id":"05ab9ec5-5dfc-41a7-86fb-b32b311c7372"}
5502025-01-28T17:16:12.118Z{"msg":"sending reconcile request ReconciliationId(2)","v":0,"name":"crucible","level":30,"time":"2025-01-28T17:16:11.259925185Z","hostname":"w-01JJPY42J7TJ48QYFMTCCVFBHG","pid":1246,"client":"2","":"downstairs","session_id":"05ab9ec5-5dfc-41a7-86fb-b32b311c7372"}
5512025-01-28T17:16:12.126Z{"msg":"sending reconcile request ReconciliationId(6)","v":0,"name":"crucible","level":30,"time":"2025-01-28T17:16:11.270273513Z","hostname":"w-01JJPY42J7TJ48QYFMTCCVFBHG","pid":1246,"client":"2","":"downstairs","session_id":"05ab9ec5-5dfc-41a7-86fb-b32b311c7372"}
5522025-01-28T17:16:12.130Z{"msg":"sending reconcile request ReconciliationId(10)","v":0,"name":"crucible","level":30,"time":"2025-01-28T17:16:11.274170069Z","hostname":"w-01JJPY42J7TJ48QYFMTCCVFBHG","pid":1246,"client":"2","":"downstairs","session_id":"05ab9ec5-5dfc-41a7-86fb-b32b311c7372"}
5532025-01-28T17:16:12.133Z{"msg":"sending reconcile request ReconciliationId(14)","v":0,"name":"crucible","level":30,"time":"2025-01-28T17:16:11.277861446Z","hostname":"w-01JJPY42J7TJ48QYFMTCCVFBHG","pid":1246,"client":"2","":"downstairs","session_id":"05ab9ec5-5dfc-41a7-86fb-b32b311c7372"}
5542025-01-28T17:16:12.138Z{"msg":"sending reconcile request ReconciliationId(18)","v":0,"name":"crucible","level":30,"time":"2025-01-28T17:16:11.281709309Z","hostname":"w-01JJPY42J7TJ48QYFMTCCVFBHG","pid":1246,"client":"2","":"downstairs","session_id":"05ab9ec5-5dfc-41a7-86fb-b32b311c7372"}
5552025-01-28T17:16:12.141Z{"msg":"done with reconciliation","v":0,"name":"crucible","level":30,"time":"2025-01-28T17:16:11.284861582Z","hostname":"w-01JJPY42J7TJ48QYFMTCCVFBHG","pid":1246,"":"downstairs","":"downstairs","session_id":"05ab9ec5-5dfc-41a7-86fb-b32b311c7372"}
5562025-01-28T17:16:12.141Z{"msg":"Transition from Reconcile to Active","v":0,"name":"crucible","level":30,"time":"2025-01-28T17:16:11.284903036Z","hostname":"w-01JJPY42J7TJ48QYFMTCCVFBHG","pid":1246,"client":"0","":"downstairs","session_id":"05ab9ec5-5dfc-41a7-86fb-b32b311c7372"}
5572025-01-28T17:16:12.141Z{"msg":"Transition from Reconcile to Active","v":0,"name":"crucible","level":30,"time":"2025-01-28T17:16:11.284918933Z","hostname":"w-01JJPY42J7TJ48QYFMTCCVFBHG","pid":1246,"client":"1","":"downstairs","session_id":"05ab9ec5-5dfc-41a7-86fb-b32b311c7372"}
5582025-01-28T17:16:12.141Z{"msg":"Transition from Reconcile to Active","v":0,"name":"crucible","level":30,"time":"2025-01-28T17:16:11.284933251Z","hostname":"w-01JJPY42J7TJ48QYFMTCCVFBHG","pid":1246,"client":"2","":"downstairs","session_id":"05ab9ec5-5dfc-41a7-86fb-b32b311c7372"}
5592025-01-28T17:16:12.141Z{"msg":"All required reconciliation work is completed","v":0,"name":"crucible","level":30,"time":"2025-01-28T17:16:11.284947398Z","hostname":"w-01JJPY42J7TJ48QYFMTCCVFBHG","pid":1246,"session_id":"05ab9ec5-5dfc-41a7-86fb-b32b311c7372"}
5602025-01-28T17:16:12.141Z{"msg":"Set Downstairs and Upstairs active after reconciliation","v":0,"name":"crucible","level":30,"time":"2025-01-28T17:16:11.284959887Z","hostname":"w-01JJPY42J7TJ48QYFMTCCVFBHG","pid":1246,"session_id":"05ab9ec5-5dfc-41a7-86fb-b32b311c7372"}
5612025-01-28T17:16:12.145Z{"msg":"2bc7a807-910d-4572-8469-9bca33563301 is now active with session: 05ab9ec5-5dfc-41a7-86fb-b32b311c7372","v":0,"name":"crucible","level":30,"time":"2025-01-28T17:16:11.284972805Z","hostname":"w-01JJPY42J7TJ48QYFMTCCVFBHG","pid":1246,"session_id":"05ab9ec5-5dfc-41a7-86fb-b32b311c7372"}
5622025-01-28T17:16:12.145Z{"msg":"The guest has finished waiting for activation with:33","v":0,"name":"crucible","level":30,"time":"2025-01-28T17:16:11.284995561Z","hostname":"w-01JJPY42J7TJ48QYFMTCCVFBHG","pid":1246}
5632025-01-28T17:16:12.145Z{"msg":"The guest has requested activation with gen:33","v":0,"name":"crucible","level":30,"time":"2025-01-28T17:16:11.285033615Z","hostname":"w-01JJPY42J7TJ48QYFMTCCVFBHG","pid":1246}
5642025-01-28T17:16:12.145Z{"msg":"2bc7a807-910d-4572-8469-9bca33563301 active request set","v":0,"name":"crucible","level":30,"time":"2025-01-28T17:16:11.285056811Z","hostname":"w-01JJPY42J7TJ48QYFMTCCVFBHG","pid":1246,"session_id":"822a2999-1329-4fb6-b0c8-4ad0351a1b17"}
5652025-01-28T17:16:12.145Z{"msg":"sending connect oneshot to client","v":0,"name":"crucible","level":30,"time":"2025-01-28T17:16:11.285070489Z","hostname":"w-01JJPY42J7TJ48QYFMTCCVFBHG","pid":1246,"client":"0","":"downstairs","session_id":"822a2999-1329-4fb6-b0c8-4ad0351a1b17"}
5662025-01-28T17:16:12.145Z{"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-28T17:16:11.285093875Z","hostname":"w-01JJPY42J7TJ48QYFMTCCVFBHG","pid":1246,"client":"0","":"downstairs","session_id":"822a2999-1329-4fb6-b0c8-4ad0351a1b17"}
5672025-01-28T17:16:12.145Z{"msg":"sending connect oneshot to client","v":0,"name":"crucible","level":30,"time":"2025-01-28T17:16:11.285107623Z","hostname":"w-01JJPY42J7TJ48QYFMTCCVFBHG","pid":1246,"client":"1","":"downstairs","session_id":"822a2999-1329-4fb6-b0c8-4ad0351a1b17"}
5682025-01-28T17:16:12.145Z{"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-28T17:16:11.28513114Z","hostname":"w-01JJPY42J7TJ48QYFMTCCVFBHG","pid":1246,"client":"1","":"downstairs","session_id":"822a2999-1329-4fb6-b0c8-4ad0351a1b17"}
5692025-01-28T17:16:12.145Z{"msg":"sending connect oneshot to client","v":0,"name":"crucible","level":30,"time":"2025-01-28T17:16:11.285153206Z","hostname":"w-01JJPY42J7TJ48QYFMTCCVFBHG","pid":1246,"client":"2","":"downstairs","session_id":"822a2999-1329-4fb6-b0c8-4ad0351a1b17"}
5702025-01-28T17:16:12.145Z{"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-28T17:16:11.285175453Z","hostname":"w-01JJPY42J7TJ48QYFMTCCVFBHG","pid":1246,"client":"2","":"downstairs","session_id":"822a2999-1329-4fb6-b0c8-4ad0351a1b17"}
5712025-01-28T17:16:12.145Z{"msg":"connecting to 127.0.0.1:8860","v":0,"name":"crucible","level":30,"time":"2025-01-28T17:16:11.285208697Z","hostname":"w-01JJPY42J7TJ48QYFMTCCVFBHG","pid":1246,"":"io task","client":"2","":"downstairs","session_id":"822a2999-1329-4fb6-b0c8-4ad0351a1b17"}
5722025-01-28T17:16:12.145Z{"msg":"connecting to 127.0.0.1:8840","v":0,"name":"crucible","level":30,"time":"2025-01-28T17:16:11.285245031Z","hostname":"w-01JJPY42J7TJ48QYFMTCCVFBHG","pid":1246,"":"io task","client":"0","":"downstairs","session_id":"822a2999-1329-4fb6-b0c8-4ad0351a1b17"}
5732025-01-28T17:16:12.146Z{"msg":"connecting to 127.0.0.1:8850","v":0,"name":"crucible","level":30,"time":"2025-01-28T17:16:11.285271007Z","hostname":"w-01JJPY42J7TJ48QYFMTCCVFBHG","pid":1246,"":"io task","client":"1","":"downstairs","session_id":"822a2999-1329-4fb6-b0c8-4ad0351a1b17"}
5742025-01-28T17:16:12.146Z{"msg":"ds_connection connected from Ok(127.0.0.1:40631)","v":0,"name":"crucible","level":30,"time":"2025-01-28T17:16:11.28531891Z","hostname":"w-01JJPY42J7TJ48QYFMTCCVFBHG","pid":1246,"":"io task","client":"2","":"downstairs","session_id":"822a2999-1329-4fb6-b0c8-4ad0351a1b17"}
5752025-01-28T17:16:12.146Z{"msg":"ds_connection connected from Ok(127.0.0.1:33099)","v":0,"name":"crucible","level":30,"time":"2025-01-28T17:16:11.285347655Z","hostname":"w-01JJPY42J7TJ48QYFMTCCVFBHG","pid":1246,"":"io task","client":"0","":"downstairs","session_id":"822a2999-1329-4fb6-b0c8-4ad0351a1b17"}
5762025-01-28T17:16:12.146Z{"msg":"ds_connection connected from Ok(127.0.0.1:64598)","v":0,"name":"crucible","level":30,"time":"2025-01-28T17:16:11.285376141Z","hostname":"w-01JJPY42J7TJ48QYFMTCCVFBHG","pid":1246,"":"io task","client":"1","":"downstairs","session_id":"822a2999-1329-4fb6-b0c8-4ad0351a1b17"}
5772025-01-28T17:16:12.146Z{"msg":"version negotiation from state Connecting { state: WaitForPromote, mode: New }","v":0,"name":"crucible","level":30,"time":"2025-01-28T17:16:11.285716557Z","hostname":"w-01JJPY42J7TJ48QYFMTCCVFBHG","pid":1246,"client":"2","":"downstairs","session_id":"822a2999-1329-4fb6-b0c8-4ad0351a1b17"}
5782025-01-28T17:16:12.146Z{"msg":"version negotiation from state Connecting { state: WaitForPromote, mode: New }","v":0,"name":"crucible","level":30,"time":"2025-01-28T17:16:11.285875942Z","hostname":"w-01JJPY42J7TJ48QYFMTCCVFBHG","pid":1246,"client":"1","":"downstairs","session_id":"822a2999-1329-4fb6-b0c8-4ad0351a1b17"}
5792025-01-28T17:16:12.146Z{"msg":"version negotiation from state Connecting { state: WaitForPromote, mode: New }","v":0,"name":"crucible","level":30,"time":"2025-01-28T17:16:11.285929163Z","hostname":"w-01JJPY42J7TJ48QYFMTCCVFBHG","pid":1246,"client":"0","":"downstairs","session_id":"822a2999-1329-4fb6-b0c8-4ad0351a1b17"}
5802025-01-28T17:16:12.146Z{"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-28T17:16:11.28626911Z","hostname":"w-01JJPY42J7TJ48QYFMTCCVFBHG","pid":1246,"client":"2","":"downstairs","session_id":"822a2999-1329-4fb6-b0c8-4ad0351a1b17"}
5812025-01-28T17:16:12.146Z{"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-28T17:16:11.286400209Z","hostname":"w-01JJPY42J7TJ48QYFMTCCVFBHG","pid":1246,"client":"1","":"downstairs","session_id":"822a2999-1329-4fb6-b0c8-4ad0351a1b17"}
5822025-01-28T17:16:12.146Z{"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-28T17:16:11.286431184Z","hostname":"w-01JJPY42J7TJ48QYFMTCCVFBHG","pid":1246,"client":"0","":"downstairs","session_id":"822a2999-1329-4fb6-b0c8-4ad0351a1b17"}
5832025-01-28T17:16:12.146Z{"msg":"Waiting for more clients to be ready","v":0,"name":"crucible","level":30,"time":"2025-01-28T17:16:11.286631643Z","hostname":"w-01JJPY42J7TJ48QYFMTCCVFBHG","pid":1246,"session_id":"822a2999-1329-4fb6-b0c8-4ad0351a1b17"}
5842025-01-28T17:16:12.146Z{"msg":"Waiting for more clients to be ready","v":0,"name":"crucible","level":30,"time":"2025-01-28T17:16:11.286682105Z","hostname":"w-01JJPY42J7TJ48QYFMTCCVFBHG","pid":1246,"session_id":"822a2999-1329-4fb6-b0c8-4ad0351a1b17"}
5852025-01-28T17:16:12.146Z{"msg":"[0]R flush_numbers: [5318, 5318, 5318, 5318, 5318]","v":0,"name":"crucible","level":30,"time":"2025-01-28T17:16:11.286770031Z","hostname":"w-01JJPY42J7TJ48QYFMTCCVFBHG","pid":1246,"":"downstairs","":"downstairs","session_id":"822a2999-1329-4fb6-b0c8-4ad0351a1b17"}
5862025-01-28T17:16:12.146Z{"msg":"[0]R generation: [32, 32, 32, 32, 32]","v":0,"name":"crucible","level":30,"time":"2025-01-28T17:16:11.286798086Z","hostname":"w-01JJPY42J7TJ48QYFMTCCVFBHG","pid":1246,"":"downstairs","":"downstairs","session_id":"822a2999-1329-4fb6-b0c8-4ad0351a1b17"}
5872025-01-28T17:16:12.146Z{"msg":"[0]R dirty: [false, false, false, false, false]","v":0,"name":"crucible","level":30,"time":"2025-01-28T17:16:11.286812914Z","hostname":"w-01JJPY42J7TJ48QYFMTCCVFBHG","pid":1246,"":"downstairs","":"downstairs","session_id":"822a2999-1329-4fb6-b0c8-4ad0351a1b17"}
5882025-01-28T17:16:12.146Z{"msg":"[1]R flush_numbers: [5318, 5318, 5318, 5318, 5318]","v":0,"name":"crucible","level":30,"time":"2025-01-28T17:16:11.28683929Z","hostname":"w-01JJPY42J7TJ48QYFMTCCVFBHG","pid":1246,"":"downstairs","":"downstairs","session_id":"822a2999-1329-4fb6-b0c8-4ad0351a1b17"}
5892025-01-28T17:16:12.146Z{"msg":"[1]R generation: [32, 32, 32, 32, 32]","v":0,"name":"crucible","level":30,"time":"2025-01-28T17:16:11.286852698Z","hostname":"w-01JJPY42J7TJ48QYFMTCCVFBHG","pid":1246,"":"downstairs","":"downstairs","session_id":"822a2999-1329-4fb6-b0c8-4ad0351a1b17"}
5902025-01-28T17:16:12.146Z{"msg":"[1]R dirty: [false, false, false, false, false]","v":0,"name":"crucible","level":30,"time":"2025-01-28T17:16:11.286866316Z","hostname":"w-01JJPY42J7TJ48QYFMTCCVFBHG","pid":1246,"":"downstairs","":"downstairs","session_id":"822a2999-1329-4fb6-b0c8-4ad0351a1b17"}
5912025-01-28T17:16:12.146Z{"msg":"[2]R flush_numbers: [5318, 5318, 5318, 5318, 5318]","v":0,"name":"crucible","level":30,"time":"2025-01-28T17:16:11.286879584Z","hostname":"w-01JJPY42J7TJ48QYFMTCCVFBHG","pid":1246,"":"downstairs","":"downstairs","session_id":"822a2999-1329-4fb6-b0c8-4ad0351a1b17"}
5922025-01-28T17:16:12.146Z{"msg":"[2]R generation: [32, 32, 32, 32, 32]","v":0,"name":"crucible","level":30,"time":"2025-01-28T17:16:11.286893202Z","hostname":"w-01JJPY42J7TJ48QYFMTCCVFBHG","pid":1246,"":"downstairs","":"downstairs","session_id":"822a2999-1329-4fb6-b0c8-4ad0351a1b17"}
5932025-01-28T17:16:12.146ZWait for a query_work_queue command to finish before sending IO
5942025-01-28T17:16:12.146Z{"msg":"[2]R dirty: [false, false, false, false, false]","v":0,"name":"crucible","level":30,"time":"2025-01-28T17:16:11.286921527Z","hostname":"w-01JJPY42J7TJ48QYFMTCCVFBHG","pid":1246,"":"downstairs","":"downstairs","session_id":"822a2999-1329-4fb6-b0c8-4ad0351a1b17"}
5952025-01-28T17:16:12.146Z{"msg":"Max found gen is 33","v":0,"name":"crucible","level":30,"time":"2025-01-28T17:16:11.286944423Z","hostname":"w-01JJPY42J7TJ48QYFMTCCVFBHG","pid":1246,"":"downstairs","":"downstairs","session_id":"822a2999-1329-4fb6-b0c8-4ad0351a1b17"}
5962025-01-28T17:16:12.146Z{"msg":"Generation requested: 33 >= found:33","v":0,"name":"crucible","level":30,"time":"2025-01-28T17:16:11.286979528Z","hostname":"w-01JJPY42J7TJ48QYFMTCCVFBHG","pid":1246,"":"downstairs","":"downstairs","session_id":"822a2999-1329-4fb6-b0c8-4ad0351a1b17"}
5972025-01-28T17:16:12.146Z{"msg":"Next flush: 5319","v":0,"name":"crucible","level":30,"time":"2025-01-28T17:16:11.287035989Z","hostname":"w-01JJPY42J7TJ48QYFMTCCVFBHG","pid":1246,"":"downstairs","":"downstairs","session_id":"822a2999-1329-4fb6-b0c8-4ad0351a1b17"}
5982025-01-28T17:16:12.146Z{"msg":"All extents match","v":0,"name":"crucible","level":30,"time":"2025-01-28T17:16:11.287074643Z","hostname":"w-01JJPY42J7TJ48QYFMTCCVFBHG","pid":1246,"":"downstairs","":"downstairs","session_id":"822a2999-1329-4fb6-b0c8-4ad0351a1b17"}
5992025-01-28T17:16:12.146Z{"msg":"No downstairs reconciliation required","v":0,"name":"crucible","level":30,"time":"2025-01-28T17:16:11.287109037Z","hostname":"w-01JJPY42J7TJ48QYFMTCCVFBHG","pid":1246,"session_id":"822a2999-1329-4fb6-b0c8-4ad0351a1b17"}
6002025-01-28T17:16:12.146Z{"msg":"Transition from WaitQuorum to Active","v":0,"name":"crucible","level":30,"time":"2025-01-28T17:16:11.287124125Z","hostname":"w-01JJPY42J7TJ48QYFMTCCVFBHG","pid":1246,"client":"0","":"downstairs","session_id":"822a2999-1329-4fb6-b0c8-4ad0351a1b17"}
6012025-01-28T17:16:12.146Z{"msg":"Transition from WaitQuorum to Active","v":0,"name":"crucible","level":30,"time":"2025-01-28T17:16:11.287146271Z","hostname":"w-01JJPY42J7TJ48QYFMTCCVFBHG","pid":1246,"client":"1","":"downstairs","session_id":"822a2999-1329-4fb6-b0c8-4ad0351a1b17"}
6022025-01-28T17:16:12.146Z{"msg":"Transition from WaitQuorum to Active","v":0,"name":"crucible","level":30,"time":"2025-01-28T17:16:11.287179196Z","hostname":"w-01JJPY42J7TJ48QYFMTCCVFBHG","pid":1246,"client":"2","":"downstairs","session_id":"822a2999-1329-4fb6-b0c8-4ad0351a1b17"}
6032025-01-28T17:16:12.146Z{"msg":"All required reconciliation work is completed","v":0,"name":"crucible","level":30,"time":"2025-01-28T17:16:11.287202263Z","hostname":"w-01JJPY42J7TJ48QYFMTCCVFBHG","pid":1246,"session_id":"822a2999-1329-4fb6-b0c8-4ad0351a1b17"}
6042025-01-28T17:16:12.146Z{"msg":"Set Downstairs and Upstairs active after reconciliation","v":0,"name":"crucible","level":30,"time":"2025-01-28T17:16:11.287215141Z","hostname":"w-01JJPY42J7TJ48QYFMTCCVFBHG","pid":1246,"session_id":"822a2999-1329-4fb6-b0c8-4ad0351a1b17"}
6052025-01-28T17:16:12.146Z{"msg":"2bc7a807-910d-4572-8469-9bca33563301 is now active with session: 822a2999-1329-4fb6-b0c8-4ad0351a1b17","v":0,"name":"crucible","level":30,"time":"2025-01-28T17:16:11.287240717Z","hostname":"w-01JJPY42J7TJ48QYFMTCCVFBHG","pid":1246,"session_id":"822a2999-1329-4fb6-b0c8-4ad0351a1b17"}
6062025-01-28T17:16:12.146Z{"msg":"Set Active after no reconciliation","v":0,"name":"crucible","level":30,"time":"2025-01-28T17:16:11.287269042Z","hostname":"w-01JJPY42J7TJ48QYFMTCCVFBHG","pid":1246,"session_id":"822a2999-1329-4fb6-b0c8-4ad0351a1b17"}
6072025-01-28T17:16:12.146Z{"msg":"The guest has finished waiting for activation with:33","v":0,"name":"crucible","level":30,"time":"2025-01-28T17:16:11.28728261Z","hostname":"w-01JJPY42J7TJ48QYFMTCCVFBHG","pid":1246}
6082025-01-28T17:16:12.146ZDisk: sv:2 bs:4096 ts:409600 tb:100 max_io:100 or 409600
6092025-01-28T17:16:12.146ZLoading write count information from file "/var/tmp/test_up-build/verify_file"
6102025-01-28T17:16:12.146ZRead and Verify all blocks (0..100 range:true)
6112025-01-28T17:16:12.224ZWrote out file "/var/tmp/test_up-build/verify_file"
6122025-01-28T17:16:12.224ZVerify test completed
6132025-01-28T17:16:12.227ZWrote out file "/var/tmp/test_up-build/verify_file"
6142025-01-28T17:16:12.227ZCLIENT: Tests done. All submitted work has been ACK'd
6152025-01-28T17:16:12.227Z----------------------------------------------------------------
6162025-01-28T17:16:12.227Z Crucible gen:33 GIO:true work queues: Upstairs:0 downstairs:1
6172025-01-28T17:16:12.227ZStates: Active Active Active
6182025-01-28T17:16:12.227ZJOBID ACK TYPE BKS/EXT DS:0 DS:1 DS:2 REPLAY
6192025-01-28T17:16:12.227Z 1000 Acked Read 50 Done Done Done false
6202025-01-28T17:16:12.227Z STATES DS:0 DS:1 DS:2 TOTAL
6212025-01-28T17:16:12.227Z Sent 0 0 0 0
6222025-01-28T17:16:12.228Z Done 1 1 1 3
6232025-01-28T17:16:12.228Z Skipped 0 0 0 0
6242025-01-28T17:16:12.228Z Error 0 0 0 0
6252025-01-28T17:16:12.228ZLast Flush: None None None
6262025-01-28T17:16:12.228ZDownstairs last five completed:
6272025-01-28T17:16:12.228ZUpstairs last five completed: 1000
6282025-01-28T17:16:12.228Z----------------------------------------------------------------
6292025-01-28T17:16:12.228Z Crucible gen:33 GIO:true work queues: Upstairs:0 downstairs:1
6302025-01-28T17:16:12.228ZStates: Active Active Active
6312025-01-28T17:16:12.228ZJOBID ACK TYPE BKS/EXT DS:0 DS:1 DS:2 REPLAY
6322025-01-28T17:16:12.228Z 1000 Acked Read 50 Done Done Sent false
6332025-01-28T17:16:12.228Z STATES DS:0 DS:1 DS:2 TOTAL
6342025-01-28T17:16:12.228Z Sent 0 0 1 1
6352025-01-28T17:16:12.228Z Done 1 1 0 2
6362025-01-28T17:16:12.228Z Skipped 0 0 0 0
6372025-01-28T17:16:12.228Z Error 0 0 0 0
6382025-01-28T17:16:12.228ZLast Flush: None None None
6392025-01-28T17:16:12.228ZDownstairs last five completed:
6402025-01-28T17:16:12.228ZUpstairs last five completed: 1000
6412025-01-28T17:16:12.228ZCLIENT: Up:0 ds:2 act:6
6422025-01-28T17:16:16.227Z----------------------------------------------------------------
6432025-01-28T17:16:16.227Z Crucible gen:33 GIO:true work queues: Upstairs:0 downstairs:0
6442025-01-28T17:16:16.227ZDownstairs last five completed: 1001 1000
6452025-01-28T17:16:16.227ZUpstairs last five completed: 1001 1000
6462025-01-28T17:16:16.231Z----------------------------------------------------------------
6472025-01-28T17:16:16.232Z Crucible gen:33 GIO:true work queues: Upstairs:0 downstairs:0
6482025-01-28T17:16:16.232ZDownstairs last five completed: 1001 1000
6492025-01-28T17:16:16.232ZUpstairs last five completed: 1001 1000
6502025-01-28T17:16:16.232ZCLIENT: Up:0 ds:0 act:6
6512025-01-28T17:16:16.232ZCLIENT: All crucible jobs finished, exiting program
6522025-01-28T17:16:16.232Z{"msg":"Guest handle has been dropped","v":0,"name":"crucible","level":40,"time":"2025-01-28T17:16:15.370776237Z","hostname":"w-01JJPY42J7TJ48QYFMTCCVFBHG","pid":1246}
6532025-01-28T17:16:16.235ZRepair part 2 passed
6542025-01-28T17:16:16.238Z/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
6552025-01-28T17:16:16.254ZEXT BLOCKS GEN0 GEN1 GEN2 FL0 FL1 FL2 D0 D1 D2 DIFF
6562025-01-28T17:16:16.254Z 0 000-009 32 32 32 3993 3993 3993 F F F
6572025-01-28T17:16:16.254Z 1 010-019 32 32 32 3993 3993 3993 F F F
6582025-01-28T17:16:16.254Z 2 020-029 32 32 32 3993 3993 3993 F F F
6592025-01-28T17:16:16.254Z 3 030-039 32 32 32 3993 3993 3993 F F F
6602025-01-28T17:16:16.254Z 4 040-049 32 32 32 3993 3993 3993 F F F
6612025-01-28T17:16:16.254ZMax gen: 32, Max flush: 3993
6622025-01-28T17:16:16.259Zdump test passed
6632025-01-28T17:16:16.263Z/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
6642025-01-28T17:16:16.278Z Extent 1
6652025-01-28T17:16:16.284ZGEN 32 32 32
6662025-01-28T17:16:16.284ZFLUSH_ID 3993 3993 3993
6672025-01-28T17:16:16.284ZDIRTY
6682025-01-28T17:16:16.284Z
6692025-01-28T17:16:16.284ZBLOCK D0 D1 D2 C0 C1 C2 DIFF
6702025-01-28T17:16:16.284Z010 A A A A A A
6712025-01-28T17:16:16.284Z011 A A A A A A
6722025-01-28T17:16:16.284Z012 A A A A A A
6732025-01-28T17:16:16.287Z013 A A A A A A
6742025-01-28T17:16:16.287Z014 A A A A A A
6752025-01-28T17:16:16.287Z015 A A A A A A
6762025-01-28T17:16:16.290Z016 A A A A A A
6772025-01-28T17:16:16.290Z017 A A A A A A
6782025-01-28T17:16:16.293Z018 A A A A A A
6792025-01-28T17:16:16.293Z019 A A A A A A
6802025-01-28T17:16:16.298Zdump extent test passed
6812025-01-28T17:16:16.301Z/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
6822025-01-28T17:16:16.317ZExtent 2 Block in extent 0 Actual block 20
6832025-01-28T17:16:16.317Z
6842025-01-28T17:16:16.321Z DATA SHA256 VER
6852025-01-28T17:16:16.321Z------ ---------------------------------------------------------------- ---
6862025-01-28T17:16:16.321Z 0 f91babbf10471e4026c58ad99af5e9681fe4bfa86a648fd77a7919f28624a1d5 A
6872025-01-28T17:16:16.321Z 1 f91babbf10471e4026c58ad99af5e9681fe4bfa86a648fd77a7919f28624a1d5 A
6882025-01-28T17:16:16.321Z 2 f91babbf10471e4026c58ad99af5e9681fe4bfa86a648fd77a7919f28624a1d5 A
6892025-01-28T17:16:16.321Z
6902025-01-28T17:16:16.321ZNONCES 0 1 2 DIFF
6912025-01-28T17:16:16.321Z------ ------------------------ ------------------------ ------------------------ -----
6922025-01-28T17:16:16.321Z 0 66eba24999baa9baa489d225 66eba24999baa9baa489d225 66eba24999baa9baa489d225
6932025-01-28T17:16:16.321Z
6942025-01-28T17:16:16.321Z TAGS 0 1 2 DIFF
6952025-01-28T17:16:16.321Z------ -------------------------------- -------------------------------- -------------------------------- -----
6962025-01-28T17:16:16.321Z 0 b4b99905690d8c1e78c77767cb2ddf06 b4b99905690d8c1e78c77767cb2ddf06 b4b99905690d8c1e78c77767cb2ddf06
6972025-01-28T17:16:16.321Z
6982025-01-28T17:16:16.321ZHASHES 0 1 2 DIFF
6992025-01-28T17:16:16.321Z------ ---------------- ---------------- ---------------- -----
7002025-01-28T17:16:16.321Z
7012025-01-28T17:16:16.327Zdump block test passed
7022025-01-28T17:16:16.330ZInitial upstairs tests have completed, stopping all downstairs
7032025-01-28T17:16:21.397ZCreating 7 larger downstairs regions
7042025-01-28T17:16:21.609ZStarting 7 downstairs
7052025-01-28T17:16:26.618Zdsc restarted at PID: 1262
7062025-01-28T17:16:27.065ZNow do the replace-reconcile test
7072025-01-28T17:16:27.129ZUsing 8870 for the replacement port
7082025-01-28T17:19:04.460ZCompleted test: replace-reconcile
7092025-01-28T17:19:04.463ZNow do the replace-before-active test
7102025-01-28T17:22:37.890ZCompleted test: replace-before-active
7112025-01-28T17:22:37.892ZAll tests have completed, stopping all downstairs
7122025-01-28T17:22:37.950Z
7132025-01-28T17:22:37.950ZAll Tests have passed
7142025-01-28T17:22:37.953Z13:24 Test duration
7152025-01-28T17:22:37.953Z
7162025-01-28T17:22:37.953Zreal 13:23.372574909
7172025-01-28T17:22:37.953Zuser 18:39.260899185
7182025-01-28T17:22:37.953Zsys 26.992185191
7192025-01-28T17:22:37.953Ztrap 0.539734452
7202025-01-28T17:22:37.953Ztflt 0.034027616
7212025-01-28T17:22:37.953Zdflt 0.021669586
7222025-01-28T17:22:37.953Zkflt 0.001403282
7232025-01-28T17:22:37.953Zlock 25:33:51.046556930
7242025-01-28T17:22:37.953Zslp 1:14:26.633964974
7252025-01-28T17:22:37.953Zlat 2:01.685471691
7262025-01-28T17:22:37.953Zstop 0.279146714
7272025-01-28T17:22:37.953Z+ echo 'test-up-2region-encrypted ends'
7282025-01-28T17:22:37.953Ztest-up-2region-encrypted ends
7292025-01-28T17:22:42.958Zprocess exited: duration 811570 ms, exit code 0
7302025-01-28T17:22:42.958Zexec warning: : stdio descriptors remain open after task exit; waiting 60 seconds for them to close
7312025-01-28T17:23:42.970Zexec warning: : stdout descriptor may be held open by a background process; giving up!
7322025-01-28T17:23:42.970Zexec warning: : stderr descriptor may be held open by a background process; giving up!
 
7332025-01-28T17:23:42.981Zfound 17 output files
7342025-01-28T17:23:42.981Zuploading: /tmp/test_up-build/dsc-out.txt (48909 bytes)
7352025-01-28T17:23:43.994Zuploaded: /tmp/test_up-build/dsc-out.txt
7362025-01-28T17:23:43.994Zuploading: /tmp/test_up-build/test_up_out.txt (8429799 bytes)
7372025-01-28T17:23:45.163Zuploaded: /tmp/test_up-build/test_up_out.txt
7382025-01-28T17:23:45.163Zuploading: /tmp/test_up-build/dsc/downstairs-8810.txt (147260 bytes)
7392025-01-28T17:23:46.177Zuploaded: /tmp/test_up-build/dsc/downstairs-8810.txt
7402025-01-28T17:23:46.177Zuploading: /tmp/test_up-build/dsc/downstairs-8820.txt (144645 bytes)
7412025-01-28T17:23:47.192Zuploaded: /tmp/test_up-build/dsc/downstairs-8820.txt
7422025-01-28T17:23:47.192Zuploading: /tmp/test_up-build/dsc/downstairs-8830.txt (251027 bytes)
7432025-01-28T17:23:48.208Zuploaded: /tmp/test_up-build/dsc/downstairs-8830.txt
7442025-01-28T17:23:48.208Zuploading: /tmp/test_up-build/dsc/downstairs-8840.txt (139431 bytes)
7452025-01-28T17:23:49.222Zuploaded: /tmp/test_up-build/dsc/downstairs-8840.txt
7462025-01-28T17:23:49.222Zuploading: /tmp/test_up-build/dsc/downstairs-8850.txt (2500 bytes)
7472025-01-28T17:23:50.231Zuploaded: /tmp/test_up-build/dsc/downstairs-8850.txt
7482025-01-28T17:23:50.231Zuploading: /tmp/test_up-build/dsc/downstairs-8860.txt (33789 bytes)
7492025-01-28T17:23:51.242Zuploaded: /tmp/test_up-build/dsc/downstairs-8860.txt
7502025-01-28T17:23:51.242Zuploading: /tmp/test_up-build/dsc/downstairs-8870.txt (735754 bytes)
7512025-01-28T17:23:52.270Zuploaded: /tmp/test_up-build/dsc/downstairs-8870.txt
7522025-01-28T17:23:52.270Zuploading: /tmp/debug/df.txt (1270 bytes)
7532025-01-28T17:23:53.279Zuploaded: /tmp/debug/df.txt
7542025-01-28T17:23:53.279Zuploading: /tmp/debug/dtrace.txt (991838 bytes)
7552025-01-28T17:23:54.322Zuploaded: /tmp/debug/dtrace.txt
7562025-01-28T17:23:54.322Zuploading: /tmp/debug/iostat.txt (260759 bytes)
7572025-01-28T17:23:54.342Zupload warning: file "/tmp/debug/iostat.txt" changed size mid upload: 260759 -> 264059
7582025-01-28T17:23:55.347Zuploaded: /tmp/debug/iostat.txt
7592025-01-28T17:23:55.347Zuploading: /tmp/debug/mpstat.txt (633511 bytes)
7602025-01-28T17:23:55.380Zupload warning: file "/tmp/debug/mpstat.txt" changed size mid upload: 633511 -> 642259
7612025-01-28T17:23:56.386Zuploaded: /tmp/debug/mpstat.txt
7622025-01-28T17:23:56.386Zuploading: /tmp/debug/paging.txt (113681 bytes)
7632025-01-28T17:23:56.398Zupload warning: file "/tmp/debug/paging.txt" changed size mid upload: 113681 -> 115492
7642025-01-28T17:23:57.404Zuploaded: /tmp/debug/paging.txt
7652025-01-28T17:23:57.404Zuploading: /tmp/debug/prstat.txt (1231145 bytes)
7662025-01-28T17:23:57.451Zupload warning: file "/tmp/debug/prstat.txt" changed size mid upload: 1231145 -> 1250509
7672025-01-28T17:23:58.457Zuploaded: /tmp/debug/prstat.txt
7682025-01-28T17:23:58.458Zuploading: /tmp/debug/psrinfo.txt (1528 bytes)
7692025-01-28T17:23:59.465Zuploaded: /tmp/debug/psrinfo.txt
7702025-01-28T17:23:59.465Zuploading: /tmp/debug/upstairs-info.txt (177210 bytes)
7712025-01-28T17:24:00.486Zuploaded: /tmp/debug/upstairs-info.txt