01JJA6YZJ04HGW5RB519R96B52: 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: 01JJA6Z9N7YDQQQDGJFJF9151R

Tags:

Artefacts:

Output:

SEQ GLOBAL TIME DETAILS
12025-01-23T18:46:23.913Zjob dependencies complete; ready to run (waiting for 14 m 11 s)
22025-01-23T18:47:23.116Zjob assigned to worker 01JJA7SE9SCYB3AF1MKA8WXYP0 [factory aws, i-04d8906ab8f0dbc12] (queued for 59 s)
32025-01-23T18:47:30.997Zdownloading input: /input/build/work/bins/crucible-downstairs.gz
42025-01-23T18:47:32.107Zdownloaded input: /input/build/work/bins/crucible-downstairs.gz
52025-01-23T18:47:32.108Zdownloading input: /input/build/work/bins/crucible-hammer.gz
62025-01-23T18:47:33.384Zdownloaded input: /input/build/work/bins/crucible-hammer.gz
72025-01-23T18:47:33.384Zdownloading input: /input/build/work/bins/crutest.gz
82025-01-23T18:47:34.696Zdownloaded input: /input/build/work/bins/crutest.gz
92025-01-23T18:47:34.696Zdownloading input: /input/build/work/bins/dsc.gz
102025-01-23T18:47:35.512Zdownloaded input: /input/build/work/bins/dsc.gz
112025-01-23T18:47:35.525Zdownloading input: /input/build/work/scripts/perf-downstairs-tick.d
122025-01-23T18:47:35.534Zdownloaded input: /input/build/work/scripts/perf-downstairs-tick.d
132025-01-23T18:47:35.534Zdownloading input: /input/build/work/scripts/test_ds.sh
142025-01-23T18:47:35.552Zdownloaded input: /input/build/work/scripts/test_ds.sh
152025-01-23T18:47:35.552Zdownloading input: /input/build/work/scripts/test_live_repair.sh
162025-01-23T18:47:35.577Zdownloaded input: /input/build/work/scripts/test_live_repair.sh
172025-01-23T18:47:35.577Zdownloading input: /input/build/work/scripts/test_repair.sh
182025-01-23T18:47:35.603Zdownloaded input: /input/build/work/scripts/test_repair.sh
192025-01-23T18:47:35.603Zdownloading input: /input/build/work/scripts/test_replay.sh
202025-01-23T18:47:35.629Zdownloaded input: /input/build/work/scripts/test_replay.sh
212025-01-23T18:47:35.629Zdownloading input: /input/build/work/scripts/test_up.sh
222025-01-23T18:47:35.654Zdownloaded input: /input/build/work/scripts/test_up.sh
232025-01-23T18:47:35.654Zdownloading input: /input/build/work/scripts/upstairs_info.d
242025-01-23T18:47:35.674Zdownloaded input: /input/build/work/scripts/upstairs_info.d
252025-01-23T18:47:35.701Zdownloading input: /input/build/tmp/cargo-test-out.log
262025-01-23T18:47:36.481Zdownloaded input: /input/build/tmp/cargo-test-out.log
 
272025-01-23T18:47:36.481Zstarting task 0: "setup"
282025-01-23T18:47:36.489Z++ uname -s
292025-01-23T18:47:36.497Z+ kern=SunOS
302025-01-23T18:47:36.497Z+ case "$kern" in
312025-01-23T18:47:36.497Z+ groupadd -g 12345 build
322025-01-23T18:47:36.497Z+ useradd -u 12345 -g build -d /home/build -s /bin/bash -c build -P 'Primary Administrator' build
332025-01-23T18:47:38.501Z+ zfs create -o mountpoint=/work rpool/work
342025-01-23T18:47:38.707Z++ awk '$2 == "/home" { print $3 }' /etc/mnttab
352025-01-23T18:47:38.709Z+ home_fs=zfs
362025-01-23T18:47:38.709Z+ [[ zfs == autofs ]]
372025-01-23T18:47:38.709Z+ mkdir -p /home/build
382025-01-23T18:47:38.712Z+ chown build:build /home/build /work
392025-01-23T18:47:40.713Z+ chmod 0700 /home/build /work
402025-01-23T18:47:40.716Zprocess exited: duration 4239 ms, exit code 0
 
412025-01-23T18:47:40.721Zstarting task 1: "authentication"
422025-01-23T18:47:40.739Zprocess exited: duration 17 ms, exit code 0
 
432025-01-23T18:47:40.744Zstarting task 2: "build"
442025-01-23T18:47:40.749Z+ banner cores
452025-01-23T18:47:40.764Z
462025-01-23T18:47:40.764Z #### #### ##### ###### ####
472025-01-23T18:47:40.764Z # # # # # # # #
482025-01-23T18:47:40.764Z # # # # # ##### ####
492025-01-23T18:47:40.764Z # # # ##### # #
502025-01-23T18:47:40.764Z # # # # # # # # #
512025-01-23T18:47:40.764Z #### #### # # ###### ####
522025-01-23T18:47:40.764Z
532025-01-23T18:47:40.767Z+ pfexec coreadm -i /tmp/core.%f.%p -g /tmp/core.%f.%p -e global -e log -e proc-setid -e global-setid
542025-01-23T18:47:40.773Z+ banner unpack
552025-01-23T18:47:40.776Z
562025-01-23T18:47:40.776Z # # # # ##### ## #### # #
572025-01-23T18:47:40.776Z # # ## # # # # # # # # #
582025-01-23T18:47:40.776Z # # # # # # # # # # ####
592025-01-23T18:47:40.776Z # # # # # ##### ###### # # #
602025-01-23T18:47:40.776Z # # # ## # # # # # # #
612025-01-23T18:47:40.776Z #### # # # # # #### # #
622025-01-23T18:47:40.776Z
632025-01-23T18:47:40.776Z+ mkdir -p /var/tmp/bins
642025-01-23T18:47:40.780Z+ for t in "$input/bins/"*.gz
652025-01-23T18:47:40.780Z++ basename /input/build/work/bins/crucible-downstairs.gz
662025-01-23T18:47:40.783Z+ b=crucible-downstairs.gz
672025-01-23T18:47:40.783Z+ b=crucible-downstairs
682025-01-23T18:47:40.783Z+ gunzip
692025-01-23T18:47:43.024Z+ chmod +x /var/tmp/bins/crucible-downstairs
702025-01-23T18:47:43.026Z+ for t in "$input/bins/"*.gz
712025-01-23T18:47:43.029Z++ basename /input/build/work/bins/crucible-hammer.gz
722025-01-23T18:47:43.029Z+ b=crucible-hammer.gz
732025-01-23T18:47:43.029Z+ b=crucible-hammer
742025-01-23T18:47:43.029Z+ gunzip
752025-01-23T18:47:45.151Z+ chmod +x /var/tmp/bins/crucible-hammer
762025-01-23T18:47:45.154Z+ for t in "$input/bins/"*.gz
772025-01-23T18:47:45.156Z++ basename /input/build/work/bins/crutest.gz
782025-01-23T18:47:45.156Z+ b=crutest.gz
792025-01-23T18:47:45.156Z+ b=crutest
802025-01-23T18:47:45.157Z+ gunzip
812025-01-23T18:47:47.544Z+ chmod +x /var/tmp/bins/crutest
822025-01-23T18:47:47.547Z+ for t in "$input/bins/"*.gz
832025-01-23T18:47:47.550Z++ basename /input/build/work/bins/dsc.gz
842025-01-23T18:47:47.552Z+ b=dsc.gz
852025-01-23T18:47:47.552Z+ b=dsc
862025-01-23T18:47:47.552Z+ gunzip
872025-01-23T18:47:48.919Z+ chmod +x /var/tmp/bins/dsc
882025-01-23T18:47:48.921Z+ export BINDIR=/var/tmp/bins
892025-01-23T18:47:48.922Z+ BINDIR=/var/tmp/bins
902025-01-23T18:47:48.922Z+ jobpid=1139
912025-01-23T18:47:48.924Z+ echo 'Setup debug logging'
922025-01-23T18:47:48.924ZSetup debug logging
932025-01-23T18:47:48.924Z+ mkdir /tmp/debug
942025-01-23T18:47:48.924Z+ sleep 3600
952025-01-23T18:47:48.924Z+ psrinfo -v
962025-01-23T18:47:48.928Z+ df -h
972025-01-23T18:47:48.935Z+ prstat -d d -mLc 1
982025-01-23T18:47:48.938Z+ iostat -T d -xn 1
992025-01-23T18:47:48.938Z+ mpstat -T d 1
1002025-01-23T18:47:48.938Z+ vmstat -T d -p 1
1012025-01-23T18:47:48.940Z+ pfexec dtrace -Z -s /input/build/work/scripts/perf-downstairs-tick.d
1022025-01-23T18:47:48.940Z+ banner test_up_2r_encrypted
1032025-01-23T18:47:48.940Z+ pfexec dtrace -Z -s /input/build/work/scripts/upstairs_info.d
1042025-01-23T18:47:48.943Z #####
1052025-01-23T18:47:48.943Z ##### ###### #### ##### # # ##### # # #####
1062025-01-23T18:47:48.943Z # # # # # # # # # # #
1072025-01-23T18:47:48.943Z # ##### #### # # # # # ##### # #
1082025-01-23T18:47:48.943Z # # # # # # ##### # #####
1092025-01-23T18:47:48.943Z # # # # # # # # # # #
1102025-01-23T18:47:48.943Z # ###### #### # ####### #### # ####### ####### # #
1112025-01-23T18:47:48.943Z
1122025-01-23T18:47:48.943Z+ ptime -m bash /input/build/work/scripts/test_up.sh -r 2 -N encrypted
1132025-01-23T18:47:48.952Z/input/build/work
1142025-01-23T18:47:48.976ZUsing 2 region sets
1152025-01-23T18:47:48.976ZTurn off color for downstairs dump
1162025-01-23T18:47:48.993ZUpstairs using key: 9xPvF7de3WZ1vCpioKQCACyo8vJ/rwySjcN3nDeHU00=
1172025-01-23T18:47:48.996Zdsc output goes to /tmp/test_up-build/dsc-out.txt
1182025-01-23T18:47:48.996ZCreating 6 downstairs regions
1192025-01-23T18:47:49.352ZStarting 6 downstairs
1202025-01-23T18:47:49.355Zdsc started at PID: 1187
1212025-01-23T18:47:54.691ZDisable automatic restart on all downstairs
1222025-01-23T18:47:54.743Z
1232025-01-23T18:47:54.743ZBegin tests, output goes to /tmp/test_up-build/test_up_out.txt
1242025-01-23T18:47:54.746ZRunning test: span
1252025-01-23T18:47:58.911ZCompleted test: span
1262025-01-23T18:48:03.918ZRunning test: big
1272025-01-23T18:48:08.506ZCompleted test: big
1282025-01-23T18:48:13.514ZRunning test: dep
1292025-01-23T18:48:46.826ZCompleted test: dep
1302025-01-23T18:48:51.833ZRunning test: balloon
1312025-01-23T18:53:07.334ZCompleted test: balloon
1322025-01-23T18:53:12.340ZRunning test: deactivate
1332025-01-23T18:54:07.017ZCompleted test: deactivate
1342025-01-23T18:54:12.023ZRunning hammer
1352025-01-23T18:54:24.761ZRun repair tests
1362025-01-23T18:54:24.764Z/var/tmp/bins/crutest fill -g 31 -q --key 9xPvF7de3WZ1vCpioKQCACyo8vJ/rwySjcN3nDeHU00= --dsc 127.0.0.1:9998 --verify-out /var/tmp/test_up-build/verify_file
1372025-01-23T18:54:24.824Z{"msg":"Use this region info from dsc: RegionExtentInfo { block_size: 4096, blocks_per_extent: 10, extent_count: 5 }","v":0,"name":"crucible","level":30,"time":"2025-01-23T18:54:24.578215299Z","hostname":"w-01JJA7SE9SCYB3AF1MKA8WXYP0","pid":1230,"task":"crutest"}
1382025-01-23T18:54:24.828Z{"msg":"dsc has 6 regions. This means 2 sub_volumes","v":0,"name":"crucible","level":30,"time":"2025-01-23T18:54:24.57881748Z","hostname":"w-01JJA7SE9SCYB3AF1MKA8WXYP0","pid":1230,"task":"crutest"}
1392025-01-23T18:54:24.828Z{"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-23T18:54:24.580517033Z","hostname":"w-01JJA7SE9SCYB3AF1MKA8WXYP0","pid":1230,"task":"crutest"}
1402025-01-23T18:54:24.828Z{"msg":"Upstairs starts","v":0,"name":"crucible","level":30,"time":"2025-01-23T18:54:24.580727503Z","hostname":"w-01JJA7SE9SCYB3AF1MKA8WXYP0","pid":1230}
1412025-01-23T18:54:24.828Z{"msg":"Crucible Version: BuildInfo {\n version: \"0.0.1\",\n git_sha: \"dd1cf1330bf5c5b1551a0ad961a7aa7c6207feae\",\n git_commit_timestamp: \"2025-01-23T18:31:41.000000000Z\",\n git_branch: \"mkeeter/early-io-rejection\",\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-23T18:54:24.580773803Z","hostname":"w-01JJA7SE9SCYB3AF1MKA8WXYP0","pid":1230}
1422025-01-23T18:54:24.828Z{"msg":"Upstairs <-> Downstairs Message Version: 13","v":0,"name":"crucible","level":30,"time":"2025-01-23T18:54:24.580797563Z","hostname":"w-01JJA7SE9SCYB3AF1MKA8WXYP0","pid":1230}
1432025-01-23T18:54:24.828Z{"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-23T18:54:24.580813513Z","hostname":"w-01JJA7SE9SCYB3AF1MKA8WXYP0","pid":1230}
1442025-01-23T18:54:24.828Z{"msg":"Crucible c616f691-1688-47c3-a9db-04fa97d0e601 has session id: 9ccb1b55-1b2c-4cfe-932d-91c9d0ace6f5","v":0,"name":"crucible","level":30,"time":"2025-01-23T18:54:24.581428314Z","hostname":"w-01JJA7SE9SCYB3AF1MKA8WXYP0","pid":1230,"session_id":"9ccb1b55-1b2c-4cfe-932d-91c9d0ace6f5"}
1452025-01-23T18:54:24.829Z{"msg":"Upstairs opts: Upstairs UUID: c616f691-1688-47c3-a9db-04fa97d0e601, 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-23T18:54:24.581477484Z","hostname":"w-01JJA7SE9SCYB3AF1MKA8WXYP0","pid":1230,"session_id":"9ccb1b55-1b2c-4cfe-932d-91c9d0ace6f5"}
1462025-01-23T18:54:24.829Z{"msg":"Crucible stats registered with UUID: c616f691-1688-47c3-a9db-04fa97d0e601","v":0,"name":"crucible","level":30,"time":"2025-01-23T18:54:24.581493324Z","hostname":"w-01JJA7SE9SCYB3AF1MKA8WXYP0","pid":1230,"session_id":"9ccb1b55-1b2c-4cfe-932d-91c9d0ace6f5"}
1472025-01-23T18:54:24.829Z{"msg":"could not find Downstairs address for Nexus","v":0,"name":"crucible","level":40,"time":"2025-01-23T18:54:24.581505754Z","hostname":"w-01JJA7SE9SCYB3AF1MKA8WXYP0","pid":1230,"session_id":"9ccb1b55-1b2c-4cfe-932d-91c9d0ace6f5"}
1482025-01-23T18:54:24.834Z{"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-23T18:54:24.583514547Z","hostname":"w-01JJA7SE9SCYB3AF1MKA8WXYP0","pid":1230,"task":"crutest"}
1492025-01-23T18:54:24.834Z{"msg":"Upstairs starts","v":0,"name":"crucible","level":30,"time":"2025-01-23T18:54:24.583573597Z","hostname":"w-01JJA7SE9SCYB3AF1MKA8WXYP0","pid":1230}
1502025-01-23T18:54:24.834Z{"msg":"Crucible Version: BuildInfo {\n version: \"0.0.1\",\n git_sha: \"dd1cf1330bf5c5b1551a0ad961a7aa7c6207feae\",\n git_commit_timestamp: \"2025-01-23T18:31:41.000000000Z\",\n git_branch: \"mkeeter/early-io-rejection\",\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-23T18:54:24.583604327Z","hostname":"w-01JJA7SE9SCYB3AF1MKA8WXYP0","pid":1230}
1512025-01-23T18:54:24.834Z{"msg":"Upstairs <-> Downstairs Message Version: 13","v":0,"name":"crucible","level":30,"time":"2025-01-23T18:54:24.583631077Z","hostname":"w-01JJA7SE9SCYB3AF1MKA8WXYP0","pid":1230}
1522025-01-23T18:54:24.834Z{"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-23T18:54:24.583649147Z","hostname":"w-01JJA7SE9SCYB3AF1MKA8WXYP0","pid":1230}
1532025-01-23T18:54:24.834Z{"msg":"Crucible c616f691-1688-47c3-a9db-04fa97d0e601 has session id: 483f0b99-e7a6-4888-b357-3c470b30eda0","v":0,"name":"crucible","level":30,"time":"2025-01-23T18:54:24.584030308Z","hostname":"w-01JJA7SE9SCYB3AF1MKA8WXYP0","pid":1230,"session_id":"483f0b99-e7a6-4888-b357-3c470b30eda0"}
1542025-01-23T18:54:24.834Z{"msg":"Upstairs opts: Upstairs UUID: c616f691-1688-47c3-a9db-04fa97d0e601, 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-23T18:54:24.584108768Z","hostname":"w-01JJA7SE9SCYB3AF1MKA8WXYP0","pid":1230,"session_id":"483f0b99-e7a6-4888-b357-3c470b30eda0"}
1552025-01-23T18:54:24.834Z{"msg":"Crucible stats registered with UUID: c616f691-1688-47c3-a9db-04fa97d0e601","v":0,"name":"crucible","level":30,"time":"2025-01-23T18:54:24.584157048Z","hostname":"w-01JJA7SE9SCYB3AF1MKA8WXYP0","pid":1230,"session_id":"483f0b99-e7a6-4888-b357-3c470b30eda0"}
1562025-01-23T18:54:24.834Z{"msg":"could not find Downstairs address for Nexus","v":0,"name":"crucible","level":40,"time":"2025-01-23T18:54:24.584178448Z","hostname":"w-01JJA7SE9SCYB3AF1MKA8WXYP0","pid":1230,"session_id":"483f0b99-e7a6-4888-b357-3c470b30eda0"}
1572025-01-23T18:54:24.834Z{"msg":"Downstairs in volume = 6","v":0,"name":"crucible","level":30,"time":"2025-01-23T18:54:24.584812659Z","hostname":"w-01JJA7SE9SCYB3AF1MKA8WXYP0","pid":1230,"task":"crutest"}
1582025-01-23T18:54:24.834Z{"msg":"The guest has requested activation with gen:31","v":0,"name":"crucible","level":30,"time":"2025-01-23T18:54:24.584862779Z","hostname":"w-01JJA7SE9SCYB3AF1MKA8WXYP0","pid":1230}
1592025-01-23T18:54:24.834Z{"msg":"c616f691-1688-47c3-a9db-04fa97d0e601 active request set","v":0,"name":"crucible","level":30,"time":"2025-01-23T18:54:24.584881629Z","hostname":"w-01JJA7SE9SCYB3AF1MKA8WXYP0","pid":1230,"session_id":"9ccb1b55-1b2c-4cfe-932d-91c9d0ace6f5"}
1602025-01-23T18:54:24.834Z{"msg":"sending connect oneshot to client","v":0,"name":"crucible","level":30,"time":"2025-01-23T18:54:24.584895219Z","hostname":"w-01JJA7SE9SCYB3AF1MKA8WXYP0","pid":1230,"client":"0","":"downstairs","session_id":"9ccb1b55-1b2c-4cfe-932d-91c9d0ace6f5"}
1612025-01-23T18:54:24.834Z{"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-23T18:54:24.584936379Z","hostname":"w-01JJA7SE9SCYB3AF1MKA8WXYP0","pid":1230,"client":"0","":"downstairs","session_id":"9ccb1b55-1b2c-4cfe-932d-91c9d0ace6f5"}
1622025-01-23T18:54:24.834Z{"msg":"sending connect oneshot to client","v":0,"name":"crucible","level":30,"time":"2025-01-23T18:54:24.584963889Z","hostname":"w-01JJA7SE9SCYB3AF1MKA8WXYP0","pid":1230,"client":"1","":"downstairs","session_id":"9ccb1b55-1b2c-4cfe-932d-91c9d0ace6f5"}
1632025-01-23T18:54:24.834Z{"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-23T18:54:24.585006409Z","hostname":"w-01JJA7SE9SCYB3AF1MKA8WXYP0","pid":1230,"client":"1","":"downstairs","session_id":"9ccb1b55-1b2c-4cfe-932d-91c9d0ace6f5"}
1642025-01-23T18:54:24.834Z{"msg":"sending connect oneshot to client","v":0,"name":"crucible","level":30,"time":"2025-01-23T18:54:24.585055479Z","hostname":"w-01JJA7SE9SCYB3AF1MKA8WXYP0","pid":1230,"client":"2","":"downstairs","session_id":"9ccb1b55-1b2c-4cfe-932d-91c9d0ace6f5"}
1652025-01-23T18:54:24.834Z{"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-23T18:54:24.585084789Z","hostname":"w-01JJA7SE9SCYB3AF1MKA8WXYP0","pid":1230,"client":"2","":"downstairs","session_id":"9ccb1b55-1b2c-4cfe-932d-91c9d0ace6f5"}
1662025-01-23T18:54:24.834Z{"msg":"connecting to 127.0.0.1:8830","v":0,"name":"crucible","level":30,"time":"2025-01-23T18:54:24.585125419Z","hostname":"w-01JJA7SE9SCYB3AF1MKA8WXYP0","pid":1230,"":"io task","client":"2","":"downstairs","session_id":"9ccb1b55-1b2c-4cfe-932d-91c9d0ace6f5"}
1672025-01-23T18:54:24.834Z{"msg":"connecting to 127.0.0.1:8810","v":0,"name":"crucible","level":30,"time":"2025-01-23T18:54:24.585169049Z","hostname":"w-01JJA7SE9SCYB3AF1MKA8WXYP0","pid":1230,"":"io task","client":"0","":"downstairs","session_id":"9ccb1b55-1b2c-4cfe-932d-91c9d0ace6f5"}
1682025-01-23T18:54:24.834Z{"msg":"connecting to 127.0.0.1:8820","v":0,"name":"crucible","level":30,"time":"2025-01-23T18:54:24.58526636Z","hostname":"w-01JJA7SE9SCYB3AF1MKA8WXYP0","pid":1230,"":"io task","client":"1","":"downstairs","session_id":"9ccb1b55-1b2c-4cfe-932d-91c9d0ace6f5"}
1692025-01-23T18:54:24.834Z{"msg":"ds_connection connected from Ok(127.0.0.1:50227)","v":0,"name":"crucible","level":30,"time":"2025-01-23T18:54:24.58537855Z","hostname":"w-01JJA7SE9SCYB3AF1MKA8WXYP0","pid":1230,"":"io task","client":"2","":"downstairs","session_id":"9ccb1b55-1b2c-4cfe-932d-91c9d0ace6f5"}
1702025-01-23T18:54:24.834Z{"msg":"ds_connection connected from Ok(127.0.0.1:55334)","v":0,"name":"crucible","level":30,"time":"2025-01-23T18:54:24.58541224Z","hostname":"w-01JJA7SE9SCYB3AF1MKA8WXYP0","pid":1230,"":"io task","client":"0","":"downstairs","session_id":"9ccb1b55-1b2c-4cfe-932d-91c9d0ace6f5"}
1712025-01-23T18:54:24.834Z{"msg":"ds_connection connected from Ok(127.0.0.1:34258)","v":0,"name":"crucible","level":30,"time":"2025-01-23T18:54:24.58545244Z","hostname":"w-01JJA7SE9SCYB3AF1MKA8WXYP0","pid":1230,"":"io task","client":"1","":"downstairs","session_id":"9ccb1b55-1b2c-4cfe-932d-91c9d0ace6f5"}
1722025-01-23T18:54:24.834Z{"msg":"version negotiation from state Connecting { state: WaitForPromote, mode: New }","v":0,"name":"crucible","level":30,"time":"2025-01-23T18:54:24.585914181Z","hostname":"w-01JJA7SE9SCYB3AF1MKA8WXYP0","pid":1230,"client":"1","":"downstairs","session_id":"9ccb1b55-1b2c-4cfe-932d-91c9d0ace6f5"}
1732025-01-23T18:54:24.834Z{"msg":"version negotiation from state Connecting { state: WaitForPromote, mode: New }","v":0,"name":"crucible","level":30,"time":"2025-01-23T18:54:24.58598929Z","hostname":"w-01JJA7SE9SCYB3AF1MKA8WXYP0","pid":1230,"client":"0","":"downstairs","session_id":"9ccb1b55-1b2c-4cfe-932d-91c9d0ace6f5"}
1742025-01-23T18:54:24.834Z{"msg":"version negotiation from state Connecting { state: WaitForPromote, mode: New }","v":0,"name":"crucible","level":30,"time":"2025-01-23T18:54:24.586019391Z","hostname":"w-01JJA7SE9SCYB3AF1MKA8WXYP0","pid":1230,"client":"2","":"downstairs","session_id":"9ccb1b55-1b2c-4cfe-932d-91c9d0ace6f5"}
1752025-01-23T18:54:24.834Z{"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-23T18:54:24.586468301Z","hostname":"w-01JJA7SE9SCYB3AF1MKA8WXYP0","pid":1230,"client":"1","":"downstairs","session_id":"9ccb1b55-1b2c-4cfe-932d-91c9d0ace6f5"}
1762025-01-23T18:54:24.834Z{"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-23T18:54:24.586615042Z","hostname":"w-01JJA7SE9SCYB3AF1MKA8WXYP0","pid":1230,"client":"0","":"downstairs","session_id":"9ccb1b55-1b2c-4cfe-932d-91c9d0ace6f5"}
1772025-01-23T18:54:24.834Z{"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-23T18:54:24.586656031Z","hostname":"w-01JJA7SE9SCYB3AF1MKA8WXYP0","pid":1230,"client":"2","":"downstairs","session_id":"9ccb1b55-1b2c-4cfe-932d-91c9d0ace6f5"}
1782025-01-23T18:54:24.834Z{"msg":"Waiting for more clients to be ready","v":0,"name":"crucible","level":30,"time":"2025-01-23T18:54:24.586911012Z","hostname":"w-01JJA7SE9SCYB3AF1MKA8WXYP0","pid":1230,"session_id":"9ccb1b55-1b2c-4cfe-932d-91c9d0ace6f5"}
1792025-01-23T18:54:24.834Z{"msg":"Waiting for more clients to be ready","v":0,"name":"crucible","level":30,"time":"2025-01-23T18:54:24.587012482Z","hostname":"w-01JJA7SE9SCYB3AF1MKA8WXYP0","pid":1230,"session_id":"9ccb1b55-1b2c-4cfe-932d-91c9d0ace6f5"}
1802025-01-23T18:54:24.834Z{"msg":"[0]R flush_numbers: [4000, 4000, 4000, 4000, 4000]","v":0,"name":"crucible","level":30,"time":"2025-01-23T18:54:24.587043402Z","hostname":"w-01JJA7SE9SCYB3AF1MKA8WXYP0","pid":1230,"":"downstairs","":"downstairs","session_id":"9ccb1b55-1b2c-4cfe-932d-91c9d0ace6f5"}
1812025-01-23T18:54:24.834Z{"msg":"[0]R generation: [25, 25, 25, 25, 25]","v":0,"name":"crucible","level":30,"time":"2025-01-23T18:54:24.587059042Z","hostname":"w-01JJA7SE9SCYB3AF1MKA8WXYP0","pid":1230,"":"downstairs","":"downstairs","session_id":"9ccb1b55-1b2c-4cfe-932d-91c9d0ace6f5"}
1822025-01-23T18:54:24.834Z{"msg":"[0]R dirty: [false, false, false, false, false]","v":0,"name":"crucible","level":30,"time":"2025-01-23T18:54:24.587080112Z","hostname":"w-01JJA7SE9SCYB3AF1MKA8WXYP0","pid":1230,"":"downstairs","":"downstairs","session_id":"9ccb1b55-1b2c-4cfe-932d-91c9d0ace6f5"}
1832025-01-23T18:54:24.834Z{"msg":"[1]R flush_numbers: [4000, 4000, 4000, 4000, 4000]","v":0,"name":"crucible","level":30,"time":"2025-01-23T18:54:24.587093962Z","hostname":"w-01JJA7SE9SCYB3AF1MKA8WXYP0","pid":1230,"":"downstairs","":"downstairs","session_id":"9ccb1b55-1b2c-4cfe-932d-91c9d0ace6f5"}
1842025-01-23T18:54:24.834Z{"msg":"[1]R generation: [25, 25, 25, 25, 25]","v":0,"name":"crucible","level":30,"time":"2025-01-23T18:54:24.587114762Z","hostname":"w-01JJA7SE9SCYB3AF1MKA8WXYP0","pid":1230,"":"downstairs","":"downstairs","session_id":"9ccb1b55-1b2c-4cfe-932d-91c9d0ace6f5"}
1852025-01-23T18:54:24.839Z{"msg":"[1]R dirty: [false, false, false, false, false]","v":0,"name":"crucible","level":30,"time":"2025-01-23T18:54:24.587128152Z","hostname":"w-01JJA7SE9SCYB3AF1MKA8WXYP0","pid":1230,"":"downstairs","":"downstairs","session_id":"9ccb1b55-1b2c-4cfe-932d-91c9d0ace6f5"}
1862025-01-23T18:54:24.839Z{"msg":"[2]R flush_numbers: [4000, 4000, 4000, 4000, 4000]","v":0,"name":"crucible","level":30,"time":"2025-01-23T18:54:24.587148062Z","hostname":"w-01JJA7SE9SCYB3AF1MKA8WXYP0","pid":1230,"":"downstairs","":"downstairs","session_id":"9ccb1b55-1b2c-4cfe-932d-91c9d0ace6f5"}
1872025-01-23T18:54:24.840Z{"msg":"[2]R generation: [25, 25, 25, 25, 25]","v":0,"name":"crucible","level":30,"time":"2025-01-23T18:54:24.587161342Z","hostname":"w-01JJA7SE9SCYB3AF1MKA8WXYP0","pid":1230,"":"downstairs","":"downstairs","session_id":"9ccb1b55-1b2c-4cfe-932d-91c9d0ace6f5"}
1882025-01-23T18:54:24.840Z{"msg":"[2]R dirty: [false, false, false, false, false]","v":0,"name":"crucible","level":30,"time":"2025-01-23T18:54:24.587185522Z","hostname":"w-01JJA7SE9SCYB3AF1MKA8WXYP0","pid":1230,"":"downstairs","":"downstairs","session_id":"9ccb1b55-1b2c-4cfe-932d-91c9d0ace6f5"}
1892025-01-23T18:54:24.840Z{"msg":"Max found gen is 26","v":0,"name":"crucible","level":30,"time":"2025-01-23T18:54:24.587202702Z","hostname":"w-01JJA7SE9SCYB3AF1MKA8WXYP0","pid":1230,"":"downstairs","":"downstairs","session_id":"9ccb1b55-1b2c-4cfe-932d-91c9d0ace6f5"}
1902025-01-23T18:54:24.840Z{"msg":"Generation requested: 31 >= found:26","v":0,"name":"crucible","level":30,"time":"2025-01-23T18:54:24.587224502Z","hostname":"w-01JJA7SE9SCYB3AF1MKA8WXYP0","pid":1230,"":"downstairs","":"downstairs","session_id":"9ccb1b55-1b2c-4cfe-932d-91c9d0ace6f5"}
1912025-01-23T18:54:24.840Z{"msg":"Next flush: 4001","v":0,"name":"crucible","level":30,"time":"2025-01-23T18:54:24.587238172Z","hostname":"w-01JJA7SE9SCYB3AF1MKA8WXYP0","pid":1230,"":"downstairs","":"downstairs","session_id":"9ccb1b55-1b2c-4cfe-932d-91c9d0ace6f5"}
1922025-01-23T18:54:24.840Z{"msg":"All extents match","v":0,"name":"crucible","level":30,"time":"2025-01-23T18:54:24.587251632Z","hostname":"w-01JJA7SE9SCYB3AF1MKA8WXYP0","pid":1230,"":"downstairs","":"downstairs","session_id":"9ccb1b55-1b2c-4cfe-932d-91c9d0ace6f5"}
1932025-01-23T18:54:24.840Z{"msg":"No downstairs reconciliation required","v":0,"name":"crucible","level":30,"time":"2025-01-23T18:54:24.587266812Z","hostname":"w-01JJA7SE9SCYB3AF1MKA8WXYP0","pid":1230,"session_id":"9ccb1b55-1b2c-4cfe-932d-91c9d0ace6f5"}
1942025-01-23T18:54:24.840Z{"msg":"Transition from WaitQuorum to Active","v":0,"name":"crucible","level":30,"time":"2025-01-23T18:54:24.587288843Z","hostname":"w-01JJA7SE9SCYB3AF1MKA8WXYP0","pid":1230,"client":"0","":"downstairs","session_id":"9ccb1b55-1b2c-4cfe-932d-91c9d0ace6f5"}
1952025-01-23T18:54:24.840Z{"msg":"Transition from WaitQuorum to Active","v":0,"name":"crucible","level":30,"time":"2025-01-23T18:54:24.587324172Z","hostname":"w-01JJA7SE9SCYB3AF1MKA8WXYP0","pid":1230,"client":"1","":"downstairs","session_id":"9ccb1b55-1b2c-4cfe-932d-91c9d0ace6f5"}
1962025-01-23T18:54:24.840Z{"msg":"Transition from WaitQuorum to Active","v":0,"name":"crucible","level":30,"time":"2025-01-23T18:54:24.587339852Z","hostname":"w-01JJA7SE9SCYB3AF1MKA8WXYP0","pid":1230,"client":"2","":"downstairs","session_id":"9ccb1b55-1b2c-4cfe-932d-91c9d0ace6f5"}
1972025-01-23T18:54:24.840Z{"msg":"All required reconciliation work is completed","v":0,"name":"crucible","level":30,"time":"2025-01-23T18:54:24.587360343Z","hostname":"w-01JJA7SE9SCYB3AF1MKA8WXYP0","pid":1230,"session_id":"9ccb1b55-1b2c-4cfe-932d-91c9d0ace6f5"}
1982025-01-23T18:54:24.840Z{"msg":"Set Downstairs and Upstairs active after reconciliation","v":0,"name":"crucible","level":30,"time":"2025-01-23T18:54:24.587372883Z","hostname":"w-01JJA7SE9SCYB3AF1MKA8WXYP0","pid":1230,"session_id":"9ccb1b55-1b2c-4cfe-932d-91c9d0ace6f5"}
1992025-01-23T18:54:24.840Z{"msg":"c616f691-1688-47c3-a9db-04fa97d0e601 is now active with session: 9ccb1b55-1b2c-4cfe-932d-91c9d0ace6f5","v":0,"name":"crucible","level":30,"time":"2025-01-23T18:54:24.587385403Z","hostname":"w-01JJA7SE9SCYB3AF1MKA8WXYP0","pid":1230,"session_id":"9ccb1b55-1b2c-4cfe-932d-91c9d0ace6f5"}
2002025-01-23T18:54:24.840Z{"msg":"Set Active after no reconciliation","v":0,"name":"crucible","level":30,"time":"2025-01-23T18:54:24.587414893Z","hostname":"w-01JJA7SE9SCYB3AF1MKA8WXYP0","pid":1230,"session_id":"9ccb1b55-1b2c-4cfe-932d-91c9d0ace6f5"}
2012025-01-23T18:54:24.841Z{"msg":"The guest has finished waiting for activation with:31","v":0,"name":"crucible","level":30,"time":"2025-01-23T18:54:24.587437603Z","hostname":"w-01JJA7SE9SCYB3AF1MKA8WXYP0","pid":1230}
2022025-01-23T18:54:24.841Z{"msg":"The guest has requested activation with gen:31","v":0,"name":"crucible","level":30,"time":"2025-01-23T18:54:24.587455773Z","hostname":"w-01JJA7SE9SCYB3AF1MKA8WXYP0","pid":1230}
2032025-01-23T18:54:24.841Z{"msg":"c616f691-1688-47c3-a9db-04fa97d0e601 active request set","v":0,"name":"crucible","level":30,"time":"2025-01-23T18:54:24.587495003Z","hostname":"w-01JJA7SE9SCYB3AF1MKA8WXYP0","pid":1230,"session_id":"483f0b99-e7a6-4888-b357-3c470b30eda0"}
2042025-01-23T18:54:24.841Z{"msg":"sending connect oneshot to client","v":0,"name":"crucible","level":30,"time":"2025-01-23T18:54:24.587529313Z","hostname":"w-01JJA7SE9SCYB3AF1MKA8WXYP0","pid":1230,"client":"0","":"downstairs","session_id":"483f0b99-e7a6-4888-b357-3c470b30eda0"}
2052025-01-23T18:54:24.841Z{"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-23T18:54:24.587559083Z","hostname":"w-01JJA7SE9SCYB3AF1MKA8WXYP0","pid":1230,"client":"0","":"downstairs","session_id":"483f0b99-e7a6-4888-b357-3c470b30eda0"}
2062025-01-23T18:54:24.841Z{"msg":"sending connect oneshot to client","v":0,"name":"crucible","level":30,"time":"2025-01-23T18:54:24.587667383Z","hostname":"w-01JJA7SE9SCYB3AF1MKA8WXYP0","pid":1230,"client":"1","":"downstairs","session_id":"483f0b99-e7a6-4888-b357-3c470b30eda0"}
2072025-01-23T18:54:24.841Z{"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-23T18:54:24.587717783Z","hostname":"w-01JJA7SE9SCYB3AF1MKA8WXYP0","pid":1230,"client":"1","":"downstairs","session_id":"483f0b99-e7a6-4888-b357-3c470b30eda0"}
2082025-01-23T18:54:24.841Z{"msg":"sending connect oneshot to client","v":0,"name":"crucible","level":30,"time":"2025-01-23T18:54:24.587744943Z","hostname":"w-01JJA7SE9SCYB3AF1MKA8WXYP0","pid":1230,"client":"2","":"downstairs","session_id":"483f0b99-e7a6-4888-b357-3c470b30eda0"}
2092025-01-23T18:54:24.841Z{"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-23T18:54:24.587769173Z","hostname":"w-01JJA7SE9SCYB3AF1MKA8WXYP0","pid":1230,"client":"2","":"downstairs","session_id":"483f0b99-e7a6-4888-b357-3c470b30eda0"}
2102025-01-23T18:54:24.841Z{"msg":"connecting to 127.0.0.1:8860","v":0,"name":"crucible","level":30,"time":"2025-01-23T18:54:24.587784443Z","hostname":"w-01JJA7SE9SCYB3AF1MKA8WXYP0","pid":1230,"":"io task","client":"2","":"downstairs","session_id":"483f0b99-e7a6-4888-b357-3c470b30eda0"}
2112025-01-23T18:54:24.841Z{"msg":"connecting to 127.0.0.1:8840","v":0,"name":"crucible","level":30,"time":"2025-01-23T18:54:24.587798073Z","hostname":"w-01JJA7SE9SCYB3AF1MKA8WXYP0","pid":1230,"":"io task","client":"0","":"downstairs","session_id":"483f0b99-e7a6-4888-b357-3c470b30eda0"}
2122025-01-23T18:54:24.841Z{"msg":"connecting to 127.0.0.1:8850","v":0,"name":"crucible","level":30,"time":"2025-01-23T18:54:24.587819143Z","hostname":"w-01JJA7SE9SCYB3AF1MKA8WXYP0","pid":1230,"":"io task","client":"1","":"downstairs","session_id":"483f0b99-e7a6-4888-b357-3c470b30eda0"}
2132025-01-23T18:54:24.841Z{"msg":"ds_connection connected from Ok(127.0.0.1:59921)","v":0,"name":"crucible","level":30,"time":"2025-01-23T18:54:24.587845293Z","hostname":"w-01JJA7SE9SCYB3AF1MKA8WXYP0","pid":1230,"":"io task","client":"0","":"downstairs","session_id":"483f0b99-e7a6-4888-b357-3c470b30eda0"}
2142025-01-23T18:54:24.841Z{"msg":"ds_connection connected from Ok(127.0.0.1:61267)","v":0,"name":"crucible","level":30,"time":"2025-01-23T18:54:24.587870863Z","hostname":"w-01JJA7SE9SCYB3AF1MKA8WXYP0","pid":1230,"":"io task","client":"2","":"downstairs","session_id":"483f0b99-e7a6-4888-b357-3c470b30eda0"}
2152025-01-23T18:54:24.841Z{"msg":"ds_connection connected from Ok(127.0.0.1:35207)","v":0,"name":"crucible","level":30,"time":"2025-01-23T18:54:24.587896433Z","hostname":"w-01JJA7SE9SCYB3AF1MKA8WXYP0","pid":1230,"":"io task","client":"1","":"downstairs","session_id":"483f0b99-e7a6-4888-b357-3c470b30eda0"}
2162025-01-23T18:54:24.841Z{"msg":"version negotiation from state Connecting { state: WaitForPromote, mode: New }","v":0,"name":"crucible","level":30,"time":"2025-01-23T18:54:24.587998264Z","hostname":"w-01JJA7SE9SCYB3AF1MKA8WXYP0","pid":1230,"client":"0","":"downstairs","session_id":"483f0b99-e7a6-4888-b357-3c470b30eda0"}
2172025-01-23T18:54:24.841Z{"msg":"version negotiation from state Connecting { state: WaitForPromote, mode: New }","v":0,"name":"crucible","level":30,"time":"2025-01-23T18:54:24.588058694Z","hostname":"w-01JJA7SE9SCYB3AF1MKA8WXYP0","pid":1230,"client":"2","":"downstairs","session_id":"483f0b99-e7a6-4888-b357-3c470b30eda0"}
2182025-01-23T18:54:24.841Z{"msg":"version negotiation from state Connecting { state: WaitForPromote, mode: New }","v":0,"name":"crucible","level":30,"time":"2025-01-23T18:54:24.588096144Z","hostname":"w-01JJA7SE9SCYB3AF1MKA8WXYP0","pid":1230,"client":"1","":"downstairs","session_id":"483f0b99-e7a6-4888-b357-3c470b30eda0"}
2192025-01-23T18:54:24.841Z{"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-23T18:54:24.588517824Z","hostname":"w-01JJA7SE9SCYB3AF1MKA8WXYP0","pid":1230,"client":"1","":"downstairs","session_id":"483f0b99-e7a6-4888-b357-3c470b30eda0"}
2202025-01-23T18:54:24.841Z{"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-23T18:54:24.588571114Z","hostname":"w-01JJA7SE9SCYB3AF1MKA8WXYP0","pid":1230,"client":"0","":"downstairs","session_id":"483f0b99-e7a6-4888-b357-3c470b30eda0"}
2212025-01-23T18:54:24.841Z{"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-23T18:54:24.588660934Z","hostname":"w-01JJA7SE9SCYB3AF1MKA8WXYP0","pid":1230,"client":"2","":"downstairs","session_id":"483f0b99-e7a6-4888-b357-3c470b30eda0"}
2222025-01-23T18:54:24.841Z{"msg":"Waiting for more clients to be ready","v":0,"name":"crucible","level":30,"time":"2025-01-23T18:54:24.588833585Z","hostname":"w-01JJA7SE9SCYB3AF1MKA8WXYP0","pid":1230,"session_id":"483f0b99-e7a6-4888-b357-3c470b30eda0"}
2232025-01-23T18:54:24.841Z{"msg":"Waiting for more clients to be ready","v":0,"name":"crucible","level":30,"time":"2025-01-23T18:54:24.588881935Z","hostname":"w-01JJA7SE9SCYB3AF1MKA8WXYP0","pid":1230,"session_id":"483f0b99-e7a6-4888-b357-3c470b30eda0"}
2242025-01-23T18:54:24.841Z{"msg":"[0]R flush_numbers: [5319, 5317, 5320, 5320, 5314]","v":0,"name":"crucible","level":30,"time":"2025-01-23T18:54:24.588971855Z","hostname":"w-01JJA7SE9SCYB3AF1MKA8WXYP0","pid":1230,"":"downstairs","":"downstairs","session_id":"483f0b99-e7a6-4888-b357-3c470b30eda0"}
2252025-01-23T18:54:24.841Z{"msg":"[0]R generation: [14, 13, 14, 14, 12]","v":0,"name":"crucible","level":30,"time":"2025-01-23T18:54:24.589043045Z","hostname":"w-01JJA7SE9SCYB3AF1MKA8WXYP0","pid":1230,"":"downstairs","":"downstairs","session_id":"483f0b99-e7a6-4888-b357-3c470b30eda0"}
2262025-01-23T18:54:24.842Z{"msg":"[0]R dirty: [false, false, false, false, false]","v":0,"name":"crucible","level":30Wait for a query_work_queue command to finish before sending IO
2272025-01-23T18:54:24.842Z,"time":"2025-01-23T18:54:24.589089855Z","hostname":"w-01JJA7SE9SCYB3AF1MKA8WXYP0","pid":1230,"":"downstairs","":"downstairs","session_id":"483f0b99-e7a6-4888-b357-3c470b30eda0"}
2282025-01-23T18:54:24.842Z{"msg":"[1]R flush_numbers: [5319, 5317, 5320, 5320, 5314]","v":0,"name":"crucible","level":30,"time":"2025-01-23T18:54:24.589113315Z","hostname":"w-01JJA7SE9SCYB3AF1MKA8WXYP0","pid":1230,"":"downstairs","":"downstairs","session_id":"483f0b99-e7a6-4888-b357-3c470b30eda0"}
2292025-01-23T18:54:24.842Z{"msg":"[1]R generation: [14, 13, 14, 14, 12]","v":0,"name":"crucible","level":30,"time":"2025-01-23T18:54:24.589136015Z","hostname":"w-01JJA7SE9SCYB3AF1MKA8WXYP0","pid":1230,"":"downstairs","":"downstairs","session_id":"483f0b99-e7a6-4888-b357-3c470b30eda0"}
2302025-01-23T18:54:24.842Z{"msg":"[1]R dirty: [false, false, false, false, false]","v":0,"name":"crucible","level":30,"time":"2025-01-23T18:54:24.589154285Z","hostname":"w-01JJA7SE9SCYB3AF1MKA8WXYP0","pid":1230,"":"downstairs","":"downstairs","session_id":"483f0b99-e7a6-4888-b357-3c470b30eda0"}
2312025-01-23T18:54:24.842Z{"msg":"[2]R flush_numbers: [5319, 5317, 5320, 5320, 5314]","v":0,"name":"crucible","level":30,"time":"2025-01-23T18:54:24.589188825Z","hostname":"w-01JJA7SE9SCYB3AF1MKA8WXYP0","pid":1230,"":"downstairs","":"downstairs","session_id":"483f0b99-e7a6-4888-b357-3c470b30eda0"}
2322025-01-23T18:54:24.842Z{"msg":"[2]R generation: [14, 13, 14, 14, 12]","v":0,"name":"crucible","level":30,"time":"2025-01-23T18:54:24.589221535Z","hostname":"w-01JJA7SE9SCYB3AF1MKA8WXYP0","pid":1230,"":"downstairs","":"downstairs","session_id":"483f0b99-e7a6-4888-b357-3c470b30eda0"}
2332025-01-23T18:54:24.842Z{"msg":"[2]R dirty: [false, false, false, false, false]","v":0,"name":"crucible","level":30,"time":"2025-01-23T18:54:24.589257295Z","hostname":"w-01JJA7SE9SCYB3AF1MKA8WXYP0","pid":1230,"":"downstairs","":"downstairs","session_id":"483f0b99-e7a6-4888-b357-3c470b30eda0"}
2342025-01-23T18:54:24.842Z{"msg":"Max found gen is 15","v":0,"name":"crucible","level":30,"time":"2025-01-23T18:54:24.589292415Z","hostname":"w-01JJA7SE9SCYB3AF1MKA8WXYP0","pid":1230,"":"downstairs","":"downstairs","session_id":"483f0b99-e7a6-4888-b357-3c470b30eda0"}
2352025-01-23T18:54:24.842Z{"msg":"Generation requested: 31 >= found:15","v":0,"name":"crucible","level":30,"time":"2025-01-23T18:54:24.589324726Z","hostname":"w-01JJA7SE9SCYB3AF1MKA8WXYP0","pid":1230,"":"downstairs","":"downstairs","session_id":"483f0b99-e7a6-4888-b357-3c470b30eda0"}
2362025-01-23T18:54:24.842Z{"msg":"Next flush: 5321","v":0,"name":"crucible","level":30,"time":"2025-01-23T18:54:24.589358535Z","hostname":"w-01JJA7SE9SCYB3AF1MKA8WXYP0","pid":1230,"":"downstairs","":"downstairs","session_id":"483f0b99-e7a6-4888-b357-3c470b30eda0"}
2372025-01-23T18:54:24.842Z{"msg":"All extents match","v":0,"name":"crucible","level":30,"time":"2025-01-23T18:54:24.589389496Z"Disk: sv:2 bs:4096 ts:409600 tb:100 max_io:100 or 409600
2382025-01-23T18:54:24.842Z,"hostname":"w-01JJA7SE9SCYB3AF1MKA8WXYP0","pid":1230,"":"downstairs","":"downstairs","session_id":"483f0b99-e7a6-4888-b357-3c470b30eda0"}
2392025-01-23T18:54:24.842Z{"msg":"No downstairs reconciliation required","v":0,"name":"crucible","level":30,"time":"2025-01-23T18:54:24.589423456Z","hostname":"w-01JJA7SE9SCYB3AF1MKA8WXYP0","pid":1230,"session_id":"483f0b99-e7a6-4888-b357-3c470b30eda0"}
2402025-01-23T18:54:24.842ZFill test
2412025-01-23T18:54:24.842Z{"msg":"Transition from WaitQuorum to Active","v":0,"name":"crucible","level":30,"time":"2025-01-23T18:54:24.589447906Z","hostname":"w-01JJA7SE9SCYB3AF1MKA8WXYP0","pid":1230,"client":"0","":"downstairs","session_id":"483f0b99-e7a6-4888-b357-3c470b30eda0"}
2422025-01-23T18:54:24.842Z{"msg":"Transition from WaitQuorum to Active","v":0,"name":"crucible","level":30,"time":"2025-01-23T18:54:24.589463006Z","hostname":"w-01JJA7SE9SCYB3AF1MKA8WXYP0","pid":1230,"client":"1","":"downstairs","session_id":"483f0b99-e7a6-4888-b357-3c470b30eda0"}
2432025-01-23T18:54:24.842Z{"msg":"Transition from WaitQuorum to Active","v":0,"name":"crucible","level":30,"time":"2025-01-23T18:54:24.589484426Z","hostname":"w-01JJA7SE9SCYB3AF1MKA8WXYP0","pid":1230,"client":"2","":"downstairs","session_id":"483f0b99-e7a6-4888-b357-3c470b30eda0"}
2442025-01-23T18:54:24.842Z{"msg":"All required reconciliation work is completed","v":0,"name":"crucible","level":30,"time":"2025-01-23T18:54:24.589497786Z","hostname":"w-01JJA7SE9SCYB3AF1MKA8WXYP0","pid":1230,"session_id":"483f0b99-e7a6-4888-b357-3c470b30eda0"}
2452025-01-23T18:54:24.842Z{"msg":"Set Downstairs and Upstairs active after reconciliation","v":0,"name":"crucible","level":30,"time":"2025-01-23T18:54:24.589517806Z","hostname":"w-01JJA7SE9SCYB3AF1MKA8WXYP0","pid":1230,"session_id":"483f0b99-e7a6-4888-b357-3c470b30eda0"}
2462025-01-23T18:54:24.842Z{"msg":"c616f691-1688-47c3-a9db-04fa97d0e601 is now active with session: 483f0b99-e7a6-4888-b357-3c470b30eda0","v":0,"name":"crucible","level":30,"time":"2025-01-23T18:54:24.589530846Z","hostname":"w-01JJA7SE9SCYB3AF1MKA8WXYP0","pid":1230,"session_id":"483f0b99-e7a6-4888-b357-3c470b30eda0"}
2472025-01-23T18:54:24.842Z{"msg":"Set Active after no reconciliation","v":0,"name":"crucible","level":30,"time":"2025-01-23T18:54:24.589550256Z","hostname":"w-01JJA7SE9SCYB3AF1MKA8WXYP0","pid":1230,"session_id":"483f0b99-e7a6-4888-b357-3c470b30eda0"}
2482025-01-23T18:54:24.842Z{"msg":"The guest has finished waiting for activation with:31","v":0,"name":"crucible","level":30,"time":"2025-01-23T18:54:24.589563206Z","hostname":"w-01JJA7SE9SCYB3AF1MKA8WXYP0","pid":1230}
2492025-01-23T18:54:24.878ZRead and Verify all blocks (0..100 range:false)
2502025-01-23T18:54:24.957ZWrote out file "/var/tmp/test_up-build/verify_file"
2512025-01-23T18:54:24.957ZCLIENT: Tests done. All submitted work has been ACK'd
2522025-01-23T18:54:24.960Z----------------------------------------------------------------
2532025-01-23T18:54:24.960Z Crucible gen:31 GIO:true work queues: Upstairs:0 downstairs:1
2542025-01-23T18:54:24.960ZStates: Active Active Active
2552025-01-23T18:54:24.960ZJOBID ACK TYPE BKS/EXT DS:0 DS:1 DS:2 REPLAY
2562025-01-23T18:54:24.960Z 1002 Acked Read 50 Done Done Done false
2572025-01-23T18:54:24.960Z STATES DS:0 DS:1 DS:2 TOTAL
2582025-01-23T18:54:24.960Z Sent 0 0 0 0
2592025-01-23T18:54:24.960Z Done 1 1 1 3
2602025-01-23T18:54:24.960Z Skipped 0 0 0 0
2612025-01-23T18:54:24.960Z Error 0 0 0 0
2622025-01-23T18:54:24.960ZLast Flush: Some(JobId(1001)) Some(JobId(1001)) Some(JobId(1001))
2632025-01-23T18:54:24.960ZDownstairs last five completed: 1001 1000
2642025-01-23T18:54:24.960ZUpstairs last five completed: 1002 1001 1000
2652025-01-23T18:54:24.960Z----------------------------------------------------------------
2662025-01-23T18:54:24.960Z Crucible gen:31 GIO:true work queues: Upstairs:0 downstairs:1
2672025-01-23T18:54:24.960ZStates: Active Active Active
2682025-01-23T18:54:24.960ZJOBID ACK TYPE BKS/EXT DS:0 DS:1 DS:2 REPLAY
2692025-01-23T18:54:24.960Z 1002 Acked Read 50 Done Done Done false
2702025-01-23T18:54:24.960Z STATES DS:0 DS:1 DS:2 TOTAL
2712025-01-23T18:54:24.960Z Sent 0 0 0 0
2722025-01-23T18:54:24.960Z Done 1 1 1 3
2732025-01-23T18:54:24.960Z Skipped 0 0 0 0
2742025-01-23T18:54:24.960Z Error 0 0 0 0
2752025-01-23T18:54:24.960ZLast Flush: Some(JobId(1001)) Some(JobId(1001)) Some(JobId(1001))
2762025-01-23T18:54:24.960ZDownstairs last five completed: 1001 1000
2772025-01-23T18:54:24.960ZUpstairs last five completed: 1002 1001 1000
2782025-01-23T18:54:24.960ZCLIENT: Up:0 ds:2 act:6
2792025-01-23T18:54:28.958Z----------------------------------------------------------------
2802025-01-23T18:54:28.958Z Crucible gen:31 GIO:true work queues: Upstairs:0 downstairs:0
2812025-01-23T18:54:28.958ZDownstairs last five completed: 1003 1002 1001 1000
2822025-01-23T18:54:28.958ZUpstairs last five completed: 1003 1002 1001 1000
2832025-01-23T18:54:28.959Z----------------------------------------------------------------
2842025-01-23T18:54:28.959Z Crucible gen:31 GIO:true work queues: Upstairs:0 downstairs:0
2852025-01-23T18:54:28.959ZDownstairs last five completed: 1003 1002 1001 1000
2862025-01-23T18:54:28.959ZUpstairs last five completed: 1003 1002 1001 1000
2872025-01-23T18:54:28.959ZCLIENT: Up:0 ds:0 act:6
2882025-01-23T18:54:28.959ZCLIENT: All crucible jobs finished, exiting program
2892025-01-23T18:54:28.961Z{"msg":"Guest handle has been dropped","v":0,"name":"crucible","level":40,"time":"2025-01-23T18:54:28.713119439Z","hostname":"w-01JJA7SE9SCYB3AF1MKA8WXYP0","pid":1230}
2902025-01-23T18:54:28.969ZRepair setup passed
2912025-01-23T18:54:28.973ZCopy the region for /var/tmp/test_up-build/8830
2922025-01-23T18:54:28.976Zcp -r /var/tmp/test_up-build/8830 /var/tmp/test_up-build/previous
2932025-01-23T18:54:28.979Z/var/tmp/bins/crutest fill -g 32 -q --key 9xPvF7de3WZ1vCpioKQCACyo8vJ/rwySjcN3nDeHU00= --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-23T18:54:29.035Z{"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-23T18:54:28.789672221Z","hostname":"w-01JJA7SE9SCYB3AF1MKA8WXYP0","pid":1236,"task":"crutest"}
2952025-01-23T18:54:29.038Z{"msg":"dsc has 6 regions. This means 2 sub_volumes","v":0,"name":"crucible","level":30,"time":"2025-01-23T18:54:28.790272562Z","hostname":"w-01JJA7SE9SCYB3AF1MKA8WXYP0","pid":1236,"task":"crutest"}
2962025-01-23T18:54:29.038Z{"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-23T18:54:28.791895344Z","hostname":"w-01JJA7SE9SCYB3AF1MKA8WXYP0","pid":1236,"task":"crutest"}
2972025-01-23T18:54:29.038Z{"msg":"Upstairs starts","v":0,"name":"crucible","level":30,"time":"2025-01-23T18:54:28.792099845Z","hostname":"w-01JJA7SE9SCYB3AF1MKA8WXYP0","pid":1236}
2982025-01-23T18:54:29.038Z{"msg":"Crucible Version: BuildInfo {\n version: \"0.0.1\",\n git_sha: \"dd1cf1330bf5c5b1551a0ad961a7aa7c6207feae\",\n git_commit_timestamp: \"2025-01-23T18:31:41.000000000Z\",\n git_branch: \"mkeeter/early-io-rejection\",\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-23T18:54:28.792144385Z","hostname":"w-01JJA7SE9SCYB3AF1MKA8WXYP0","pid":1236}
2992025-01-23T18:54:29.038Z{"msg":"Upstairs <-> Downstairs Message Version: 13","v":0,"name":"crucible","level":30,"time":"2025-01-23T18:54:28.792168125Z","hostname":"w-01JJA7SE9SCYB3AF1MKA8WXYP0","pid":1236}
3002025-01-23T18:54:29.038Z{"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-23T18:54:28.792184345Z","hostname":"w-01JJA7SE9SCYB3AF1MKA8WXYP0","pid":1236}
3012025-01-23T18:54:29.041Z{"msg":"Crucible 17eeca5e-f1c3-46a0-bcb2-be03bd636092 has session id: 0ffcf43c-6fbd-455e-b473-6df314085a28","v":0,"name":"crucible","level":30,"time":"2025-01-23T18:54:28.792859376Z","hostname":"w-01JJA7SE9SCYB3AF1MKA8WXYP0","pid":1236,"session_id":"0ffcf43c-6fbd-455e-b473-6df314085a28"}
3022025-01-23T18:54:29.041Z{"msg":"Upstairs opts: Upstairs UUID: 17eeca5e-f1c3-46a0-bcb2-be03bd636092, 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-23T18:54:28.792938396Z","hostname":"w-01JJA7SE9SCYB3AF1MKA8WXYP0","pid":1236,"session_id":"0ffcf43c-6fbd-455e-b473-6df314085a28"}
3032025-01-23T18:54:29.041Z{"msg":"Crucible stats registered with UUID: 17eeca5e-f1c3-46a0-bcb2-be03bd636092","v":0,"name":"crucible","level":30,"time":"2025-01-23T18:54:28.792976676Z","hostname":"w-01JJA7SE9SCYB3AF1MKA8WXYP0","pid":1236,"session_id":"0ffcf43c-6fbd-455e-b473-6df314085a28"}
3042025-01-23T18:54:29.041Z{"msg":"could not find Downstairs address for Nexus","v":0,"name":"crucible","level":40,"time":"2025-01-23T18:54:28.792991086Z","hostname":"w-01JJA7SE9SCYB3AF1MKA8WXYP0","pid":1236,"session_id":"0ffcf43c-6fbd-455e-b473-6df314085a28"}
3052025-01-23T18:54:29.041Z{"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-23T18:54:28.794888629Z","hostname":"w-01JJA7SE9SCYB3AF1MKA8WXYP0","pid":1236,"task":"crutest"}
3062025-01-23T18:54:29.041Z{"msg":"Upstairs starts","v":0,"name":"crucible","level":30,"time":"2025-01-23T18:54:28.794990699Z","hostname":"w-01JJA7SE9SCYB3AF1MKA8WXYP0","pid":1236}
3072025-01-23T18:54:29.041Z{"msg":"Crucible Version: BuildInfo {\n version: \"0.0.1\",\n git_sha: \"dd1cf1330bf5c5b1551a0ad961a7aa7c6207feae\",\n git_commit_timestamp: \"2025-01-23T18:31:41.000000000Z\",\n git_branch: \"mkeeter/early-io-rejection\",\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-23T18:54:28.795034149Z","hostname":"w-01JJA7SE9SCYB3AF1MKA8WXYP0","pid":1236}
3082025-01-23T18:54:29.041Z{"msg":"Upstairs <-> Downstairs Message Version: 13","v":0,"name":"crucible","level":30,"time":"2025-01-23T18:54:28.795058109Z","hostname":"w-01JJA7SE9SCYB3AF1MKA8WXYP0","pid":1236}
3092025-01-23T18:54:29.041Z{"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-23T18:54:28.795075679Z","hostname":"w-01JJA7SE9SCYB3AF1MKA8WXYP0","pid":1236}
3102025-01-23T18:54:29.041Z{"msg":"Crucible 17eeca5e-f1c3-46a0-bcb2-be03bd636092 has session id: 2895d124-7b8f-41c4-aac8-882111792420","v":0,"name":"crucible","level":30,"time":"2025-01-23T18:54:28.79547475Z","hostname":"w-01JJA7SE9SCYB3AF1MKA8WXYP0","pid":1236,"session_id":"2895d124-7b8f-41c4-aac8-882111792420"}
3112025-01-23T18:54:29.041Z{"msg":"Upstairs opts: Upstairs UUID: 17eeca5e-f1c3-46a0-bcb2-be03bd636092, 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-23T18:54:28.7955336Z","hostname":"w-01JJA7SE9SCYB3AF1MKA8WXYP0","pid":1236,"session_id":"2895d124-7b8f-41c4-aac8-882111792420"}
3122025-01-23T18:54:29.041Z{"msg":"Crucible stats registered with UUID: 17eeca5e-f1c3-46a0-bcb2-be03bd636092","v":0,"name":"crucible","level":30,"time":"2025-01-23T18:54:28.7955713Z","hostname":"w-01JJA7SE9SCYB3AF1MKA8WXYP0","pid":1236,"session_id":"2895d124-7b8f-41c4-aac8-882111792420"}
3132025-01-23T18:54:29.041Z{"msg":"could not find Downstairs address for Nexus","v":0,"name":"crucible","level":40,"time":"2025-01-23T18:54:28.79561729Z","hostname":"w-01JJA7SE9SCYB3AF1MKA8WXYP0","pid":1236,"session_id":"2895d124-7b8f-41c4-aac8-882111792420"}
3142025-01-23T18:54:29.044Z{"msg":"Downstairs in volume = 6","v":0,"name":"crucible","level":30,"time":"2025-01-23T18:54:28.796227131Z","hostname":"w-01JJA7SE9SCYB3AF1MKA8WXYP0","pid":1236,"task":"crutest"}
3152025-01-23T18:54:29.044Z{"msg":"The guest has requested activation with gen:32","v":0,"name":"crucible","level":30,"time":"2025-01-23T18:54:28.796270361Z","hostname":"w-01JJA7SE9SCYB3AF1MKA8WXYP0","pid":1236}
3162025-01-23T18:54:29.044Z{"msg":"17eeca5e-f1c3-46a0-bcb2-be03bd636092 active request set","v":0,"name":"crucible","level":30,"time":"2025-01-23T18:54:28.796329101Z","hostname":"w-01JJA7SE9SCYB3AF1MKA8WXYP0","pid":1236,"session_id":"0ffcf43c-6fbd-455e-b473-6df314085a28"}
3172025-01-23T18:54:29.044Z{"msg":"sending connect oneshot to client","v":0,"name":"crucible","level":30,"time":"2025-01-23T18:54:28.796370471Z","hostname":"w-01JJA7SE9SCYB3AF1MKA8WXYP0","pid":1236,"client":"0","":"downstairs","session_id":"0ffcf43c-6fbd-455e-b473-6df314085a28"}
3182025-01-23T18:54:29.044Z{"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-23T18:54:28.796393811Z","hostname":"w-01JJA7SE9SCYB3AF1MKA8WXYP0","pid":1236,"client":"0","":"downstairs","session_id":"0ffcf43c-6fbd-455e-b473-6df314085a28"}
3192025-01-23T18:54:29.044Z{"msg":"sending connect oneshot to client","v":0,"name":"crucible","level":30,"time":"2025-01-23T18:54:28.796408341Z","hostname":"w-01JJA7SE9SCYB3AF1MKA8WXYP0","pid":1236,"client":"1","":"downstairs","session_id":"0ffcf43c-6fbd-455e-b473-6df314085a28"}
3202025-01-23T18:54:29.044Z{"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-23T18:54:28.796433051Z","hostname":"w-01JJA7SE9SCYB3AF1MKA8WXYP0","pid":1236,"client":"1","":"downstairs","session_id":"0ffcf43c-6fbd-455e-b473-6df314085a28"}
3212025-01-23T18:54:29.044Z{"msg":"sending connect oneshot to client","v":0,"name":"crucible","level":30,"time":"2025-01-23T18:54:28.796468311Z","hostname":"w-01JJA7SE9SCYB3AF1MKA8WXYP0","pid":1236,"client":"2","":"downstairs","session_id":"0ffcf43c-6fbd-455e-b473-6df314085a28"}
3222025-01-23T18:54:29.044Z{"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-23T18:54:28.796501321Z","hostname":"w-01JJA7SE9SCYB3AF1MKA8WXYP0","pid":1236,"client":"2","":"downstairs","session_id":"0ffcf43c-6fbd-455e-b473-6df314085a28"}
3232025-01-23T18:54:29.044Z{"msg":"connecting to 127.0.0.1:8830","v":0,"name":"crucible","level":30,"time":"2025-01-23T18:54:28.796553991Z","hostname":"w-01JJA7SE9SCYB3AF1MKA8WXYP0","pid":1236,"":"io task","client":"2","":"downstairs","session_id":"0ffcf43c-6fbd-455e-b473-6df314085a28"}
3242025-01-23T18:54:29.044Z{"msg":"connecting to 127.0.0.1:8810","v":0,"name":"crucible","level":30,"time":"2025-01-23T18:54:28.796601531Z","hostname":"w-01JJA7SE9SCYB3AF1MKA8WXYP0","pid":1236,"":"io task","client":"0","":"downstairs","session_id":"0ffcf43c-6fbd-455e-b473-6df314085a28"}
3252025-01-23T18:54:29.044Z{"msg":"connecting to 127.0.0.1:8820","v":0,"name":"crucible","level":30,"time":"2025-01-23T18:54:28.796628031Z","hostname":"w-01JJA7SE9SCYB3AF1MKA8WXYP0","pid":1236,"":"io task","client":"1","":"downstairs","session_id":"0ffcf43c-6fbd-455e-b473-6df314085a28"}
3262025-01-23T18:54:29.044Z{"msg":"ds_connection connected from Ok(127.0.0.1:33252)","v":0,"name":"crucible","level":30,"time":"2025-01-23T18:54:28.796649931Z","hostname":"w-01JJA7SE9SCYB3AF1MKA8WXYP0","pid":1236,"":"io task","client":"2","":"downstairs","session_id":"0ffcf43c-6fbd-455e-b473-6df314085a28"}
3272025-01-23T18:54:29.044Z{"msg":"ds_connection connected from Ok(127.0.0.1:61421)","v":0,"name":"crucible","level":30,"time":"2025-01-23T18:54:28.796680871Z","hostname":"w-01JJA7SE9SCYB3AF1MKA8WXYP0","pid":1236,"":"io task","client":"0","":"downstairs","session_id":"0ffcf43c-6fbd-455e-b473-6df314085a28"}
3282025-01-23T18:54:29.044Z{"msg":"ds_connection connected from Ok(127.0.0.1:49668)","v":0,"name":"crucible","level":30,"time":"2025-01-23T18:54:28.796807981Z","hostname":"w-01JJA7SE9SCYB3AF1MKA8WXYP0","pid":1236,"":"io task","client":"1","":"downstairs","session_id":"0ffcf43c-6fbd-455e-b473-6df314085a28"}
3292025-01-23T18:54:29.045Z{"msg":"version negotiation from state Connecting { state: WaitForPromote, mode: New }","v":0,"name":"crucible","level":30,"time":"2025-01-23T18:54:28.797355612Z","hostname":"w-01JJA7SE9SCYB3AF1MKA8WXYP0","pid":1236,"client":"2","":"downstairs","session_id":"0ffcf43c-6fbd-455e-b473-6df314085a28"}
3302025-01-23T18:54:29.045Z{"msg":"version negotiation from state Connecting { state: WaitForPromote, mode: New }","v":0,"name":"crucible","level":30,"time":"2025-01-23T18:54:28.797398293Z","hostname":"w-01JJA7SE9SCYB3AF1MKA8WXYP0","pid":1236,"client":"1","":"downstairs","session_id":"0ffcf43c-6fbd-455e-b473-6df314085a28"}
3312025-01-23T18:54:29.045Z{"msg":"version negotiation from state Connecting { state: WaitForPromote, mode: New }","v":0,"name":"crucible","level":30,"time":"2025-01-23T18:54:28.797416702Z","hostname":"w-01JJA7SE9SCYB3AF1MKA8WXYP0","pid":1236,"client":"0","":"downstairs","session_id":"0ffcf43c-6fbd-455e-b473-6df314085a28"}
3322025-01-23T18:54:29.045Z{"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-23T18:54:28.798060854Z","hostname":"w-01JJA7SE9SCYB3AF1MKA8WXYP0","pid":1236,"client":"0","":"downstairs","session_id":"0ffcf43c-6fbd-455e-b473-6df314085a28"}
3332025-01-23T18:54:29.045Z{"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-23T18:54:28.798103134Z","hostname":"w-01JJA7SE9SCYB3AF1MKA8WXYP0","pid":1236,"client":"1","":"downstairs","session_id":"0ffcf43c-6fbd-455e-b473-6df314085a28"}
3342025-01-23T18:54:29.045Z{"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-23T18:54:28.798130703Z","hostname":"w-01JJA7SE9SCYB3AF1MKA8WXYP0","pid":1236,"client":"2","":"downstairs","session_id":"0ffcf43c-6fbd-455e-b473-6df314085a28"}
3352025-01-23T18:54:29.045Z{"msg":"Waiting for more clients to be ready","v":0,"name":"crucible","level":30,"time":"2025-01-23T18:54:28.798460284Z","hostname":"w-01JJA7SE9SCYB3AF1MKA8WXYP0","pid":1236,"session_id":"0ffcf43c-6fbd-455e-b473-6df314085a28"}
3362025-01-23T18:54:29.045Z{"msg":"Waiting for more clients to be ready","v":0,"name":"crucible","level":30,"time":"2025-01-23T18:54:28.798568944Z","hostname":"w-01JJA7SE9SCYB3AF1MKA8WXYP0","pid":1236,"session_id":"0ffcf43c-6fbd-455e-b473-6df314085a28"}
3372025-01-23T18:54:29.045Z{"msg":"[0]R flush_numbers: [4001, 4001, 4001, 4001, 4001]","v":0,"name":"crucible","level":30,"time":"2025-01-23T18:54:28.798603864Z","hostname":"w-01JJA7SE9SCYB3AF1MKA8WXYP0","pid":1236,"":"downstairs","":"downstairs","session_id":"0ffcf43c-6fbd-455e-b473-6df314085a28"}
3382025-01-23T18:54:29.045Z{"msg":"[0]R generation: [31, 31, 31, 31, 31]","v":0,"name":"crucible","level":30,"time":"2025-01-23T18:54:28.798619644Z","hostname":"w-01JJA7SE9SCYB3AF1MKA8WXYP0","pid":1236,"":"downstairs","":"downstairs","session_id":"0ffcf43c-6fbd-455e-b473-6df314085a28"}
3392025-01-23T18:54:29.045Z{"msg":"[0]R dirty: [false, false, false, false, false]","v":0,"name":"crucible","level":30,"time":"2025-01-23T18:54:28.798640674Z","hostname":"w-01JJA7SE9SCYB3AF1MKA8WXYP0","pid":1236,"":"downstairs","":"downstairs","session_id":"0ffcf43c-6fbd-455e-b473-6df314085a28"}
3402025-01-23T18:54:29.045Z{"msg":"[1]R flush_numbers: [4001, 4001, 4001, 4001, 4001]","v":0,"name":"crucible","level":30,"time":"2025-01-23T18:54:28.798654784Z","hostname":"w-01JJA7SE9SCYB3AF1MKA8WXYP0","pid":1236,"":"downstairs","":"downstairs","session_id":"0ffcf43c-6fbd-455e-b473-6df314085a28"}
3412025-01-23T18:54:29.045Z{"msg":"[1]R generation: [31, 31, 31, 31, 31]","v":0,"name":"crucible","level":30,"time":"2025-01-23T18:54:28.798676614Z","hostname":"w-01JJA7SE9SCYB3AF1MKA8WXYP0","pid":1236,"":"downstairs","":"downstairs","session_id":"0ffcf43c-6fbd-455e-b473-6df314085a28"}
3422025-01-23T18:54:29.045Z{"msg":"[1]R dirty: [false, false, false, false, false]","v":0,"name":"crucible","level":30,"time":"2025-01-23T18:54:28.798699734Z","hostname":"w-01JJA7SE9SCYB3AF1MKA8WXYP0","pid":1236,"":"downstairs","":"downstairs","session_id":"0ffcf43c-6fbd-455e-b473-6df314085a28"}
3432025-01-23T18:54:29.048Z{"msg":"[2]R flush_numbers: [4001, 4001, 4001, 4001, 4001]","v":0,"name":"crucible","level":30,"time":"2025-01-23T18:54:28.798734424Z","hostname":"w-01JJA7SE9SCYB3AF1MKA8WXYP0","pid":1236,"":"downstairs","":"downstairs","session_id":"0ffcf43c-6fbd-455e-b473-6df314085a28"}
3442025-01-23T18:54:29.048Z{"msg":"[2]R generation: [31, 31, 31, 31, 31]","v":0,"name":"crucible","level":30,"time":"2025-01-23T18:54:28.798771204Z","hostname":"w-01JJA7SE9SCYB3AF1MKA8WXYP0","pid":1236,"":"downstairs","":"downstairs","session_id":"0ffcf43c-6fbd-455e-b473-6df314085a28"}
3452025-01-23T18:54:29.049Z{"msg":"[2]R dirty: [false, false, false, false, false]","v":0,"name":"crucible","level":30,"time":"2025-01-23T18:54:28.798808455Z","hostname":"w-01JJA7SE9SCYB3AF1MKA8WXYP0","pid":1236,"":"downstairs","":"downstairs","session_id":"0ffcf43c-6fbd-455e-b473-6df314085a28"}
3462025-01-23T18:54:29.049Z{"msg":"Max found gen is 32","v":0,"name":"crucible","level":30,"time":"2025-01-23T18:54:28.798842505Z","hostname":"w-01JJA7SE9SCYB3AF1MKA8WXYP0","pid":1236,"":"downstairs","":"downstairs","session_id":"0ffcf43c-6fbd-455e-b473-6df314085a28"}
3472025-01-23T18:54:29.049Z{"msg":"Generation requested: 32 >= found:32","v":0,"name":"crucible","level":30,"time":"2025-01-23T18:54:28.798859215Z","hostname":"w-01JJA7SE9SCYB3AF1MKA8WXYP0","pid":1236,"":"downstairs","":"downstairs","session_id":"0ffcf43c-6fbd-455e-b473-6df314085a28"}
3482025-01-23T18:54:29.049Z{"msg":"Next flush: 4002","v":0,"name":"crucible","level":30,"time":"2025-01-23T18:54:28.798880255Z","hostname":"w-01JJA7SE9SCYB3AF1MKA8WXYP0","pid":1236,"":"downstairs","":"downstairs","session_id":"0ffcf43c-6fbd-455e-b473-6df314085a28"}
3492025-01-23T18:54:29.049Z{"msg":"All extents match","v":0,"name":"crucible","level":30,"time":"2025-01-23T18:54:28.798893395Z","hostname":"w-01JJA7SE9SCYB3AF1MKA8WXYP0","pid":1236,"":"downstairs","":"downstairs","session_id":"0ffcf43c-6fbd-455e-b473-6df314085a28"}
3502025-01-23T18:54:29.049Z{"msg":"No downstairs reconciliation required","v":0,"name":"crucible","level":30,"time":"2025-01-23T18:54:28.798918325Z","hostname":"w-01JJA7SE9SCYB3AF1MKA8WXYP0","pid":1236,"session_id":"0ffcf43c-6fbd-455e-b473-6df314085a28"}
3512025-01-23T18:54:29.049Z{"msg":"Transition from WaitQuorum to Active","v":0,"name":"crucible","level":30,"time":"2025-01-23T18:54:28.798952415Z","hostname":"w-01JJA7SE9SCYB3AF1MKA8WXYP0","pid":1236,"client":"0","":"downstairs","session_id":"0ffcf43c-6fbd-455e-b473-6df314085a28"}
3522025-01-23T18:54:29.049Z{"msg":"Transition from WaitQuorum to Active","v":0,"name":"crucible","level":30,"time":"2025-01-23T18:54:28.798990735Z","hostname":"w-01JJA7SE9SCYB3AF1MKA8WXYP0","pid":1236,"client":"1","":"downstairs","session_id":"0ffcf43c-6fbd-455e-b473-6df314085a28"}
3532025-01-23T18:54:29.049Z{"msg":"Transition from WaitQuorum to Active","v":0,"name":"crucible","level":30,"time":"2025-01-23T18:54:28.799012555Z","hostname":"w-01JJA7SE9SCYB3AF1MKA8WXYP0","pid":1236,"client":"2","":"downstairs","session_id":"0ffcf43c-6fbd-455e-b473-6df314085a28"}
3542025-01-23T18:54:29.049Z{"msg":"All required reconciliation work is completed","v":0,"name":"crucible","level":30,"time":"2025-01-23T18:54:28.799038305Z","hostname":"w-01JJA7SE9SCYB3AF1MKA8WXYP0","pid":1236,"session_id":"0ffcf43c-6fbd-455e-b473-6df314085a28"}
3552025-01-23T18:54:29.049Z{"msg":"Set Downstairs and Upstairs active after reconciliation","v":0,"name":"crucible","level":30,"time":"2025-01-23T18:54:28.799057495Z","hostname":"w-01JJA7SE9SCYB3AF1MKA8WXYP0","pid":1236,"session_id":"0ffcf43c-6fbd-455e-b473-6df314085a28"}
3562025-01-23T18:54:29.049Z{"msg":"17eeca5e-f1c3-46a0-bcb2-be03bd636092 is now active with session: 0ffcf43c-6fbd-455e-b473-6df314085a28","v":0,"name":"crucible","level":30,"time":"2025-01-23T18:54:28.799078555Z","hostname":"w-01JJA7SE9SCYB3AF1MKA8WXYP0","pid":1236,"session_id":"0ffcf43c-6fbd-455e-b473-6df314085a28"}
3572025-01-23T18:54:29.049Z{"msg":"Set Active after no reconciliation","v":0,"name":"crucible","level":30,"time":"2025-01-23T18:54:28.799110835Z","hostname":"w-01JJA7SE9SCYB3AF1MKA8WXYP0","pid":1236,"session_id":"0ffcf43c-6fbd-455e-b473-6df314085a28"}
3582025-01-23T18:54:29.049Z{"msg":"The guest has finished waiting for activation with:32","v":0,"name":"crucible","level":30,"time":"2025-01-23T18:54:28.799133185Z","hostname":"w-01JJA7SE9SCYB3AF1MKA8WXYP0","pid":1236}
3592025-01-23T18:54:29.049Z{"msg":"The guest has requested activation with gen:32","v":0,"name":"crucible","level":30,"time":"2025-01-23T18:54:28.799302785Z","hostname":"w-01JJA7SE9SCYB3AF1MKA8WXYP0","pid":1236}
3602025-01-23T18:54:29.049Z{"msg":"17eeca5e-f1c3-46a0-bcb2-be03bd636092 active request set","v":0,"name":"crucible","level":30,"time":"2025-01-23T18:54:28.799342505Z","hostname":"w-01JJA7SE9SCYB3AF1MKA8WXYP0","pid":1236,"session_id":"2895d124-7b8f-41c4-aac8-882111792420"}
3612025-01-23T18:54:29.049Z{"msg":"sending connect oneshot to client","v":0,"name":"crucible","level":30,"time":"2025-01-23T18:54:28.799361795Z","hostname":"w-01JJA7SE9SCYB3AF1MKA8WXYP0","pid":1236,"client":"0","":"downstairs","session_id":"2895d124-7b8f-41c4-aac8-882111792420"}
3622025-01-23T18:54:29.049Z{"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-23T18:54:28.799391665Z","hostname":"w-01JJA7SE9SCYB3AF1MKA8WXYP0","pid":1236,"client":"0","":"downstairs","session_id":"2895d124-7b8f-41c4-aac8-882111792420"}
3632025-01-23T18:54:29.049Z{"msg":"sending connect oneshot to client","v":0,"name":"crucible","level":30,"time":"2025-01-23T18:54:28.799427005Z","hostname":"w-01JJA7SE9SCYB3AF1MKA8WXYP0","pid":1236,"client":"1","":"downstairs","session_id":"2895d124-7b8f-41c4-aac8-882111792420"}
3642025-01-23T18:54:29.049Z{"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-23T18:54:28.799458016Z","hostname":"w-01JJA7SE9SCYB3AF1MKA8WXYP0","pid":1236,"client":"1","":"downstairs","session_id":"2895d124-7b8f-41c4-aac8-882111792420"}
3652025-01-23T18:54:29.049Z{"msg":"sending connect oneshot to client","v":0,"name":"crucible","level":30,"time":"2025-01-23T18:54:28.799487045Z","hostname":"w-01JJA7SE9SCYB3AF1MKA8WXYP0","pid":1236,"client":"2","":"downstairs","session_id":"2895d124-7b8f-41c4-aac8-882111792420"}
3662025-01-23T18:54:29.049Z{"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-23T18:54:28.799520806Z","hostname":"w-01JJA7SE9SCYB3AF1MKA8WXYP0","pid":1236,"client":"2","":"downstairs","session_id":"2895d124-7b8f-41c4-aac8-882111792420"}
3672025-01-23T18:54:29.049Z{"msg":"connecting to 127.0.0.1:8860","v":0,"name":"crucible","level":30,"time":"2025-01-23T18:54:28.799536196Z","hostname":"w-01JJA7SE9SCYB3AF1MKA8WXYP0","pid":1236,"":"io task","client":"2","":"downstairs","session_id":"2895d124-7b8f-41c4-aac8-882111792420"}
3682025-01-23T18:54:29.049Z{"msg":"connecting to 127.0.0.1:8840","v":0,"name":"crucible","level":30,"time":"2025-01-23T18:54:28.799612956Z","hostname":"w-01JJA7SE9SCYB3AF1MKA8WXYP0","pid":1236,"":"io task","client":"0","":"downstairs","session_id":"2895d124-7b8f-41c4-aac8-882111792420"}
3692025-01-23T18:54:29.049Z{"msg":"connecting to 127.0.0.1:8850","v":0,"name":"crucible","level":30,"time":"2025-01-23T18:54:28.799649336Z","hostname":"w-01JJA7SE9SCYB3AF1MKA8WXYP0","pid":1236,"":"io task","client":"1","":"downstairs","session_id":"2895d124-7b8f-41c4-aac8-882111792420"}
3702025-01-23T18:54:29.049Z{"msg":"ds_connection connected from Ok(127.0.0.1:56609)","v":0,"name":"crucible","level":30,"time":"2025-01-23T18:54:28.799668426Z","hostname":"w-01JJA7SE9SCYB3AF1MKA8WXYP0","pid":1236,"":"io task","client":"1","":"downstairs","session_id":"2895d124-7b8f-41c4-aac8-882111792420"}
3712025-01-23T18:54:29.049Z{"msg":"ds_connection connected from Ok(127.0.0.1:60734)","v":0,"name":"crucible","level":30,"time":"2025-01-23T18:54:28.799698956Z","hostname":"w-01JJA7SE9SCYB3AF1MKA8WXYP0","pid":1236,"":"io task","client":"0","":"downstairs","session_id":"2895d124-7b8f-41c4-aac8-882111792420"}
3722025-01-23T18:54:29.049Z{"msg":"ds_connection connected from Ok(127.0.0.1:58183)","v":0,"name":"crucible","level":30,"time":"2025-01-23T18:54:28.799725886Z","hostname":"w-01JJA7SE9SCYB3AF1MKA8WXYP0","pid":1236,"":"io task","client":"2","":"downstairs","session_id":"2895d124-7b8f-41c4-aac8-882111792420"}
3732025-01-23T18:54:29.049Z{"msg":"version negotiation from state Connecting { state: WaitForPromote, mode: New }","v":0,"name":"crucible","level":30,"time":"2025-01-23T18:54:28.799768566Z","hostname":"w-01JJA7SE9SCYB3AF1MKA8WXYP0","pid":1236,"client":"1","":"downstairs","session_id":"2895d124-7b8f-41c4-aac8-882111792420"}
3742025-01-23T18:54:29.049Z{"msg":"version negotiation from state Connecting { state: WaitForPromote, mode: New }","v":0,"name":"crucible","level":30,"time":"2025-01-23T18:54:28.799813976Z","hostname":"w-01JJA7SE9SCYB3AF1MKA8WXYP0","pid":1236,"client":"0","":"downstairs","session_id":"2895d124-7b8f-41c4-aac8-882111792420"}
3752025-01-23T18:54:29.049Z{"msg":"version negotiation from state Connecting { state: WaitForPromote, mode: New }","v":0,"name":"crucible","level":30,"time":"2025-01-23T18:54:28.799840466Z","hostname":"w-01JJA7SE9SCYB3AF1MKA8WXYP0","pid":1236,"client":"2","":"downstairs","session_id":"2895d124-7b8f-41c4-aac8-882111792420"}
3762025-01-23T18:54:29.049Z{"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-23T18:54:28.800078577Z","hostname":"w-01JJA7SE9SCYB3AF1MKA8WXYP0","pid":1236,"client":"1","":"downstairs","session_id":"2895d124-7b8f-41c4-aac8-882111792420"}
3772025-01-23T18:54:29.049Z{"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-23T18:54:28.800158126Z","hostname":"w-01JJA7SE9SCYB3AF1MKA8WXYP0","pid":1236,"client":"0","":"downstairs","session_id":"2895d124-7b8f-41c4-aac8-882111792420"}
3782025-01-23T18:54:29.049Z{"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-23T18:54:28.800201567Z","hostname":"w-01JJA7SE9SCYB3AF1MKA8WXYP0","pid":1236,"client":"2","":"downstairs","session_id":"2895d124-7b8f-41c4-aac8-882111792420"}
3792025-01-23T18:54:29.049Z{"msg":"Waiting for more clients to be ready","v":0,"name":"crucible","level":30,"time":"2025-01-23T18:54:28.800415637Z","hostname":"w-01JJA7SE9SCYB3AF1MKA8WXYP0","pid":1236,"session_id":"2895d124-7b8f-41c4-aac8-882111792420"}
3802025-01-23T18:54:29.049Z{"msg":"Waiting for more clients to be ready","v":0,"name":"crucible","level":30,"time":"2025-01-23T18:54:28.800524797Z","hostname":"w-01JJA7SE9SCYB3AF1MKA8WXYP0","pid":1236,"session_id":"2895d124-7b8f-41c4-aac8-882111792420"}
3812025-01-23T18:54:29.049Z{"msg":"[0]R flush_numbers: [5321, 5321, 5321, 5321, 5321]","v":0,"name":"crucible","level":30,"time":"2025-01-23T18:54:28.800564137Z","hostname":"w-01JJA7SE9SCYB3AF1MKA8WXYP0","pid":1236,"":"downstairs","":"downstairs","session_id":"2895d124-7b8f-41c4-aac8-882111792420"}
3822025-01-23T18:54:29.049Z{"msg":"[0]R generation: [31, 31, 31, 31, 31]","v":0,"name":"crucible","level":30,"time":"2025-01-23T18:54:28.800580207Z","hostname":"w-01JJA7SE9SCYB3AF1MKA8WXYP0","pid":1236,"":"downstairs","":"downstairs","session_id":"2895d124-7b8f-41c4-aac8-882111792420"}
3832025-01-23T18:54:29.050Z{"msg":"[0]R dirty: [false, false, false, false, false]","v":0,"name":"crucible","level":30,"time":"2025-01-23T18:54:28.800594477Z","hostname":"w-01JJA7SE9SCYB3AF1MKA8WXYP0","pid":1236,"":"downstairs","":"downstairs","session_id":"2895d124-7b8f-41c4-aac8-882111792420"}
3842025-01-23T18:54:29.050Z{"msg":"[1]R flush_numbers: [5321, 5321, 5321, 5321, 5321]","v":0,"name":"crucible","level":30,"time":"2025-01-23T18:54:28.800607727Z","hostname":"w-01JJA7SE9SCYB3AF1MKA8WXYP0","pid":1236,"":"downstairs","":"downstairs","session_id":"2895d124-7b8f-41c4-aac8-882111792420"}
3852025-01-23T18:54:29.050Z{"msg":"[1]R generation: [31, 31, 31, 31, 31]","v":0,"name":"crucible","level":30,"time":"2025-01-23T18:54:28.800634507Z","hostname":"w-01JJA7SE9SCYB3AF1MKA8WXYP0","pid":1236,"":"downstairs","":"downstairs","session_id":"2895d124-7b8f-41c4-aac8-882111792420"}
3862025-01-23T18:54:29.050Z{"msg":"[1]R dirty: [false, false, false, false, false]","v":0,"name":"crucible","level":30,"time":"2025-01-23T18:54:28.800655037Z","hostname":"w-01JJA7SE9SCYB3AF1MKA8WXYP0","pid":1236,"":"downstairs","":"downstairs","session_id":"2895d124-7b8f-41c4-aac8-882111792420"}
3872025-01-23T18:54:29.050Z{"msg":"[2]R flush_numbers: [5321, 5321, 5321, 5321, 5321]","v":0,"name":"crucible","level":30,"time":"2025-01-23T18:54:28.800671817Z","hostname":"w-01JJA7SE9SCYB3AF1MKA8WXYP0","pid":1236,"":"downstairs","":"downstairs","session_id":"2895d124-7b8f-41c4-aac8-882111792420"}
3882025-01-23T18:54:29.050Z{"msg":"[2]R generation: [31, 31, 31, 31, 31]","v":0,"name":"crucible","level":30,"time":"2025-01-23T18:54:28.800705387Z","hostname":"w-01JJA7SE9SCYB3AF1MKA8WXYP0","pid":1236,"":"downstairs","":"downstairs","session_id":"2895d124-7b8f-41c4-aac8-882111792420"}
3892025-01-23T18:54:29.050Z{"msg":"[2]R dirty: [false, false, false, false, false]","v":0,"name":"crucible","level":30,"time":"2025-01-23T18:54:28.800738187Z","hostname":"w-01JJA7SE9SCYB3AF1MKA8WXYP0","pid":1236,"":"downstairs","":"downstairs","session_id":"2895d124-7b8f-41c4-aac8-882111792420"}
3902025-01-23T18:54:29.050Z{"msg":"Max found gen is 32","v":0,"name":"crucible","level":30,"time":"2025-01-23T18:54:28.800753378Z","hostname":"w-01JJA7SE9SCYB3AF1MKA8WXYP0","pid":1236,"":"downstairs","":"downstairs","session_id":"2895d124-7b8f-41c4-aac8-882111792420"}
3912025-01-23T18:54:29.050Z{"msg":"Generation requested: 32 >= found:32","v":0,"name":"crucible","level":30,"time":"2025-01-23T18:54:28.800767387Z","hostname":"w-01JJA7SE9SCYB3AF1MKA8WXYP0","pid":1236,"":"downstairs","":"downstairs","session_id":"2895d124-7b8f-41c4-aac8-882111792420"}
3922025-01-23T18:54:29.050Z{"msg":"Next flush: 5322","v":0,"Wait for a query_work_queue command to finish before sending IO
3932025-01-23T18:54:29.050Zname":"crucible","level":30,"time":"2025-01-23T18:54:28.800806678Z","hostname":"w-01JJA7SE9SCYB3AF1MKA8WXYP0","pid":1236,"":"downstairs","":"downstairs","session_id":"2895d124-7b8f-41c4-aac8-882111792420"}
3942025-01-23T18:54:29.050Z{"msg":"All extents match","v":0,"name":"crucible","level":30,"time":"2025-01-23T18:54:28.800835187Z","hostname":"w-01JJA7SE9SCYB3AF1MKA8WXYP0","pid":1236,"":"downstairs","":"downstairs","session_id":"2895d124-7b8f-41c4-aac8-882111792420"}
3952025-01-23T18:54:29.050Z{"msg":"No downstairs reconciliation required","v":0,"name":"crucible","level":30,"time":"2025-01-23T18:54:28.800853958Z","hostname":"w-01JJA7SE9SCYB3AF1MKA8WXYP0","pid":1236,"session_id":"2895d124-7b8f-41c4-aac8-882111792420"}
3962025-01-23T18:54:29.050Z{"msg":"Transition from WaitQuorum to Active","v":0,"name":"crucible","level":30,"time":"2025-01-23T18:54:28.800865947Z","hostname":"w-01JJA7SE9SCYB3AF1MKA8WXYP0","pid":1236,"client":"0","":"downstairs","session_id":"2895d124-7b8f-41c4-aac8-882111792420"}
3972025-01-23T18:54:29.050Z{"msg":"Transition from WaitQuorum to Active","v":0,"name":"crucible","level":30,"time":"2025-01-23T18:54:28.800878728Z","hostname":"w-01JJA7SE9SCYB3AF1MKA8WXYP0","pid":1236,"client":"1","":"downstairs","session_id":"2895d124-7b8f-41c4-aac8-882111792420"}
3982025-01-23T18:54:29.050Z{"msg":"Transition from WaitQuorum to Active","v":0,"name":"crucible","level":30,"time":"2025-01-23T18:54:28.800906068Z","hostname":"w-01JJA7SE9SCYB3AF1MKA8WXYP0","pid":1236,"client":"2","":"downstairs","session_id":"2895d124-7b8f-41c4-aac8-882111792420"}
3992025-01-23T18:54:29.050Z{"msg":"All required reconciliation work is completed","v":0,"name":"crucible","level":30,"time":"2025-01-23T18:54:28.800932638Z","hostname":"w-01JJA7SE9SCYB3AF1MKA8WXYP0","pid":1236,"session_id":"2895d124-7b8f-41c4-aac8-882111792420"}
4002025-01-23T18:54:29.050Z{"msg":"Set Downstairs and Upstairs active after reconciliation","v":0,"name":"crucible","level":30,"time":"2025-01-23T18:54:28.800961928Z","hostname":"w-01JJA7SE9SCYB3AF1MKA8WXYP0","pid":1236,"session_id":"2895d124-7b8f-41c4-aac8-882111792420"}
4012025-01-23T18:54:29.050Z{"msg":"17eeca5e-f1c3-46a0-bcb2-be03bd636092 is now active with session: 2895d124-7b8f-41c4-aac8-882111792420","v":0,"name":"crucible","level":30,"time":"2025-01-23T18:54:28.800975888Z","hostname":"w-01JJA7SE9SCYB3AF1MKA8WXYP0","pid":1236,"session_id":"2895d124-7b8f-41c4-aac8-882111792420"}
4022025-01-23T18:54:29.050Z{"msg":"Set Active after no reconciliation","v":0,"name":"crucible","level":30,"time":"2025-01-23T18:54:28.800994138Z","hostname":"w-01JJA7SE9SCYB3AF1MKA8WXYP0","pid":1236,"session_id":"2895d124-7b8f-41c4-aac8-882111792420"}
4032025-01-23T18:54:29.050Z{"msg":"The guest has finished waiting for activation with:32","v":0,"name":"crucible","level":30,"time":"2025-01-23T18:54:28.801017238Z","hostname":"w-01JJA7SE9SCYB3AF1MKA8WXYP0","pid":1236}
4042025-01-23T18:54:29.050ZDisk: sv:2 bs:4096 ts:409600 tb:100 max_io:100 or 409600
4052025-01-23T18:54:29.050ZLoading write count information from file "/var/tmp/test_up-build/verify_file"
4062025-01-23T18:54:29.050ZFill test
4072025-01-23T18:54:29.090ZRead and Verify all blocks (0..100 range:false)
4082025-01-23T18:54:29.169ZWrote out file "/var/tmp/test_up-build/verify_file"
4092025-01-23T18:54:29.169ZCLIENT: Tests done. All submitted work has been ACK'd
4102025-01-23T18:54:29.172Z----------------------------------------------------------------
4112025-01-23T18:54:29.172Z Crucible gen:32 GIO:true work queues: Upstairs:0 downstairs:1
4122025-01-23T18:54:29.172ZStates: Active Active Active
4132025-01-23T18:54:29.172ZJOBID ACK TYPE BKS/EXT DS:0 DS:1 DS:2 REPLAY
4142025-01-23T18:54:29.172Z 1002 Acked Read 50 Done Done Done false
4152025-01-23T18:54:29.172Z STATES DS:0 DS:1 DS:2 TOTAL
4162025-01-23T18:54:29.172Z Sent 0 0 0 0
4172025-01-23T18:54:29.172Z Done 1 1 1 3
4182025-01-23T18:54:29.172Z Skipped 0 0 0 0
4192025-01-23T18:54:29.172Z Error 0 0 0 0
4202025-01-23T18:54:29.172ZLast Flush: Some(JobId(1001)) Some(JobId(1001)) Some(JobId(1001))
4212025-01-23T18:54:29.172ZDownstairs last five completed: 1001 1000
4222025-01-23T18:54:29.172ZUpstairs last five completed: 1002 1001 1000
4232025-01-23T18:54:29.172Z----------------------------------------------------------------
4242025-01-23T18:54:29.172Z Crucible gen:32 GIO:true work queues: Upstairs:0 downstairs:1
4252025-01-23T18:54:29.172ZStates: Active Active Active
4262025-01-23T18:54:29.172ZJOBID ACK TYPE BKS/EXT DS:0 DS:1 DS:2 REPLAY
4272025-01-23T18:54:29.172Z 1002 Acked Read 50 Sent Done Done false
4282025-01-23T18:54:29.172Z STATES DS:0 DS:1 DS:2 TOTAL
4292025-01-23T18:54:29.172Z Sent 1 0 0 1
4302025-01-23T18:54:29.172Z Done 0 1 1 2
4312025-01-23T18:54:29.172Z Skipped 0 0 0 0
4322025-01-23T18:54:29.172Z Error 0 0 0 0
4332025-01-23T18:54:29.172ZLast Flush: Some(JobId(1001)) Some(JobId(1001)) Some(JobId(1001))
4342025-01-23T18:54:29.172ZDownstairs last five completed: 1001 1000
4352025-01-23T18:54:29.172ZUpstairs last five completed: 1002 1001 1000
4362025-01-23T18:54:29.172ZCLIENT: Up:0 ds:2 act:6
4372025-01-23T18:54:33.171Z----------------------------------------------------------------
4382025-01-23T18:54:33.171Z Crucible gen:32 GIO:true work queues: Upstairs:0 downstairs:0
4392025-01-23T18:54:33.171ZDownstairs last five completed: 1003 1002 1001 1000
4402025-01-23T18:54:33.171ZUpstairs last five completed: 1003 1002 1001 1000
4412025-01-23T18:54:33.174Z----------------------------------------------------------------
4422025-01-23T18:54:33.174Z Crucible gen:32 GIO:true work queues: Upstairs:0 downstairs:0
4432025-01-23T18:54:33.174ZDownstairs last five completed: 1003 1002 1001 1000
4442025-01-23T18:54:33.174ZUpstairs last five completed: 1003 1002 1001 1000
4452025-01-23T18:54:33.174ZCLIENT: Up:0 ds:0 act:6
4462025-01-23T18:54:33.174ZCLIENT: All crucible jobs finished, exiting program
4472025-01-23T18:54:33.174Z{"msg":"Guest handle has been dropped","v":0,"name":"crucible","level":40,"time":"2025-01-23T18:54:32.925860642Z","hostname":"w-01JJA7SE9SCYB3AF1MKA8WXYP0","pid":1236}
4482025-01-23T18:54:33.178ZRepair part 1 passed
4492025-01-23T18:54:33.181Z
4502025-01-23T18:54:33.181ZKill the current downstairs
4512025-01-23T18:54:33.348ZDownstairs 2 stopped
4522025-01-23T18:54:33.348Zmv /var/tmp/test_up-build/8830 /var/tmp/test_up-build/new
4532025-01-23T18:54:33.351ZNow put back the original so we have a mismatch
4542025-01-23T18:54:33.351Zmv /var/tmp/test_up-build/previous /var/tmp/test_up-build/8830
4552025-01-23T18:54:33.354ZRestart downstairs with old directory
4562025-01-23T18:54:33.408Z/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-23T18:54:33.425ZEXT BLOCKS GEN0 GEN1 GEN2 FL0 FL1 FL2 D0 D1 D2 DIFF
4582025-01-23T18:54:33.427Z 0 000-009 32 32 31 4002 4002 4001 F F F <---
4592025-01-23T18:54:33.427Z 1 010-019 32 32 31 4002 4002 4001 F F F <---
4602025-01-23T18:54:33.427Z 2 020-029 32 32 31 4002 4002 4001 F F F <---
4612025-01-23T18:54:33.427Z 3 030-039 32 32 31 4002 4002 4001 F F F <---
4622025-01-23T18:54:33.427Z 4 040-049 32 32 31 4002 4002 4001 F F F <---
4632025-01-23T18:54:33.427ZMax gen: 32, Max flush: 4002
4642025-01-23T18:54:33.427ZError: Difference in extent metadata found!
4652025-01-23T18:54:33.430Zdump test found error as expected
4662025-01-23T18:54:33.430Z
4672025-01-23T18:54:33.430Z
4682025-01-23T18:54:33.430Z/var/tmp/bins/crutest verify --range -g 33 -q --key 9xPvF7de3WZ1vCpioKQCACyo8vJ/rwySjcN3nDeHU00= --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-23T18:54:33.487Z{"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-23T18:54:33.240956557Z","hostname":"w-01JJA7SE9SCYB3AF1MKA8WXYP0","pid":1244,"task":"crutest"}
4702025-01-23T18:54:33.489Z{"msg":"dsc has 6 regions. This means 2 sub_volumes","v":0,"name":"crucible","level":30,"time":"2025-01-23T18:54:33.241473738Z","hostname":"w-01JJA7SE9SCYB3AF1MKA8WXYP0","pid":1244,"task":"crutest"}
4712025-01-23T18:54:33.489Z{"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-23T18:54:33.243100251Z","hostname":"w-01JJA7SE9SCYB3AF1MKA8WXYP0","pid":1244,"task":"crutest"}
4722025-01-23T18:54:33.489Z{"msg":"Upstairs starts","v":0,"name":"crucible","level":30,"time":"2025-01-23T18:54:33.243297071Z","hostname":"w-01JJA7SE9SCYB3AF1MKA8WXYP0","pid":1244}
4732025-01-23T18:54:33.489Z{"msg":"Crucible Version: BuildInfo {\n version: \"0.0.1\",\n git_sha: \"dd1cf1330bf5c5b1551a0ad961a7aa7c6207feae\",\n git_commit_timestamp: \"2025-01-23T18:31:41.000000000Z\",\n git_branch: \"mkeeter/early-io-rejection\",\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-23T18:54:33.243349511Z","hostname":"w-01JJA7SE9SCYB3AF1MKA8WXYP0","pid":1244}
4742025-01-23T18:54:33.489Z{"msg":"Upstairs <-> Downstairs Message Version: 13","v":0,"name":"crucible","level":30,"time":"2025-01-23T18:54:33.243378001Z","hostname":"w-01JJA7SE9SCYB3AF1MKA8WXYP0","pid":1244}
4752025-01-23T18:54:33.489Z{"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-23T18:54:33.243396611Z","hostname":"w-01JJA7SE9SCYB3AF1MKA8WXYP0","pid":1244}
4762025-01-23T18:54:33.492Z{"msg":"Crucible 3ac6dd39-e20c-4bef-acfe-72e4b2f9b18a has session id: 37a75942-1a54-4ffb-ae5d-b0f17f1e77a9","v":0,"name":"crucible","level":30,"time":"2025-01-23T18:54:33.243888682Z","hostname":"w-01JJA7SE9SCYB3AF1MKA8WXYP0","pid":1244,"session_id":"37a75942-1a54-4ffb-ae5d-b0f17f1e77a9"}
4772025-01-23T18:54:33.492Z{"msg":"Upstairs opts: Upstairs UUID: 3ac6dd39-e20c-4bef-acfe-72e4b2f9b18a, 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-23T18:54:33.243953312Z","hostname":"w-01JJA7SE9SCYB3AF1MKA8WXYP0","pid":1244,"session_id":"37a75942-1a54-4ffb-ae5d-b0f17f1e77a9"}
4782025-01-23T18:54:33.492Z{"msg":"Crucible stats registered with UUID: 3ac6dd39-e20c-4bef-acfe-72e4b2f9b18a","v":0,"name":"crucible","level":30,"time":"2025-01-23T18:54:33.243976072Z","hostname":"w-01JJA7SE9SCYB3AF1MKA8WXYP0","pid":1244,"session_id":"37a75942-1a54-4ffb-ae5d-b0f17f1e77a9"}
4792025-01-23T18:54:33.492Z{"msg":"could not find Downstairs address for Nexus","v":0,"name":"crucible","level":40,"time":"2025-01-23T18:54:33.244008492Z","hostname":"w-01JJA7SE9SCYB3AF1MKA8WXYP0","pid":1244,"session_id":"37a75942-1a54-4ffb-ae5d-b0f17f1e77a9"}
4802025-01-23T18:54:33.492Z{"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-23T18:54:33.245899385Z","hostname":"w-01JJA7SE9SCYB3AF1MKA8WXYP0","pid":1244,"task":"crutest"}
4812025-01-23T18:54:33.492Z{"msg":"Upstairs starts","v":0,"name":"crucible","level":30,"time":"2025-01-23T18:54:33.245974655Z","hostname":"w-01JJA7SE9SCYB3AF1MKA8WXYP0","pid":1244}
4822025-01-23T18:54:33.492Z{"msg":"Crucible Version: BuildInfo {\n version: \"0.0.1\",\n git_sha: \"dd1cf1330bf5c5b1551a0ad961a7aa7c6207feae\",\n git_commit_timestamp: \"2025-01-23T18:31:41.000000000Z\",\n git_branch: \"mkeeter/early-io-rejection\",\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-23T18:54:33.246019105Z","hostname":"w-01JJA7SE9SCYB3AF1MKA8WXYP0","pid":1244}
4832025-01-23T18:54:33.492Z{"msg":"Upstairs <-> Downstairs Message Version: 13","v":0,"name":"crucible","level":30,"time":"2025-01-23T18:54:33.246040685Z","hostname":"w-01JJA7SE9SCYB3AF1MKA8WXYP0","pid":1244}
4842025-01-23T18:54:33.492Z{"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-23T18:54:33.246055285Z","hostname":"w-01JJA7SE9SCYB3AF1MKA8WXYP0","pid":1244}
4852025-01-23T18:54:33.492Z{"msg":"Crucible 3ac6dd39-e20c-4bef-acfe-72e4b2f9b18a has session id: 623db029-411f-4023-8a4a-8acb2790d712","v":0,"name":"crucible","level":30,"time":"2025-01-23T18:54:33.246467845Z","hostname":"w-01JJA7SE9SCYB3AF1MKA8WXYP0","pid":1244,"session_id":"623db029-411f-4023-8a4a-8acb2790d712"}
4862025-01-23T18:54:33.495Z{"msg":"Upstairs opts: Upstairs UUID: 3ac6dd39-e20c-4bef-acfe-72e4b2f9b18a, 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-23T18:54:33.246541116Z","hostname":"w-01JJA7SE9SCYB3AF1MKA8WXYP0","pid":1244,"session_id":"623db029-411f-4023-8a4a-8acb2790d712"}
4872025-01-23T18:54:33.495Z{"msg":"Crucible stats registered with UUID: 3ac6dd39-e20c-4bef-acfe-72e4b2f9b18a","v":0,"name":"crucible","level":30,"time":"2025-01-23T18:54:33.246582916Z","hostname":"w-01JJA7SE9SCYB3AF1MKA8WXYP0","pid":1244,"session_id":"623db029-411f-4023-8a4a-8acb2790d712"}
4882025-01-23T18:54:33.495Z{"msg":"could not find Downstairs address for Nexus","v":0,"name":"crucible","level":40,"time":"2025-01-23T18:54:33.246625866Z","hostname":"w-01JJA7SE9SCYB3AF1MKA8WXYP0","pid":1244,"session_id":"623db029-411f-4023-8a4a-8acb2790d712"}
4892025-01-23T18:54:33.495Z{"msg":"Downstairs in volume = 6","v":0,"name":"crucible","level":30,"time":"2025-01-23T18:54:33.247172266Z","hostname":"w-01JJA7SE9SCYB3AF1MKA8WXYP0","pid":1244,"task":"crutest"}
4902025-01-23T18:54:33.496Z{"msg":"The guest has requested activation with gen:33","v":0,"name":"crucible","level":30,"time":"2025-01-23T18:54:33.247205686Z","hostname":"w-01JJA7SE9SCYB3AF1MKA8WXYP0","pid":1244}
4912025-01-23T18:54:33.496Z{"msg":"3ac6dd39-e20c-4bef-acfe-72e4b2f9b18a active request set","v":0,"name":"crucible","level":30,"time":"2025-01-23T18:54:33.247257637Z","hostname":"w-01JJA7SE9SCYB3AF1MKA8WXYP0","pid":1244,"session_id":"37a75942-1a54-4ffb-ae5d-b0f17f1e77a9"}
4922025-01-23T18:54:33.496Z{"msg":"sending connect oneshot to client","v":0,"name":"crucible","level":30,"time":"2025-01-23T18:54:33.247294057Z","hostname":"w-01JJA7SE9SCYB3AF1MKA8WXYP0","pid":1244,"client":"0","":"downstairs","session_id":"37a75942-1a54-4ffb-ae5d-b0f17f1e77a9"}
4932025-01-23T18:54:33.496Z{"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-23T18:54:33.247340527Z","hostname":"w-01JJA7SE9SCYB3AF1MKA8WXYP0","pid":1244,"client":"0","":"downstairs","session_id":"37a75942-1a54-4ffb-ae5d-b0f17f1e77a9"}
4942025-01-23T18:54:33.496Z{"msg":"sending connect oneshot to client","v":0,"name":"crucible","level":30,"time":"2025-01-23T18:54:33.247368597Z","hostname":"w-01JJA7SE9SCYB3AF1MKA8WXYP0","pid":1244,"client":"1","":"downstairs","session_id":"37a75942-1a54-4ffb-ae5d-b0f17f1e77a9"}
4952025-01-23T18:54:33.496Z{"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-23T18:54:33.247391487Z","hostname":"w-01JJA7SE9SCYB3AF1MKA8WXYP0","pid":1244,"client":"1","":"downstairs","session_id":"37a75942-1a54-4ffb-ae5d-b0f17f1e77a9"}
4962025-01-23T18:54:33.496Z{"msg":"sending connect oneshot to client","v":0,"name":"crucible","level":30,"time":"2025-01-23T18:54:33.247414387Z","hostname":"w-01JJA7SE9SCYB3AF1MKA8WXYP0","pid":1244,"client":"2","":"downstairs","session_id":"37a75942-1a54-4ffb-ae5d-b0f17f1e77a9"}
4972025-01-23T18:54:33.496Z{"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-23T18:54:33.247436277Z","hostname":"w-01JJA7SE9SCYB3AF1MKA8WXYP0","pid":1244,"client":"2","":"downstairs","session_id":"37a75942-1a54-4ffb-ae5d-b0f17f1e77a9"}
4982025-01-23T18:54:33.496Z{"msg":"connecting to 127.0.0.1:8830","v":0,"name":"crucible","level":30,"time":"2025-01-23T18:54:33.247460917Z","hostname":"w-01JJA7SE9SCYB3AF1MKA8WXYP0","pid":1244,"":"io task","client":"2","":"downstairs","session_id":"37a75942-1a54-4ffb-ae5d-b0f17f1e77a9"}
4992025-01-23T18:54:33.496Z{"msg":"connecting to 127.0.0.1:8810","v":0,"name":"crucible","level":30,"time":"2025-01-23T18:54:33.247488217Z","hostname":"w-01JJA7SE9SCYB3AF1MKA8WXYP0","pid":1244,"":"io task","client":"0","":"downstairs","session_id":"37a75942-1a54-4ffb-ae5d-b0f17f1e77a9"}
5002025-01-23T18:54:33.497Z{"msg":"connecting to 127.0.0.1:8820","v":0,"name":"crucible","level":30,"time":"2025-01-23T18:54:33.247513637Z","hostname":"w-01JJA7SE9SCYB3AF1MKA8WXYP0","pid":1244,"":"io task","client":"1","":"downstairs","session_id":"37a75942-1a54-4ffb-ae5d-b0f17f1e77a9"}
5012025-01-23T18:54:33.497Z{"msg":"ds_connection connected from Ok(127.0.0.1:36146)","v":0,"name":"crucible","level":30,"time":"2025-01-23T18:54:33.247537497Z","hostname":"w-01JJA7SE9SCYB3AF1MKA8WXYP0","pid":1244,"":"io task","client":"1","":"downstairs","session_id":"37a75942-1a54-4ffb-ae5d-b0f17f1e77a9"}
5022025-01-23T18:54:33.497Z{"msg":"ds_connection connected from Ok(127.0.0.1:37288)","v":0,"name":"crucible","level":30,"time":"2025-01-23T18:54:33.247560887Z","hostname":"w-01JJA7SE9SCYB3AF1MKA8WXYP0","pid":1244,"":"io task","client":"0","":"downstairs","session_id":"37a75942-1a54-4ffb-ae5d-b0f17f1e77a9"}
5032025-01-23T18:54:33.497Z{"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-23T18:54:33.247681247Z","hostname":"w-01JJA7SE9SCYB3AF1MKA8WXYP0","pid":1244,"":"io task","client":"2","":"downstairs","session_id":"37a75942-1a54-4ffb-ae5d-b0f17f1e77a9"}
5042025-01-23T18:54:33.497Z{"msg":"client task is sending Done(ConnectionFailed(Os { code: 146, kind: ConnectionRefused, message: \"Connection refused\" }))","v":0,"name":"crucible","level":40,"time":"2025-01-23T18:54:33.247751487Z","hostname":"w-01JJA7SE9SCYB3AF1MKA8WXYP0","pid":1244,"":"io task","client":"2","":"downstairs","session_id":"37a75942-1a54-4ffb-ae5d-b0f17f1e77a9"}
5052025-01-23T18:54:33.497Z{"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-23T18:54:33.247789627Z","hostname":"w-01JJA7SE9SCYB3AF1MKA8WXYP0","pid":1244,"session_id":"37a75942-1a54-4ffb-ae5d-b0f17f1e77a9"}
5062025-01-23T18:54:33.497Z{"msg":"client task is exiting","v":0,"name":"crucible","level":30,"time":"2025-01-23T18:54:33.247935298Z","hostname":"w-01JJA7SE9SCYB3AF1MKA8WXYP0","pid":1244,"":"io task","client":"2","":"downstairs","session_id":"37a75942-1a54-4ffb-ae5d-b0f17f1e77a9"}
5072025-01-23T18:54:33.497Z{"msg":"version negotiation from state Connecting { state: WaitForPromote, mode: New }","v":0,"name":"crucible","level":30,"time":"2025-01-23T18:54:33.248374968Z","hostname":"w-01JJA7SE9SCYB3AF1MKA8WXYP0","pid":1244,"client":"0","":"downstairs","session_id":"37a75942-1a54-4ffb-ae5d-b0f17f1e77a9"}
5082025-01-23T18:54:33.497Z{"msg":"version negotiation from state Connecting { state: WaitForPromote, mode: New }","v":0,"name":"crucible","level":30,"time":"2025-01-23T18:54:33.248406868Z","hostname":"w-01JJA7SE9SCYB3AF1MKA8WXYP0","pid":1244,"client":"1","":"downstairs","session_id":"37a75942-1a54-4ffb-ae5d-b0f17f1e77a9"}
5092025-01-23T18:54:33.497Z{"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-23T18:54:33.248993519Z","hostname":"w-01JJA7SE9SCYB3AF1MKA8WXYP0","pid":1244,"client":"0","":"downstairs","session_id":"37a75942-1a54-4ffb-ae5d-b0f17f1e77a9"}
5102025-01-23T18:54:33.497Z{"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-23T18:54:33.249029469Z","hostname":"w-01JJA7SE9SCYB3AF1MKA8WXYP0","pid":1244,"client":"1","":"downstairs","session_id":"37a75942-1a54-4ffb-ae5d-b0f17f1e77a9"}
5112025-01-23T18:54:33.497Z{"msg":"Waiting for more clients to be ready","v":0,"name":"crucible","level":30,"time":"2025-01-23T18:54:33.24939359Z","hostname":"w-01JJA7SE9SCYB3AF1MKA8WXYP0","pid":1244,"session_id":"37a75942-1a54-4ffb-ae5d-b0f17f1e77a9"}
5122025-01-23T18:54:33.497Z{"msg":"Waiting for more clients to be ready","v":0,"name":"crucible","level":30,"time":"2025-01-23T18:54:33.24941934Z","hostname":"w-01JJA7SE9SCYB3AF1MKA8WXYP0","pid":1244,"session_id":"37a75942-1a54-4ffb-ae5d-b0f17f1e77a9"}
5132025-01-23T18:54:43.496Z{"msg":"connecting to 127.0.0.1:8830","v":0,"name":"crucible","level":30,"time":"2025-01-23T18:54:43.249937003Z","hostname":"w-01JJA7SE9SCYB3AF1MKA8WXYP0","pid":1244,"":"io task","client":"2","":"downstairs","session_id":"37a75942-1a54-4ffb-ae5d-b0f17f1e77a9"}
5142025-01-23T18:54:43.496Z{"msg":"ds_connection connected from Ok(127.0.0.1:55403)","v":0,"name":"crucible","level":30,"time":"2025-01-23T18:54:43.250044294Z","hostname":"w-01JJA7SE9SCYB3AF1MKA8WXYP0","pid":1244,"":"io task","client":"2","":"downstairs","session_id":"37a75942-1a54-4ffb-ae5d-b0f17f1e77a9"}
5152025-01-23T18:54:43.500Z{"msg":"version negotiation from state Connecting { state: WaitForPromote, mode: New }","v":0,"name":"crucible","level":30,"time":"2025-01-23T18:54:43.251133025Z","hostname":"w-01JJA7SE9SCYB3AF1MKA8WXYP0","pid":1244,"client":"2","":"downstairs","session_id":"37a75942-1a54-4ffb-ae5d-b0f17f1e77a9"}
5162025-01-23T18:54:43.500Z{"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-23T18:54:43.251689426Z","hostname":"w-01JJA7SE9SCYB3AF1MKA8WXYP0","pid":1244,"client":"2","":"downstairs","session_id":"37a75942-1a54-4ffb-ae5d-b0f17f1e77a9"}
5172025-01-23T18:54:43.500Z{"msg":"[0]R flush_numbers: [4002, 4002, 4002, 4002, 4002]","v":0,"name":"crucible","level":30,"time":"2025-01-23T18:54:43.252090657Z","hostname":"w-01JJA7SE9SCYB3AF1MKA8WXYP0","pid":1244,"":"downstairs","":"downstairs","session_id":"37a75942-1a54-4ffb-ae5d-b0f17f1e77a9"}
5182025-01-23T18:54:43.500Z{"msg":"[0]R generation: [32, 32, 32, 32, 32]","v":0,"name":"crucible","level":30,"time":"2025-01-23T18:54:43.252131517Z","hostname":"w-01JJA7SE9SCYB3AF1MKA8WXYP0","pid":1244,"":"downstairs","":"downstairs","session_id":"37a75942-1a54-4ffb-ae5d-b0f17f1e77a9"}
5192025-01-23T18:54:43.500Z{"msg":"[0]R dirty: [false, false, false, false, false]","v":0,"name":"crucible","level":30,"time":"2025-01-23T18:54:43.252150927Z","hostname":"w-01JJA7SE9SCYB3AF1MKA8WXYP0","pid":1244,"":"downstairs","":"downstairs","session_id":"37a75942-1a54-4ffb-ae5d-b0f17f1e77a9"}
5202025-01-23T18:54:43.500Z{"msg":"[1]R flush_numbers: [4002, 4002, 4002, 4002, 4002]","v":0,"name":"crucible","level":30,"time":"2025-01-23T18:54:43.252177517Z","hostname":"w-01JJA7SE9SCYB3AF1MKA8WXYP0","pid":1244,"":"downstairs","":"downstairs","session_id":"37a75942-1a54-4ffb-ae5d-b0f17f1e77a9"}
5212025-01-23T18:54:43.500Z{"msg":"[1]R generation: [32, 32, 32, 32, 32]","v":0,"name":"crucible","level":30,"time":"2025-01-23T18:54:43.252194607Z","hostname":"w-01JJA7SE9SCYB3AF1MKA8WXYP0","pid":1244,"":"downstairs","":"downstairs","session_id":"37a75942-1a54-4ffb-ae5d-b0f17f1e77a9"}
5222025-01-23T18:54:43.500Z{"msg":"[1]R dirty: [false, false, false, false, false]","v":0,"name":"crucible","level":30,"time":"2025-01-23T18:54:43.252220727Z","hostname":"w-01JJA7SE9SCYB3AF1MKA8WXYP0","pid":1244,"":"downstairs","":"downstairs","session_id":"37a75942-1a54-4ffb-ae5d-b0f17f1e77a9"}
5232025-01-23T18:54:43.500Z{"msg":"[2]R flush_numbers: [4001, 4001, 4001, 4001, 4001]","v":0,"name":"crucible","level":30,"time":"2025-01-23T18:54:43.252237307Z","hostname":"w-01JJA7SE9SCYB3AF1MKA8WXYP0","pid":1244,"":"downstairs","":"downstairs","session_id":"37a75942-1a54-4ffb-ae5d-b0f17f1e77a9"}
5242025-01-23T18:54:43.500Z{"msg":"[2]R generation: [31, 31, 31, 31, 31]","v":0,"name":"crucible","level":30,"time":"2025-01-23T18:54:43.252262727Z","hostname":"w-01JJA7SE9SCYB3AF1MKA8WXYP0","pid":1244,"":"downstairs","":"downstairs","session_id":"37a75942-1a54-4ffb-ae5d-b0f17f1e77a9"}
5252025-01-23T18:54:43.500Z{"msg":"[2]R dirty: [false, false, false, false, false]","v":0,"name":"crucible","level":30,"time":"2025-01-23T18:54:43.252279467Z","hostname":"w-01JJA7SE9SCYB3AF1MKA8WXYP0","pid":1244,"":"downstairs","":"downstairs","session_id":"37a75942-1a54-4ffb-ae5d-b0f17f1e77a9"}
5262025-01-23T18:54:43.500Z{"msg":"Max found gen is 33","v":0,"name":"crucible","level":30,"time":"2025-01-23T18:54:43.252305347Z","hostname":"w-01JJA7SE9SCYB3AF1MKA8WXYP0","pid":1244,"":"downstairs","":"downstairs","session_id":"37a75942-1a54-4ffb-ae5d-b0f17f1e77a9"}
5272025-01-23T18:54:43.500Z{"msg":"Generation requested: 33 >= found:33","v":0,"name":"crucible","level":30,"time":"2025-01-23T18:54:43.252321807Z","hostname":"w-01JJA7SE9SCYB3AF1MKA8WXYP0","pid":1244,"":"downstairs","":"downstairs","session_id":"37a75942-1a54-4ffb-ae5d-b0f17f1e77a9"}
5282025-01-23T18:54:43.500Z{"msg":"Next flush: 4003","v":0,"name":"crucible","level":30,"time":"2025-01-23T18:54:43.252347327Z","hostname":"w-01JJA7SE9SCYB3AF1MKA8WXYP0","pid":1244,"":"downstairs","":"downstairs","session_id":"37a75942-1a54-4ffb-ae5d-b0f17f1e77a9"}
5292025-01-23T18:54:43.501Z{"msg":"extent 0 needs reconciliation: ExtentMetadata { gen: 32, flush: 4002, dirty: false } ExtentMetadata { gen: 32, flush: 4002, dirty: false } ExtentMetadata { gen: 31, flush: 4001, dirty: false }","v":0,"name":"crucible","level":30,"time":"2025-01-23T18:54:43.252366377Z","hostname":"w-01JJA7SE9SCYB3AF1MKA8WXYP0","pid":1244,"":"mend","":"downstairs","":"downstairs","session_id":"37a75942-1a54-4ffb-ae5d-b0f17f1e77a9"}
5302025-01-23T18:54:43.501Z{"msg":"extent:0 [ExtentMetadata { gen: 32, flush: 4002, dirty: false }, ExtentMetadata { gen: 32, flush: 4002, dirty: false }, ExtentMetadata { gen: 31, flush: 4001, dirty: false }] => 0","v":0,"name":"crucible","level":30,"time":"2025-01-23T18:54:43.252386367Z","hostname":"w-01JJA7SE9SCYB3AF1MKA8WXYP0","pid":1244,"":"mend","":"downstairs","":"downstairs","session_id":"37a75942-1a54-4ffb-ae5d-b0f17f1e77a9"}
5312025-01-23T18:54:43.501Z{"msg":"found dest for source 0 for extent at index 0 => [ClientId(2)]","v":0,"name":"crucible","level":30,"time":"2025-01-23T18:54:43.252403357Z","hostname":"w-01JJA7SE9SCYB3AF1MKA8WXYP0","pid":1244,"":"mend","":"downstairs","":"downstairs","session_id":"37a75942-1a54-4ffb-ae5d-b0f17f1e77a9"}
5322025-01-23T18:54:43.501Z{"msg":"extent 1 needs reconciliation: ExtentMetadata { gen: 32, flush: 4002, dirty: false } ExtentMetadata { gen: 32, flush: 4002, dirty: false } ExtentMetadata { gen: 31, flush: 4001, dirty: false }","v":0,"name":"crucible","level":30,"time":"2025-01-23T18:54:43.252422057Z","hostname":"w-01JJA7SE9SCYB3AF1MKA8WXYP0","pid":1244,"":"mend","":"downstairs","":"downstairs","session_id":"37a75942-1a54-4ffb-ae5d-b0f17f1e77a9"}
5332025-01-23T18:54:43.501Z{"msg":"extent:0 [ExtentMetadata { gen: 32, flush: 4002, dirty: false }, ExtentMetadata { gen: 32, flush: 4002, dirty: false }, ExtentMetadata { gen: 31, flush: 4001, dirty: false }] => 0","v":0,"name":"crucible","level":30,"time":"2025-01-23T18:54:43.252442147Z","hostname":"w-01JJA7SE9SCYB3AF1MKA8WXYP0","pid":1244,"":"mend","":"downstairs","":"downstairs","session_id":"37a75942-1a54-4ffb-ae5d-b0f17f1e77a9"}
5342025-01-23T18:54:43.501Z{"msg":"found dest for source 0 for extent at index 1 => [ClientId(2)]","v":0,"name":"crucible","level":30,"time":"2025-01-23T18:54:43.252459167Z","hostname":"w-01JJA7SE9SCYB3AF1MKA8WXYP0","pid":1244,"":"mend","":"downstairs","":"downstairs","session_id":"37a75942-1a54-4ffb-ae5d-b0f17f1e77a9"}
5352025-01-23T18:54:43.501Z{"msg":"extent 2 needs reconciliation: ExtentMetadata { gen: 32, flush: 4002, dirty: false } ExtentMetadata { gen: 32, flush: 4002, dirty: false } ExtentMetadata { gen: 31, flush: 4001, dirty: false }","v":0,"name":"crucible","level":30,"time":"2025-01-23T18:54:43.252488087Z","hostname":"w-01JJA7SE9SCYB3AF1MKA8WXYP0","pid":1244,"":"mend","":"downstairs","":"downstairs","session_id":"37a75942-1a54-4ffb-ae5d-b0f17f1e77a9"}
5362025-01-23T18:54:43.501Z{"msg":"extent:0 [ExtentMetadata { gen: 32, flush: 4002, dirty: false }, ExtentMetadata { gen: 32, flush: 4002, dirty: false }, ExtentMetadata { gen: 31, flush: 4001, dirty: false }] => 0","v":0,"name":"crucible","level":30,"time":"2025-01-23T18:54:43.252507817Z","hostname":"w-01JJA7SE9SCYB3AF1MKA8WXYP0","pid":1244,"":"mend","":"downstairs","":"downstairs","session_id":"37a75942-1a54-4ffb-ae5d-b0f17f1e77a9"}
5372025-01-23T18:54:43.501Z{"msg":"found dest for source 0 for extent at index 2 => [ClientId(2)]","v":0,"name":"crucible","level":30,"time":"2025-01-23T18:54:43.252525807Z","hostname":"w-01JJA7SE9SCYB3AF1MKA8WXYP0","pid":1244,"":"mend","":"downstairs","":"downstairs","session_id":"37a75942-1a54-4ffb-ae5d-b0f17f1e77a9"}
5382025-01-23T18:54:43.501Z{"msg":"extent 3 needs reconciliation: ExtentMetadata { gen: 32, flush: 4002, dirty: false } ExtentMetadata { gen: 32, flush: 4002, dirty: false } ExtentMetadata { gen: 31, flush: 4001, dirty: false }","v":0,"name":"crucible","level":30,"time":"2025-01-23T18:54:43.252544498Z","hostname":"w-01JJA7SE9SCYB3AF1MKA8WXYP0","pid":1244,"":"mend","":"downstairs","":"downstairs","session_id":"37a75942-1a54-4ffb-ae5d-b0f17f1e77a9"}
5392025-01-23T18:54:43.501Z{"msg":"extent:0 [ExtentMetadata { gen: 32, flush: 4002, dirty: false }, ExtentMetadata { gen: 32, flush: 4002, dirty: false }, ExtentMetadata { gen: 31, flush: 4001, dirty: false }] => 0","v":0,"name":"crucible","level":30,"time":"2025-01-23T18:54:43.252573118Z","hostname":"w-01JJA7SE9SCYB3AF1MKA8WXYP0","pid":1244,"":"mend","":"downstairs","":"downstairs","session_id":"37a75942-1a54-4ffb-ae5d-b0f17f1e77a9"}
5402025-01-23T18:54:43.501Z{"msg":"found dest for source 0 for extent at index 3 => [ClientId(2)]","v":0,"name":"crucible","level":30,"time":"2025-01-23T18:54:43.252590678Z","hostname":"w-01JJA7SE9SCYB3AF1MKA8WXYP0","pid":1244,"":"mend","":"downstairs","":"downstairs","session_id":"37a75942-1a54-4ffb-ae5d-b0f17f1e77a9"}
5412025-01-23T18:54:43.501Z{"msg":"extent 4 needs reconciliation: ExtentMetadata { gen: 32, flush: 4002, dirty: false } ExtentMetadata { gen: 32, flush: 4002, dirty: false } ExtentMetadata { gen: 31, flush: 4001, dirty: false }","v":0,"name":"crucible","level":30,"time":"2025-01-23T18:54:43.252618838Z","hostname":"w-01JJA7SE9SCYB3AF1MKA8WXYP0","pid":1244,"":"mend","":"downstairs","":"downstairs","session_id":"37a75942-1a54-4ffb-ae5d-b0f17f1e77a9"}
5422025-01-23T18:54:43.501Z{"msg":"extent:0 [ExtentMetadata { gen: 32, flush: 4002, dirty: false }, ExtentMetadata { gen: 32, flush: 4002, dirty: false }, ExtentMetadata { gen: 31, flush: 4001, dirty: false }] => 0","v":0,"name":"crucible","level":30,"time":"2025-01-23T18:54:43.252653178Z","hostname":"w-01JJA7SE9SCYB3AF1MKA8WXYP0","pid":1244,"":"mend","":"downstairs","":"downstairs","session_id":"37a75942-1a54-4ffb-ae5d-b0f17f1e77a9"}
5432025-01-23T18:54:43.501Z{"msg":"found dest for source 0 for extent at index 4 => [ClientId(2)]","v":0,"name":"crucible","level":30,"time":"2025-01-23T18:54:43.252677968Z","hostname":"w-01JJA7SE9SCYB3AF1MKA8WXYP0","pid":1244,"":"mend","":"downstairs","":"downstairs","session_id":"37a75942-1a54-4ffb-ae5d-b0f17f1e77a9"}
5442025-01-23T18:54:43.501Z{"msg":"Transition from Connecting { state: WaitQuorum, mode: New } to Reconcile","v":0,"name":"crucible","level":30,"time":"2025-01-23T18:54:43.252717028Z","hostname":"w-01JJA7SE9SCYB3AF1MKA8WXYP0","pid":1244,"client":"0","":"downstairs","session_id":"37a75942-1a54-4ffb-ae5d-b0f17f1e77a9"}
5452025-01-23T18:54:43.501Z{"msg":"Transition from Connecting { state: WaitQuorum, mode: New } to Reconcile","v":0,"name":"crucible","level":30,"time":"2025-01-23T18:54:43.252762408Z","hostname":"w-01JJA7SE9SCYB3AF1MKA8WXYP0","pid":1244,"client":"1","":"downstairs","session_id":"37a75942-1a54-4ffb-ae5d-b0f17f1e77a9"}
5462025-01-23T18:54:43.501Z{"msg":"Transition from Connecting { state: WaitQuorum, mode: New } to Reconcile","v":0,"name":"crucible","level":30,"time":"2025-01-23T18:54:43.252810078Z","hostname":"w-01JJA7SE9SCYB3AF1MKA8WXYP0","pid":1244,"client":"2","":"downstairs","session_id":"37a75942-1a54-4ffb-ae5d-b0f17f1e77a9"}
5472025-01-23T18:54:43.501Z{"msg":"Full repair list: {ExtentId(2): ExtentFix { source: ClientId(0), dest: [ClientId(2)] }, ExtentId(3): ExtentFix { source: ClientId(0), dest: [ClientId(2)] }, ExtentId(1): ExtentFix { source: ClientId(0), dest: [ClientId(2)] }, ExtentId(0): ExtentFix { source: ClientId(0), dest: [ClientId(2)] }, ExtentId(4): ExtentFix { source: ClientId(0), dest: [ClientId(2)] }}","v":0,"name":"crucible","level":30,"time":"2025-01-23T18:54:43.252865438Z","hostname":"w-01JJA7SE9SCYB3AF1MKA8WXYP0","pid":1244,"":"downstairs","":"downstairs","session_id":"37a75942-1a54-4ffb-ae5d-b0f17f1e77a9"}
5482025-01-23T18:54:43.504Z{"msg":"Task list: [ReconcileIO { id: ReconciliationId(0), op: ExtentFlush { repair_id: ReconciliationId(0), extent_id: ExtentId(2), client_id: ClientId(0), flush_number: 4003, gen_number: 33 }, state: ClientData([New, New, New]) }, ReconcileIO { id: ReconciliationId(1), op: ExtentClose { repair_id: ReconciliationId(1), extent_id: ExtentId(2) }, state: ClientData([New, New, New]) }, ReconcileIO { id: ReconciliationId(2), op: ExtentRepair { repair_id: ReconciliationId(2), extent_id: ExtentId(2), source_client_id: ClientId(0), source_repair_address: 0.0.0.0:12810, dest_clients: [ClientId(2)] }, state: ClientData([New, New, New]) }, ReconcileIO { id: ReconciliationId(3), op: ExtentReopen { repair_id: ReconciliationId(3), extent_id: ExtentId(2) }, state: ClientData([New, New, New]) }, ReconcileIO { id: ReconciliationId(4), op: ExtentFlush { repair_id: ReconciliationId(4), extent_id: ExtentId(3), client_id: ClientId(0), flush_number: 4003, gen_number: 33 }, state: ClientData([New, New, New]) }, ReconcileIO { id: ReconciliationId(5), op: ExtentClose { repair_id: ReconciliationId(5), extent_id: ExtentId(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(1), client_id: ClientId(0), flush_number: 4003, gen_number: 33 }, state: ClientData([New, New, New]) }, ReconcileIO { id: ReconciliationId(9), op: ExtentClose { repair_id: ReconciliationId(9), extent_id: ExtentId(1) }, state: ClientData([New, New, New]) }, ReconcileIO { id: ReconciliationId(10), op: ExtentRepair { repair_id: ReconciliationId(10), 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(11), op: ExtentReopen { repair_id: ReconciliationId(11), extent_id: ExtentId(1) }, state: ClientData([New, New, New]) }, ReconcileIO { id: ReconciliationId(12), op: ExtentFlush { repair_id: ReconciliationId(12), extent_id: ExtentId(0), client_id: ClientId(0), flush_number: 4003, gen_number: 33 }, state: ClientData([New, New, New]) }, ReconcileIO { id: ReconciliationId(13), op: ExtentClose { repair_id: ReconciliationId(13), extent_id: ExtentId(0) }, state: ClientData([New, New, New]) }, ReconcileIO { id: ReconciliationId(14), op: ExtentRepair { repair_id: ReconciliationId(14), 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(15), op: ExtentReopen { repair_id: ReconciliationId(15), extent_id: ExtentId(0) }, 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: 4003, 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-23T18:54:43.252977498Z","hostname":"w-01JJA7SE9SCYB3AF1MKA8WXYP0","pid":1244,"":"downstairs","":"downstairs","session_id":"37a75942-1a54-4ffb-ae5d-b0f17f1e77a9"}
5492025-01-23T18:54:43.504Z{"msg":"starting reconciliation 0ad963f1-9f96-4055-92c0-401e177e82f1: found 20 extents that need repair","v":0,"name":"crucible","level":30,"time":"2025-01-23T18:54:43.253005018Z","hostname":"w-01JJA7SE9SCYB3AF1MKA8WXYP0","pid":1244,"":"downstairs","":"downstairs","session_id":"37a75942-1a54-4ffb-ae5d-b0f17f1e77a9"}
5502025-01-23T18:54:43.504Z{"msg":"sending reconcile request ReconciliationId(2)","v":0,"name":"crucible","level":30,"time":"2025-01-23T18:54:43.253105668Z","hostname":"w-01JJA7SE9SCYB3AF1MKA8WXYP0","pid":1244,"client":"2","":"downstairs","session_id":"37a75942-1a54-4ffb-ae5d-b0f17f1e77a9"}
5512025-01-23T18:54:43.508Z{"msg":"sending reconcile request ReconciliationId(6)","v":0,"name":"crucible","level":30,"time":"2025-01-23T18:54:43.262579732Z","hostname":"w-01JJA7SE9SCYB3AF1MKA8WXYP0","pid":1244,"client":"2","":"downstairs","session_id":"37a75942-1a54-4ffb-ae5d-b0f17f1e77a9"}
5522025-01-23T18:54:43.512Z{"msg":"sending reconcile request ReconciliationId(10)","v":0,"name":"crucible","level":30,"time":"2025-01-23T18:54:43.266271208Z","hostname":"w-01JJA7SE9SCYB3AF1MKA8WXYP0","pid":1244,"client":"2","":"downstairs","session_id":"37a75942-1a54-4ffb-ae5d-b0f17f1e77a9"}
5532025-01-23T18:54:43.515Z{"msg":"sending reconcile request ReconciliationId(14)","v":0,"name":"crucible","level":30,"time":"2025-01-23T18:54:43.269706603Z","hostname":"w-01JJA7SE9SCYB3AF1MKA8WXYP0","pid":1244,"client":"2","":"downstairs","session_id":"37a75942-1a54-4ffb-ae5d-b0f17f1e77a9"}
5542025-01-23T18:54:43.519Z{"msg":"sending reconcile request ReconciliationId(18)","v":0,"name":"crucible","level":30,"time":"2025-01-23T18:54:43.273232728Z","hostname":"w-01JJA7SE9SCYB3AF1MKA8WXYP0","pid":1244,"client":"2","":"downstairs","session_id":"37a75942-1a54-4ffb-ae5d-b0f17f1e77a9"}
5552025-01-23T18:54:43.522Z{"msg":"done with reconciliation","v":0,"name":"crucible","level":30,"time":"2025-01-23T18:54:43.276287993Z","hostname":"w-01JJA7SE9SCYB3AF1MKA8WXYP0","pid":1244,"":"downstairs","":"downstairs","session_id":"37a75942-1a54-4ffb-ae5d-b0f17f1e77a9"}
5562025-01-23T18:54:43.522Z{"msg":"Transition from Reconcile to Active","v":0,"name":"crucible","level":30,"time":"2025-01-23T18:54:43.276316402Z","hostname":"w-01JJA7SE9SCYB3AF1MKA8WXYP0","pid":1244,"client":"0","":"downstairs","session_id":"37a75942-1a54-4ffb-ae5d-b0f17f1e77a9"}
5572025-01-23T18:54:43.522Z{"msg":"Transition from Reconcile to Active","v":0,"name":"crucible","level":30,"time":"2025-01-23T18:54:43.276331573Z","hostname":"w-01JJA7SE9SCYB3AF1MKA8WXYP0","pid":1244,"client":"1","":"downstairs","session_id":"37a75942-1a54-4ffb-ae5d-b0f17f1e77a9"}
5582025-01-23T18:54:43.522Z{"msg":"Transition from Reconcile to Active","v":0,"name":"crucible","level":30,"time":"2025-01-23T18:54:43.276344622Z","hostname":"w-01JJA7SE9SCYB3AF1MKA8WXYP0","pid":1244,"client":"2","":"downstairs","session_id":"37a75942-1a54-4ffb-ae5d-b0f17f1e77a9"}
5592025-01-23T18:54:43.522Z{"msg":"All required reconciliation work is completed","v":0,"name":"crucible","level":30,"time":"2025-01-23T18:54:43.276357713Z","hostname":"w-01JJA7SE9SCYB3AF1MKA8WXYP0","pid":1244,"session_id":"37a75942-1a54-4ffb-ae5d-b0f17f1e77a9"}
5602025-01-23T18:54:43.522Z{"msg":"Set Downstairs and Upstairs active after reconciliation","v":0,"name":"crucible","level":30,"time":"2025-01-23T18:54:43.276371322Z","hostname":"w-01JJA7SE9SCYB3AF1MKA8WXYP0","pid":1244,"session_id":"37a75942-1a54-4ffb-ae5d-b0f17f1e77a9"}
5612025-01-23T18:54:43.522Z{"msg":"3ac6dd39-e20c-4bef-acfe-72e4b2f9b18a is now active with session: 37a75942-1a54-4ffb-ae5d-b0f17f1e77a9","v":0,"name":"crucible","level":30,"time":"2025-01-23T18:54:43.276384213Z","hostname":"w-01JJA7SE9SCYB3AF1MKA8WXYP0","pid":1244,"session_id":"37a75942-1a54-4ffb-ae5d-b0f17f1e77a9"}
5622025-01-23T18:54:43.525Z{"msg":"The guest has finished waiting for activation with:33","v":0,"name":"crucible","level":30,"time":"2025-01-23T18:54:43.276396393Z","hostname":"w-01JJA7SE9SCYB3AF1MKA8WXYP0","pid":1244}
5632025-01-23T18:54:43.525Z{"msg":"The guest has requested activation with gen:33","v":0,"name":"crucible","level":30,"time":"2025-01-23T18:54:43.276452393Z","hostname":"w-01JJA7SE9SCYB3AF1MKA8WXYP0","pid":1244}
5642025-01-23T18:54:43.525Z{"msg":"3ac6dd39-e20c-4bef-acfe-72e4b2f9b18a active request set","v":0,"name":"crucible","level":30,"time":"2025-01-23T18:54:43.276485623Z","hostname":"w-01JJA7SE9SCYB3AF1MKA8WXYP0","pid":1244,"session_id":"623db029-411f-4023-8a4a-8acb2790d712"}
5652025-01-23T18:54:43.525Z{"msg":"sending connect oneshot to client","v":0,"name":"crucible","level":30,"time":"2025-01-23T18:54:43.276499563Z","hostname":"w-01JJA7SE9SCYB3AF1MKA8WXYP0","pid":1244,"client":"0","":"downstairs","session_id":"623db029-411f-4023-8a4a-8acb2790d712"}
5662025-01-23T18:54:43.525Z{"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-23T18:54:43.276513593Z","hostname":"w-01JJA7SE9SCYB3AF1MKA8WXYP0","pid":1244,"client":"0","":"downstairs","session_id":"623db029-411f-4023-8a4a-8acb2790d712"}
5672025-01-23T18:54:43.525Z{"msg":"sending connect oneshot to client","v":0,"name":"crucible","level":30,"time":"2025-01-23T18:54:43.276537663Z","hostname":"w-01JJA7SE9SCYB3AF1MKA8WXYP0","pid":1244,"client":"1","":"downstairs","session_id":"623db029-411f-4023-8a4a-8acb2790d712"}
5682025-01-23T18:54:43.525Z{"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-23T18:54:43.276557323Z","hostname":"w-01JJA7SE9SCYB3AF1MKA8WXYP0","pid":1244,"client":"1","":"downstairs","session_id":"623db029-411f-4023-8a4a-8acb2790d712"}
5692025-01-23T18:54:43.525Z{"msg":"sending connect oneshot to client","v":0,"name":"crucible","level":30,"time":"2025-01-23T18:54:43.276588313Z","hostname":"w-01JJA7SE9SCYB3AF1MKA8WXYP0","pid":1244,"client":"2","":"downstairs","session_id":"623db029-411f-4023-8a4a-8acb2790d712"}
5702025-01-23T18:54:43.525Z{"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-23T18:54:43.276613323Z","hostname":"w-01JJA7SE9SCYB3AF1MKA8WXYP0","pid":1244,"client":"2","":"downstairs","session_id":"623db029-411f-4023-8a4a-8acb2790d712"}
5712025-01-23T18:54:43.525Z{"msg":"connecting to 127.0.0.1:8860","v":0,"name":"crucible","level":30,"time":"2025-01-23T18:54:43.276635193Z","hostname":"w-01JJA7SE9SCYB3AF1MKA8WXYP0","pid":1244,"":"io task","client":"2","":"downstairs","session_id":"623db029-411f-4023-8a4a-8acb2790d712"}
5722025-01-23T18:54:43.526Z{"msg":"connecting to 127.0.0.1:8840","v":0,"name":"crucible","level":30,"time":"2025-01-23T18:54:43.276677433Z","hostname":"w-01JJA7SE9SCYB3AF1MKA8WXYP0","pid":1244,"":"io task","client":"0","":"downstairs","session_id":"623db029-411f-4023-8a4a-8acb2790d712"}
5732025-01-23T18:54:43.526Z{"msg":"connecting to 127.0.0.1:8850","v":0,"name":"crucible","level":30,"time":"2025-01-23T18:54:43.276705123Z","hostname":"w-01JJA7SE9SCYB3AF1MKA8WXYP0","pid":1244,"":"io task","client":"1","":"downstairs","session_id":"623db029-411f-4023-8a4a-8acb2790d712"}
5742025-01-23T18:54:43.526Z{"msg":"ds_connection connected from Ok(127.0.0.1:50481)","v":0,"name":"crucible","level":30,"time":"2025-01-23T18:54:43.276733883Z","hostname":"w-01JJA7SE9SCYB3AF1MKA8WXYP0","pid":1244,"":"io task","client":"0","":"downstairs","session_id":"623db029-411f-4023-8a4a-8acb2790d712"}
5752025-01-23T18:54:43.526Z{"msg":"ds_connection connected from Ok(127.0.0.1:34043)","v":0,"name":"crucible","level":30,"time":"2025-01-23T18:54:43.276759683Z","hostname":"w-01JJA7SE9SCYB3AF1MKA8WXYP0","pid":1244,"":"io task","client":"1","":"downstairs","session_id":"623db029-411f-4023-8a4a-8acb2790d712"}
5762025-01-23T18:54:43.526Z{"msg":"ds_connection connected from Ok(127.0.0.1:36999)","v":0,"name":"crucible","level":30,"time":"2025-01-23T18:54:43.276938063Z","hostname":"w-01JJA7SE9SCYB3AF1MKA8WXYP0","pid":1244,"":"io task","client":"2","":"downstairs","session_id":"623db029-411f-4023-8a4a-8acb2790d712"}
5772025-01-23T18:54:43.526Z{"msg":"version negotiation from state Connecting { state: WaitForPromote, mode: New }","v":0,"name":"crucible","level":30,"time":"2025-01-23T18:54:43.277190034Z","hostname":"w-01JJA7SE9SCYB3AF1MKA8WXYP0","pid":1244,"client":"0","":"downstairs","session_id":"623db029-411f-4023-8a4a-8acb2790d712"}
5782025-01-23T18:54:43.526Z{"msg":"version negotiation from state Connecting { state: WaitForPromote, mode: New }","v":0,"name":"crucible","level":30,"time":"2025-01-23T18:54:43.277248514Z","hostname":"w-01JJA7SE9SCYB3AF1MKA8WXYP0","pid":1244,"client":"1","":"downstairs","session_id":"623db029-411f-4023-8a4a-8acb2790d712"}
5792025-01-23T18:54:43.526Z{"msg":"version negotiation from state Connecting { state: WaitForPromote, mode: New }","v":0,"name":"crucible","level":30,"time":"2025-01-23T18:54:43.277418994Z","hostname":"w-01JJA7SE9SCYB3AF1MKA8WXYP0","pid":1244,"client":"2","":"downstairs","session_id":"623db029-411f-4023-8a4a-8acb2790d712"}
5802025-01-23T18:54:43.526Z{"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-23T18:54:43.277802485Z","hostname":"w-01JJA7SE9SCYB3AF1MKA8WXYP0","pid":1244,"client":"1","":"downstairs","session_id":"623db029-411f-4023-8a4a-8acb2790d712"}
5812025-01-23T18:54:43.526Z{"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-23T18:54:43.277854295Z","hostname":"w-01JJA7SE9SCYB3AF1MKA8WXYP0","pid":1244,"client":"0","":"downstairs","session_id":"623db029-411f-4023-8a4a-8acb2790d712"}
5822025-01-23T18:54:43.526Z{"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-23T18:54:43.277891945Z","hostname":"w-01JJA7SE9SCYB3AF1MKA8WXYP0","pid":1244,"client":"2","":"downstairs","session_id":"623db029-411f-4023-8a4a-8acb2790d712"}
5832025-01-23T18:54:43.526Z{"msg":"Waiting for more clients to be ready","v":0,"name":"crucible","level":30,"time":"2025-01-23T18:54:43.278164905Z","hostname":"w-01JJA7SE9SCYB3AF1MKA8WXYP0","pid":1244,"session_id":"623db029-411f-4023-8a4a-8acb2790d712"}
5842025-01-23T18:54:43.526Z{"msg":"Waiting for more clients to be ready","v":0,"name":"crucible","level":30,"time":"2025-01-23T18:54:43.278254855Z","hostname":"w-01JJA7SE9SCYB3AF1MKA8WXYP0","pid":1244,"session_id":"623db029-411f-4023-8a4a-8acb2790d712"}
5852025-01-23T18:54:43.526Z{"msg":"[0]R flush_numbers: [5322, 5322, 5322, 5322, 5322]","v":0,"name":"crucible","level":30,"time":"2025-01-23T18:54:43.278286625Z","hostname":"w-01JJA7SE9SCYB3AF1MKA8WXYP0","pid":1244,"":"downstairs","":"downstairs","session_id":"623db029-411f-4023-8a4a-8acb2790d712"}
5862025-01-23T18:54:43.526Z{"msg":"[0]R generation: [32, 32, 32, 32, 32]","v":0,"name":"crucible","level":30,"time":"2025-01-23T18:54:43.278310776Z","hostname":"w-01JJA7SE9SCYB3AF1MKA8WXYP0","pid":1244,"":"downstairs","":"downstairs","session_id":"623db029-411f-4023-8a4a-8acb2790d712"}
5872025-01-23T18:54:43.526Z{"msg":"[0]R dirty: [false, false, false, false, false]","v":0,"name":"crucible","level":30,"time":"2025-01-23T18:54:43.278339045Z","hostname":"w-01JJA7SE9SCYB3AF1MKA8WXYP0","pid":1244,"":"downstairs","":"downstairs","session_id":"623db029-411f-4023-8a4a-8acb2790d712"}
5882025-01-23T18:54:43.526Z{"msg":"[1]R flush_numbers: [5322, 5322, 5322, 5322, 5322]","v":0,"name":"crucible","level":30,"time":"2025-01-23T18:54:43.278363025Z","hostname":"w-01JJA7SE9SCYB3AF1MKA8WXYP0","pid":1244,"":"downstairs","":"downstairs","session_id":"623db029-411f-4023-8a4a-8acb2790d712"}
5892025-01-23T18:54:43.526Z{"msg":"[1]R generation: [32, 32, 32, 32, 32]","v":0,"name":"crucible","level":30Wait for a query_work_queue command to finish before sending IO
5902025-01-23T18:54:43.526Z,"time":"2025-01-23T18:54:43.278395196Z","hostname":"w-01JJA7SE9SCYB3AF1MKA8WXYP0","pid":1244,"":"downstairs","":"downstairs","session_id":"623db029-411f-4023-8a4a-8acb2790d712"}
5912025-01-23T18:54:43.526Z{"msg":"[1]R dirty: [false, false, false, false, false]","v":0,"name":"crucible","level":30,"time":"2025-01-23T18:54:43.278422286Z","hostname":"w-01JJA7SE9SCYB3AF1MKA8WXYP0","pid":1244,"":"downstairs","":"downstairs","session_id":"623db029-411f-4023-8a4a-8acb2790d712"}
5922025-01-23T18:54:43.526Z{"msg":"[2]R flush_numbers: [5322, 5322, 5322, 5322, 5322]","v":0,"name":"crucible","level":30,"time":"2025-01-23T18:54:43.278446486Z","hostname":"w-01JJA7SE9SCYB3AF1MKA8WXYP0","pid":1244,"":"downstairs","":"downstairs","session_id":"623db029-411f-4023-8a4a-8acb2790d712"}
5932025-01-23T18:54:43.526Z{"msg":"[2]R generation: [32, 32, 32, 32, 32]","v":0,"name":"crucible","level":30,"time":"2025-01-23T18:54:43.278478166Z","hostname":"w-01JJA7SE9SCYB3AF1MKA8WXYP0","pid":1244,"":"downstairs","":"downstairs","session_id":"623db029-411f-4023-8a4a-8acb2790d712"}
5942025-01-23T18:54:43.526Z{"msg":"[2]R dirty: [false, false, false, false, false]","v":0,"name":"crucible","level":30,"time":"2025-01-23T18:54:43.278502286Z","hostname":"w-01JJA7SE9SCYB3AF1MKA8WXYP0","pid":1244,"":"downstairs","":"downstairs","session_id":"623db029-411f-4023-8a4a-8acb2790d712"}
5952025-01-23T18:54:43.526Z{"msg":"Max found gen is 33","v":0,"name":"crucible","level":30,"time":"2025-01-23T18:54:43.278529086Z","hostname":"w-01JJA7SE9SCYB3AF1MKA8WXYP0","pid":1244,"":"downstairs","":"downstairs","session_id":"623db029-411f-4023-8a4a-8acb2790d712"}
5962025-01-23T18:54:43.526Z{"msg":"Generation requested: 33 >= found:33","v":0,"name":"crucible","level":30,"time":"2025-01-23T18:54:43.278552006Z","hostname":"w-01JJA7SE9SCYB3AF1MKA8WXYP0","pid":1244,"":"downstairs","":"downstairs","session_id":"623db029-411f-4023-8a4a-8acb2790d712"}
5972025-01-23T18:54:43.526Z{"msg":"Next flush: 5323","v":0,"name":"crucible","level":30,"time":"2025-01-23T18:54:43.278583526Z","hostname":"w-01JJA7SE9SCYB3AF1MKA8WXYP0","pid":1244,"":"downstairs","":"downstairs","session_id":"623db029-411f-4023-8a4a-8acb2790d712"}
5982025-01-23T18:54:43.526Z{"msg":"All extents match","v":0,"name":"crucible","level":30,"time":"2025-01-23T18:54:43.278607936Z","hostname":"w-01JJA7SE9SCYB3AF1MKA8WXYP0","pid":1244,"":"downstairs","":"downstairs","session_id":"623db029-411f-4023-8a4a-8acb2790d712"}
5992025-01-23T18:54:43.527Z{"msg":"No downstairs reconciliation required","v":0,"name":"crucible","level":30,"time":"2025-01-23T18:54:43.278631716Z","hostname":"w-01JJA7SE9SCYB3AF1MKA8WXYP0","pid":1244,"session_id":"623db029-411f-4023-8a4a-8acb2790d712"}
6002025-01-23T18:54:43.527Z{"msg":"Transition from WaitQuorum to Active","v":0,"name":"crucible","level":30,"time":"2025-01-23T18:54:43.278663086Z","hostname":"w-01JJA7SE9SCYB3AF1MKA8WXYP0","pid":1244,"client":"0","":"downstairs","session_id":"623db029-411f-4023-8a4a-8acb2790d712"}
6012025-01-23T18:54:43.527Z{"msg":"Transition from WaitQuorum to Active","v":0,"name":"crucible","level":30,"time":"2025-01-23T18:54:43.278687296Z","hostname":"w-01JJA7SE9SCYB3AF1MKA8WXYP0","pid":1244,"client":"1","":"downstairs","session_id":"623db029-411f-4023-8a4a-8acb2790d712"}
6022025-01-23T18:54:43.527Z{"msg":"Transition from WaitQuorum to Active","v":0,"name":"crucible","level":30,"time":"2025-01-23T18:54:43.278717226Z","hostname":"w-01JJA7SE9SCYB3AF1MKA8WXYP0","pid":1244,"client":"2","":"downstairs","session_id":"623db029-411f-4023-8a4a-8acb2790d712"}
6032025-01-23T18:54:43.527Z{"msg":"All required reconciliation work is completed","v":0,"name":"crucible","level":30,"time":"2025-01-23T18:54:43.278740896Z","hostname":"w-01JJA7SE9SCYB3AF1MKA8WXYP0","pid":1244,"session_id":"623db029-411f-4023-8a4a-8acb2790d712"}
6042025-01-23T18:54:43.527Z{"msg":"Set Downstairs and Upstairs active after reconciliation","v":0,"name":"crucible","level":30,"time":"2025-01-23T18:54:43.278767256Z","hostname":"w-01JJA7SE9SCYB3AF1MKA8WXYP0","pid":1244,"session_id":"623db029-411f-4023-8a4a-8acb2790d712"}
6052025-01-23T18:54:43.527Z{"msg":"3ac6dd39-e20c-4bef-acfe-72e4b2f9b18a is now active with session: 623db029-411f-4023-8a4a-8acb2790d712","v":0,"name":"crucible","level":30,"time":"2025-01-23T18:54:43.278789776Z","hostname":"Disk: sv:2 bs:4096 ts:409600 tb:100 max_io:100 or 409600
6062025-01-23T18:54:43.527Zw-01JJA7SE9SCYB3AF1MKA8WXYP0","pid":1244,"session_id":"623db029-411f-4023-8a4a-8acb2790d712"}
6072025-01-23T18:54:43.527Z{"msg":"Set Active after no reconciliation","v":0,"name":"crucible","level":30,"time":"2025-01-23T18:54:43.278822556Z","hostname":"w-01JJA7SE9SCYB3AF1MKA8WXYP0","pid":1244,"session_id":"623db029-411f-4023-8a4a-8acb2790d712"}
6082025-01-23T18:54:43.527Z{"msg":"The guest has finished waiting for activation with:33","v":0,"name":"crucible","level":30,"time":"2025-01-23T18:54:43.278844306Z","hostname":"w-01JJA7SE9SCYB3AF1MKA8WXYP0","pid":1244}
6092025-01-23T18:54:43.527ZLoading write count information from file "/var/tmp/test_up-build/verify_file"
6102025-01-23T18:54:43.527ZRead and Verify all blocks (0..100 range:true)
6112025-01-23T18:54:43.604ZWrote out file "/var/tmp/test_up-build/verify_file"
6122025-01-23T18:54:43.604ZVerify test completed
6132025-01-23T18:54:43.607ZWrote out file "/var/tmp/test_up-build/verify_file"
6142025-01-23T18:54:43.607ZCLIENT: Tests done. All submitted work has been ACK'd
6152025-01-23T18:54:43.607Z----------------------------------------------------------------
6162025-01-23T18:54:43.607Z Crucible gen:33 GIO:true work queues: Upstairs:0 downstairs:1
6172025-01-23T18:54:43.607ZStates: Active Active Active
6182025-01-23T18:54:43.607ZJOBID ACK TYPE BKS/EXT DS:0 DS:1 DS:2 REPLAY
6192025-01-23T18:54:43.607Z 1000 Acked Read 50 Done Done Done false
6202025-01-23T18:54:43.607Z STATES DS:0 DS:1 DS:2 TOTAL
6212025-01-23T18:54:43.607Z Sent 0 0 0 0
6222025-01-23T18:54:43.607Z Done 1 1 1 3
6232025-01-23T18:54:43.607Z Skipped 0 0 0 0
6242025-01-23T18:54:43.607Z Error 0 0 0 0
6252025-01-23T18:54:43.607ZLast Flush: None None None
6262025-01-23T18:54:43.607ZDownstairs last five completed:
6272025-01-23T18:54:43.607ZUpstairs last five completed: 1000
6282025-01-23T18:54:43.607Z----------------------------------------------------------------
6292025-01-23T18:54:43.607Z Crucible gen:33 GIO:true work queues: Upstairs:0 downstairs:1
6302025-01-23T18:54:43.607ZStates: Active Active Active
6312025-01-23T18:54:43.607ZJOBID ACK TYPE BKS/EXT DS:0 DS:1 DS:2 REPLAY
6322025-01-23T18:54:43.607Z 1000 Acked Read 50 Done Done Done false
6332025-01-23T18:54:43.607Z STATES DS:0 DS:1 DS:2 TOTAL
6342025-01-23T18:54:43.607Z Sent 0 0 0 0
6352025-01-23T18:54:43.607Z Done 1 1 1 3
6362025-01-23T18:54:43.607Z Skipped 0 0 0 0
6372025-01-23T18:54:43.607Z Error 0 0 0 0
6382025-01-23T18:54:43.607ZLast Flush: None None None
6392025-01-23T18:54:43.607ZDownstairs last five completed:
6402025-01-23T18:54:43.608ZUpstairs last five completed: 1000
6412025-01-23T18:54:43.608ZCLIENT: Up:0 ds:2 act:6
6422025-01-23T18:54:47.606Z----------------------------------------------------------------
6432025-01-23T18:54:47.607Z Crucible gen:33 GIO:true work queues: Upstairs:0 downstairs:0
6442025-01-23T18:54:47.607ZDownstairs last five completed: 1001 1000
6452025-01-23T18:54:47.607ZUpstairs last five completed: 1001 1000
6462025-01-23T18:54:47.607Z----------------------------------------------------------------
6472025-01-23T18:54:47.607Z Crucible gen:33 GIO:true work queues: Upstairs:0 downstairs:0
6482025-01-23T18:54:47.607ZDownstairs last five completed: 1001 1000
6492025-01-23T18:54:47.607ZUpstairs last five completed: 1001 1000
6502025-01-23T18:54:47.610ZCLIENT: Up:0 ds:0 act:6
6512025-01-23T18:54:47.610ZCLIENT: All crucible jobs finished, exiting program
6522025-01-23T18:54:47.610Z{"msg":"Guest handle has been dropped","v":0,"name":"crucible","level":40,"time":"2025-01-23T18:54:47.360961079Z","hostname":"w-01JJA7SE9SCYB3AF1MKA8WXYP0","pid":1244}
6532025-01-23T18:54:47.614ZRepair part 2 passed
6542025-01-23T18:54:47.616Z/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-23T18:54:47.632ZEXT BLOCKS GEN0 GEN1 GEN2 FL0 FL1 FL2 D0 D1 D2 DIFF
6562025-01-23T18:54:47.632Z 0 000-009 32 32 32 4002 4002 4002 F F F
6572025-01-23T18:54:47.632Z 1 010-019 32 32 32 4002 4002 4002 F F F
6582025-01-23T18:54:47.632Z 2 020-029 32 32 32 4002 4002 4002 F F F
6592025-01-23T18:54:47.632Z 3 030-039 32 32 32 4002 4002 4002 F F F
6602025-01-23T18:54:47.634Z 4 040-049 32 32 32 4002 4002 4002 F F F
6612025-01-23T18:54:47.634ZMax gen: 32, Max flush: 4002
6622025-01-23T18:54:47.637Zdump test passed
6632025-01-23T18:54:47.637Z/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-23T18:54:47.653Z Extent 1
6652025-01-23T18:54:47.655ZGEN 32 32 32
6662025-01-23T18:54:47.655ZFLUSH_ID 4002 4002 4002
6672025-01-23T18:54:47.655ZDIRTY
6682025-01-23T18:54:47.655Z
6692025-01-23T18:54:47.655ZBLOCK D0 D1 D2 C0 C1 C2 DIFF
6702025-01-23T18:54:47.655Z010 A A A A A A
6712025-01-23T18:54:47.658Z011 A A A A A A
6722025-01-23T18:54:47.658Z012 A A A A A A
6732025-01-23T18:54:47.661Z013 A A A A A A
6742025-01-23T18:54:47.661Z014 A A A A A A
6752025-01-23T18:54:47.663Z015 A A A A A A
6762025-01-23T18:54:47.663Z016 A A A A A A
6772025-01-23T18:54:47.666Z017 A A A A A A
6782025-01-23T18:54:47.666Z018 A A A A A A
6792025-01-23T18:54:47.669Z019 A A A A A A
6802025-01-23T18:54:47.671Zdump extent test passed
6812025-01-23T18:54:47.673Z/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-23T18:54:47.687ZExtent 2 Block in extent 0 Actual block 20
6832025-01-23T18:54:47.689Z
6842025-01-23T18:54:47.689Z DATA SHA256 VER
6852025-01-23T18:54:47.690Z------ ---------------------------------------------------------------- ---
6862025-01-23T18:54:47.692Z 0 dd2a8997239aa2031b4397230eb1efd818a5b932154a836f18e8c8e4fedebecc A
6872025-01-23T18:54:47.692Z 1 dd2a8997239aa2031b4397230eb1efd818a5b932154a836f18e8c8e4fedebecc A
6882025-01-23T18:54:47.692Z 2 dd2a8997239aa2031b4397230eb1efd818a5b932154a836f18e8c8e4fedebecc A
6892025-01-23T18:54:47.692Z
6902025-01-23T18:54:47.692ZNONCES 0 1 2 DIFF
6912025-01-23T18:54:47.692Z------ ------------------------ ------------------------ ------------------------ -----
6922025-01-23T18:54:47.692Z 0 2d5dfb433ccc7b271085cc73 2d5dfb433ccc7b271085cc73 2d5dfb433ccc7b271085cc73
6932025-01-23T18:54:47.692Z
6942025-01-23T18:54:47.692Z TAGS 0 1 2 DIFF
6952025-01-23T18:54:47.692Z------ -------------------------------- -------------------------------- -------------------------------- -----
6962025-01-23T18:54:47.693Z 0 b1e0f9b50f459c1c53937e8ddcde323d b1e0f9b50f459c1c53937e8ddcde323d b1e0f9b50f459c1c53937e8ddcde323d
6972025-01-23T18:54:47.693Z
6982025-01-23T18:54:47.693ZHASHES 0 1 2 DIFF
6992025-01-23T18:54:47.693Z------ ---------------- ---------------- ---------------- -----
7002025-01-23T18:54:47.693Z
7012025-01-23T18:54:47.695Zdump block test passed
7022025-01-23T18:54:47.695ZInitial upstairs tests have completed, stopping all downstairs
7032025-01-23T18:54:52.761ZCreating 7 larger downstairs regions
7042025-01-23T18:54:52.943ZStarting 7 downstairs
7052025-01-23T18:54:57.950Zdsc restarted at PID: 1260
7062025-01-23T18:54:58.336ZNow do the replace-reconcile test
7072025-01-23T18:54:58.390ZUsing 8870 for the replacement port
7082025-01-23T18:57:35.703ZCompleted test: replace-reconcile
7092025-01-23T18:57:35.706ZNow do the replace-before-active test
7102025-01-23T19:01:09.511ZCompleted test: replace-before-active
7112025-01-23T19:01:09.514ZAll tests have completed, stopping all downstairs
7122025-01-23T19:01:09.574Z
7132025-01-23T19:01:09.574ZAll Tests have passed
7142025-01-23T19:01:09.577Z13:21 Test duration
7152025-01-23T19:01:09.577Z
7162025-01-23T19:01:09.577Zreal 13:20.614724755
7172025-01-23T19:01:09.577Zuser 18:33.823861590
7182025-01-23T19:01:09.577Zsys 24.281622433
7192025-01-23T19:01:09.577Ztrap 0.527278653
7202025-01-23T19:01:09.577Ztflt 0.030170602
7212025-01-23T19:01:09.577Zdflt 0.032996566
7222025-01-23T19:01:09.577Zkflt 0.001206924
7232025-01-23T19:01:09.577Zlock 25:23:43.313876067
7242025-01-23T19:01:09.577Zslp 1:14:03.406281485
7252025-01-23T19:01:09.577Zlat 2:01.149276440
7262025-01-23T19:01:09.577Zstop 0.264115162
7272025-01-23T19:01:09.577Z+ echo 'test-up-2region-encrypted ends'
7282025-01-23T19:01:09.577Ztest-up-2region-encrypted ends
7292025-01-23T19:01:14.580Zprocess exited: duration 808816 ms, exit code 0
7302025-01-23T19:01:14.580Zexec warning: : stdio descriptors remain open after task exit; waiting 60 seconds for them to close
7312025-01-23T19:02:14.609Zexec warning: : stdout descriptor may be held open by a background process; giving up!
7322025-01-23T19:02:14.609Zexec warning: : stderr descriptor may be held open by a background process; giving up!
 
7332025-01-23T19:02:14.619Zfound 17 output files
7342025-01-23T19:02:14.619Zuploading: /tmp/test_up-build/dsc-out.txt (48697 bytes)
7352025-01-23T19:02:15.630Zuploaded: /tmp/test_up-build/dsc-out.txt
7362025-01-23T19:02:15.639Zuploading: /tmp/test_up-build/test_up_out.txt (8508623 bytes)
7372025-01-23T19:02:16.722Zuploaded: /tmp/test_up-build/test_up_out.txt
7382025-01-23T19:02:16.722Zuploading: /tmp/test_up-build/dsc/downstairs-8810.txt (147260 bytes)
7392025-01-23T19:02:17.734Zuploaded: /tmp/test_up-build/dsc/downstairs-8810.txt
7402025-01-23T19:02:17.737Zuploading: /tmp/test_up-build/dsc/downstairs-8820.txt (144635 bytes)
7412025-01-23T19:02:18.745Zuploaded: /tmp/test_up-build/dsc/downstairs-8820.txt
7422025-01-23T19:02:18.748Zuploading: /tmp/test_up-build/dsc/downstairs-8830.txt (251036 bytes)
7432025-01-23T19:02:19.757Zuploaded: /tmp/test_up-build/dsc/downstairs-8830.txt
7442025-01-23T19:02:19.758Zuploading: /tmp/test_up-build/dsc/downstairs-8840.txt (139439 bytes)
7452025-01-23T19:02:20.769Zuploaded: /tmp/test_up-build/dsc/downstairs-8840.txt
7462025-01-23T19:02:20.769Zuploading: /tmp/test_up-build/dsc/downstairs-8850.txt (358090 bytes)
7472025-01-23T19:02:21.784Zuploaded: /tmp/test_up-build/dsc/downstairs-8850.txt
7482025-01-23T19:02:21.786Zuploading: /tmp/test_up-build/dsc/downstairs-8860.txt (33778 bytes)
7492025-01-23T19:02:22.794Zuploaded: /tmp/test_up-build/dsc/downstairs-8860.txt
7502025-01-23T19:02:22.794Zuploading: /tmp/test_up-build/dsc/downstairs-8870.txt (735707 bytes)
7512025-01-23T19:02:23.812Zuploaded: /tmp/test_up-build/dsc/downstairs-8870.txt
7522025-01-23T19:02:23.815Zuploading: /tmp/debug/df.txt (1270 bytes)
7532025-01-23T19:02:24.820Zuploaded: /tmp/debug/df.txt
7542025-01-23T19:02:24.821Zuploading: /tmp/debug/dtrace.txt (994874 bytes)
7552025-01-23T19:02:25.841Zuploaded: /tmp/debug/dtrace.txt
7562025-01-23T19:02:25.841Zuploading: /tmp/debug/iostat.txt (259857 bytes)
7572025-01-23T19:02:25.850Zupload warning: file "/tmp/debug/iostat.txt" changed size mid upload: 259857 -> 263157
7582025-01-23T19:02:26.856Zuploaded: /tmp/debug/iostat.txt
7592025-01-23T19:02:26.856Zuploading: /tmp/debug/mpstat.txt (631322 bytes)
7602025-01-23T19:02:26.868Zupload warning: file "/tmp/debug/mpstat.txt" changed size mid upload: 631322 -> 640070
7612025-01-23T19:02:27.874Zuploaded: /tmp/debug/mpstat.txt
7622025-01-23T19:02:27.877Zuploading: /tmp/debug/paging.txt (113336 bytes)
7632025-01-23T19:02:27.880Zupload warning: file "/tmp/debug/paging.txt" changed size mid upload: 113336 -> 114989
7642025-01-23T19:02:28.886Zuploaded: /tmp/debug/paging.txt
7652025-01-23T19:02:28.889Zuploading: /tmp/debug/prstat.txt (1228933 bytes)
7662025-01-23T19:02:28.911Zupload warning: file "/tmp/debug/prstat.txt" changed size mid upload: 1228933 -> 1246996
7672025-01-23T19:02:29.917Zuploaded: /tmp/debug/prstat.txt
7682025-01-23T19:02:29.924Zuploading: /tmp/debug/psrinfo.txt (1528 bytes)
7692025-01-23T19:02:30.930Zuploaded: /tmp/debug/psrinfo.txt
7702025-01-23T19:02:30.930Zuploading: /tmp/debug/upstairs-info.txt (177210 bytes)
7712025-01-23T19:02:31.942Zuploaded: /tmp/debug/upstairs-info.txt