01JJ4QVH21XPVQAAD1BYWT2PH6: 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: 01JJ4QVT6Y1H49M92DJ6PEMQJ3

Tags:

Artefacts:

Output:

SEQ GLOBAL TIME DETAILS
12025-01-21T15:45:36.780Zjob dependencies complete; ready to run (waiting for 13 m 38 s)
22025-01-21T15:46:38.943Zjob assigned to worker 01JJ4RN3GTHENBNQ4DERAKAPSN [factory aws, i-04d6a63f1f4e05b0d] (queued for 1 m 2 s)
32025-01-21T15:46:46.916Zdownloading input: /input/build/work/bins/crucible-downstairs.gz
42025-01-21T15:46:48.310Zdownloaded input: /input/build/work/bins/crucible-downstairs.gz
52025-01-21T15:46:48.310Zdownloading input: /input/build/work/bins/crucible-hammer.gz
62025-01-21T15:46:49.370Zdownloaded input: /input/build/work/bins/crucible-hammer.gz
72025-01-21T15:46:49.370Zdownloading input: /input/build/work/bins/crutest.gz
82025-01-21T15:46:50.515Zdownloaded input: /input/build/work/bins/crutest.gz
92025-01-21T15:46:50.515Zdownloading input: /input/build/work/bins/dsc.gz
102025-01-21T15:46:51.184Zdownloaded input: /input/build/work/bins/dsc.gz
112025-01-21T15:46:51.187Zdownloading input: /input/build/work/scripts/perf-downstairs-tick.d
122025-01-21T15:46:51.202Zdownloaded input: /input/build/work/scripts/perf-downstairs-tick.d
132025-01-21T15:46:51.202Zdownloading input: /input/build/work/scripts/test_ds.sh
142025-01-21T15:46:51.220Zdownloaded input: /input/build/work/scripts/test_ds.sh
152025-01-21T15:46:51.220Zdownloading input: /input/build/work/scripts/test_live_repair.sh
162025-01-21T15:46:51.239Zdownloaded input: /input/build/work/scripts/test_live_repair.sh
172025-01-21T15:46:51.239Zdownloading input: /input/build/work/scripts/test_repair.sh
182025-01-21T15:46:51.256Zdownloaded input: /input/build/work/scripts/test_repair.sh
192025-01-21T15:46:51.256Zdownloading input: /input/build/work/scripts/test_replay.sh
202025-01-21T15:46:51.272Zdownloaded input: /input/build/work/scripts/test_replay.sh
212025-01-21T15:46:51.272Zdownloading input: /input/build/work/scripts/test_up.sh
222025-01-21T15:46:51.292Zdownloaded input: /input/build/work/scripts/test_up.sh
232025-01-21T15:46:51.292Zdownloading input: /input/build/work/scripts/upstairs_info.d
242025-01-21T15:46:51.309Zdownloaded input: /input/build/work/scripts/upstairs_info.d
252025-01-21T15:46:51.312Zdownloading input: /input/build/tmp/cargo-test-out.log
262025-01-21T15:46:52.040Zdownloaded input: /input/build/tmp/cargo-test-out.log
 
272025-01-21T15:46:52.041Zstarting task 0: "setup"
282025-01-21T15:46:52.054Z++ uname -s
292025-01-21T15:46:52.057Z+ kern=SunOS
302025-01-21T15:46:52.057Z+ case "$kern" in
312025-01-21T15:46:52.057Z+ groupadd -g 12345 build
322025-01-21T15:46:52.061Z+ useradd -u 12345 -g build -d /home/build -s /bin/bash -c build -P 'Primary Administrator' build
332025-01-21T15:46:54.068Z+ zfs create -o mountpoint=/work rpool/work
342025-01-21T15:46:54.324Z++ awk '$2 == "/home" { print $3 }' /etc/mnttab
352025-01-21T15:46:54.327Z+ home_fs=zfs
362025-01-21T15:46:54.327Z+ [[ zfs == autofs ]]
372025-01-21T15:46:54.327Z+ mkdir -p /home/build
382025-01-21T15:46:54.330Z+ chown build:build /home/build /work
392025-01-21T15:46:56.331Z+ chmod 0700 /home/build /work
402025-01-21T15:46:56.335Zprocess exited: duration 4292 ms, exit code 0
 
412025-01-21T15:46:56.342Zstarting task 1: "authentication"
422025-01-21T15:46:56.361Zprocess exited: duration 18 ms, exit code 0
 
432025-01-21T15:46:56.367Zstarting task 2: "build"
442025-01-21T15:46:56.372Z+ banner cores
452025-01-21T15:46:56.388Z
462025-01-21T15:46:56.388Z #### #### ##### ###### ####
472025-01-21T15:46:56.388Z # # # # # # # #
482025-01-21T15:46:56.388Z # # # # # ##### ####
492025-01-21T15:46:56.388Z # # # ##### # #
502025-01-21T15:46:56.392Z # # # # # # # # #
512025-01-21T15:46:56.392Z #### #### # # ###### ####
522025-01-21T15:46:56.392Z
532025-01-21T15:46:56.392Z+ pfexec coreadm -i /tmp/core.%f.%p -g /tmp/core.%f.%p -e global -e log -e proc-setid -e global-setid
542025-01-21T15:46:56.399Z+ banner unpack
552025-01-21T15:46:56.402Z
562025-01-21T15:46:56.402Z # # # # ##### ## #### # #
572025-01-21T15:46:56.402Z # # ## # # # # # # # # #
582025-01-21T15:46:56.402Z # # # # # # # # # # ####
592025-01-21T15:46:56.402Z # # # # # ##### ###### # # #
602025-01-21T15:46:56.402Z # # # ## # # # # # # #
612025-01-21T15:46:56.402Z #### # # # # # #### # #
622025-01-21T15:46:56.403Z
632025-01-21T15:46:56.403Z+ mkdir -p /var/tmp/bins
642025-01-21T15:46:56.405Z+ for t in "$input/bins/"*.gz
652025-01-21T15:46:56.405Z++ basename /input/build/work/bins/crucible-downstairs.gz
662025-01-21T15:46:56.405Z+ b=crucible-downstairs.gz
672025-01-21T15:46:56.405Z+ b=crucible-downstairs
682025-01-21T15:46:56.405Z+ gunzip
692025-01-21T15:46:58.652Z+ chmod +x /var/tmp/bins/crucible-downstairs
702025-01-21T15:46:58.655Z+ for t in "$input/bins/"*.gz
712025-01-21T15:46:58.658Z++ basename /input/build/work/bins/crucible-hammer.gz
722025-01-21T15:46:58.658Z+ b=crucible-hammer.gz
732025-01-21T15:46:58.658Z+ b=crucible-hammer
742025-01-21T15:46:58.658Z+ gunzip
752025-01-21T15:47:00.785Z+ chmod +x /var/tmp/bins/crucible-hammer
762025-01-21T15:47:00.788Z+ for t in "$input/bins/"*.gz
772025-01-21T15:47:00.791Z++ basename /input/build/work/bins/crutest.gz
782025-01-21T15:47:00.791Z+ b=crutest.gz
792025-01-21T15:47:00.791Z+ b=crutest
802025-01-21T15:47:00.791Z+ gunzip
812025-01-21T15:47:03.226Z+ chmod +x /var/tmp/bins/crutest
822025-01-21T15:47:03.229Z+ for t in "$input/bins/"*.gz
832025-01-21T15:47:03.232Z++ basename /input/build/work/bins/dsc.gz
842025-01-21T15:47:03.234Z+ b=dsc.gz
852025-01-21T15:47:03.234Z+ b=dsc
862025-01-21T15:47:03.234Z+ gunzip
872025-01-21T15:47:04.573Z+ chmod +x /var/tmp/bins/dsc
882025-01-21T15:47:04.576Z+ export BINDIR=/var/tmp/bins
892025-01-21T15:47:04.576Z+ BINDIR=/var/tmp/bins
902025-01-21T15:47:04.576Z+ jobpid=1144
912025-01-21T15:47:04.576Z+ echo 'Setup debug logging'
922025-01-21T15:47:04.576ZSetup debug logging
932025-01-21T15:47:04.576Z+ mkdir /tmp/debug
942025-01-21T15:47:04.579Z+ sleep 3600
952025-01-21T15:47:04.579Z+ psrinfo -v
962025-01-21T15:47:04.582Z+ df -h
972025-01-21T15:47:04.589Z+ prstat -d d -mLc 1
982025-01-21T15:47:04.593Z+ iostat -T d -xn 1
992025-01-21T15:47:04.593Z+ mpstat -T d 1
1002025-01-21T15:47:04.593Z+ vmstat -T d -p 1
1012025-01-21T15:47:04.593Z+ pfexec dtrace -Z -s /input/build/work/scripts/perf-downstairs-tick.d
1022025-01-21T15:47:04.596Z+ banner test_up_2r_encrypted
1032025-01-21T15:47:04.596Z+ pfexec dtrace -Z -s /input/build/work/scripts/upstairs_info.d
1042025-01-21T15:47:04.596Z #####
1052025-01-21T15:47:04.596Z ##### ###### #### ##### # # ##### # # #####
1062025-01-21T15:47:04.596Z # # # # # # # # # # #
1072025-01-21T15:47:04.596Z # ##### #### # # # # # ##### # #
1082025-01-21T15:47:04.596Z # # # # # # ##### # #####
1092025-01-21T15:47:04.596Z # # # # # # # # # # #
1102025-01-21T15:47:04.596Z # ###### #### # ####### #### # ####### ####### # #
1112025-01-21T15:47:04.596Z
1122025-01-21T15:47:04.596Z+ ptime -m bash /input/build/work/scripts/test_up.sh -r 2 -N encrypted
1132025-01-21T15:47:04.608Z/input/build/work
1142025-01-21T15:47:04.632ZUsing 2 region sets
1152025-01-21T15:47:04.632ZTurn off color for downstairs dump
1162025-01-21T15:47:04.650ZUpstairs using key: wR+F1olsh8k3doPjXFwJ2Zs1S4Z3J9BWk6o9Zds2Hdg=
1172025-01-21T15:47:04.653Zdsc output goes to /tmp/test_up-build/dsc-out.txt
1182025-01-21T15:47:04.653ZCreating 6 downstairs regions
1192025-01-21T15:47:05.013ZStarting 6 downstairs
1202025-01-21T15:47:05.016Zdsc started at PID: 1192
1212025-01-21T15:47:10.354ZDisable automatic restart on all downstairs
1222025-01-21T15:47:10.409Z
1232025-01-21T15:47:10.409ZBegin tests, output goes to /tmp/test_up-build/test_up_out.txt
1242025-01-21T15:47:10.413ZRunning test: span
1252025-01-21T15:47:14.593ZCompleted test: span
1262025-01-21T15:47:19.601ZRunning test: big
1272025-01-21T15:47:24.179ZCompleted test: big
1282025-01-21T15:47:29.187ZRunning test: dep
1292025-01-21T15:48:02.860ZCompleted test: dep
1302025-01-21T15:48:07.867ZRunning test: balloon
1312025-01-21T15:52:22.505ZCompleted test: balloon
1322025-01-21T15:52:27.512ZRunning test: deactivate
1332025-01-21T15:53:22.187ZCompleted test: deactivate
1342025-01-21T15:53:27.194ZRunning hammer
1352025-01-21T15:53:44.888ZRun repair tests
1362025-01-21T15:53:44.892Z/var/tmp/bins/crutest fill -g 31 -q --key wR+F1olsh8k3doPjXFwJ2Zs1S4Z3J9BWk6o9Zds2Hdg= --dsc 127.0.0.1:9998 --verify-out /var/tmp/test_up-build/verify_file
1372025-01-21T15:53:44.950Z{"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-21T15:53:44.48336406Z","hostname":"w-01JJ4RN3GTHENBNQ4DERAKAPSN","pid":1235,"task":"crutest"}
1382025-01-21T15:53:44.954Z{"msg":"dsc has 6 regions. This means 2 sub_volumes","v":0,"name":"crucible","level":30,"time":"2025-01-21T15:53:44.483933259Z","hostname":"w-01JJ4RN3GTHENBNQ4DERAKAPSN","pid":1235,"task":"crutest"}
1392025-01-21T15:53:44.954Z{"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-21T15:53:44.48548379Z","hostname":"w-01JJ4RN3GTHENBNQ4DERAKAPSN","pid":1235,"task":"crutest"}
1402025-01-21T15:53:44.954Z{"msg":"Upstairs starts","v":0,"name":"crucible","level":30,"time":"2025-01-21T15:53:44.485674452Z","hostname":"w-01JJ4RN3GTHENBNQ4DERAKAPSN","pid":1235}
1412025-01-21T15:53:44.954Z{"msg":"Crucible Version: BuildInfo {\n version: \"0.0.1\",\n git_sha: \"5c2b227300b758c153f33da870809d67a5160dae\",\n git_commit_timestamp: \"2025-01-21T15:31:20.000000000Z\",\n git_branch: \"mkeeter/always-check-live-repair\",\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-21T15:53:44.485721461Z","hostname":"w-01JJ4RN3GTHENBNQ4DERAKAPSN","pid":1235}
1422025-01-21T15:53:44.954Z{"msg":"Upstairs <-> Downstairs Message Version: 12","v":0,"name":"crucible","level":30,"time":"2025-01-21T15:53:44.48575186Z","hostname":"w-01JJ4RN3GTHENBNQ4DERAKAPSN","pid":1235}
1432025-01-21T15:53:44.954Z{"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-21T15:53:44.485768409Z","hostname":"w-01JJ4RN3GTHENBNQ4DERAKAPSN","pid":1235}
1442025-01-21T15:53:44.954Z{"msg":"Crucible a9d7f264-c321-49b9-aed8-ffda226931b6 has session id: ec2bb7dd-941f-47d9-9b9c-fa81586ecc65","v":0,"name":"crucible","level":30,"time":"2025-01-21T15:53:44.486381785Z","hostname":"w-01JJ4RN3GTHENBNQ4DERAKAPSN","pid":1235,"session_id":"ec2bb7dd-941f-47d9-9b9c-fa81586ecc65"}
1452025-01-21T15:53:44.954Z{"msg":"Upstairs opts: Upstairs UUID: a9d7f264-c321-49b9-aed8-ffda226931b6, 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-21T15:53:44.486447103Z","hostname":"w-01JJ4RN3GTHENBNQ4DERAKAPSN","pid":1235,"session_id":"ec2bb7dd-941f-47d9-9b9c-fa81586ecc65"}
1462025-01-21T15:53:44.954Z{"msg":"Crucible stats registered with UUID: a9d7f264-c321-49b9-aed8-ffda226931b6","v":0,"name":"crucible","level":30,"time":"2025-01-21T15:53:44.486481042Z","hostname":"w-01JJ4RN3GTHENBNQ4DERAKAPSN","pid":1235,"session_id":"ec2bb7dd-941f-47d9-9b9c-fa81586ecc65"}
1472025-01-21T15:53:44.954Z{"msg":"could not find Downstairs address for Nexus","v":0,"name":"crucible","level":40,"time":"2025-01-21T15:53:44.486505331Z","hostname":"w-01JJ4RN3GTHENBNQ4DERAKAPSN","pid":1235,"session_id":"ec2bb7dd-941f-47d9-9b9c-fa81586ecc65"}
1482025-01-21T15:53:44.959Z{"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-21T15:53:44.488495295Z","hostname":"w-01JJ4RN3GTHENBNQ4DERAKAPSN","pid":1235,"task":"crutest"}
1492025-01-21T15:53:44.959Z{"msg":"Upstairs starts","v":0,"name":"crucible","level":30,"time":"2025-01-21T15:53:44.488587681Z","hostname":"w-01JJ4RN3GTHENBNQ4DERAKAPSN","pid":1235}
1502025-01-21T15:53:44.959Z{"msg":"Crucible Version: BuildInfo {\n version: \"0.0.1\",\n git_sha: \"5c2b227300b758c153f33da870809d67a5160dae\",\n git_commit_timestamp: \"2025-01-21T15:31:20.000000000Z\",\n git_branch: \"mkeeter/always-check-live-repair\",\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-21T15:53:44.48862669Z","hostname":"w-01JJ4RN3GTHENBNQ4DERAKAPSN","pid":1235}
1512025-01-21T15:53:44.959Z{"msg":"Upstairs <-> Downstairs Message Version: 12","v":0,"name":"crucible","level":30,"time":"2025-01-21T15:53:44.488679238Z","hostname":"w-01JJ4RN3GTHENBNQ4DERAKAPSN","pid":1235}
1522025-01-21T15:53:44.959Z{"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-21T15:53:44.488698827Z","hostname":"w-01JJ4RN3GTHENBNQ4DERAKAPSN","pid":1235}
1532025-01-21T15:53:44.959Z{"msg":"Crucible a9d7f264-c321-49b9-aed8-ffda226931b6 has session id: 5d82a9b9-2980-47f0-9c4c-027ec81c9bd1","v":0,"name":"crucible","level":30,"time":"2025-01-21T15:53:44.489012045Z","hostname":"w-01JJ4RN3GTHENBNQ4DERAKAPSN","pid":1235,"session_id":"5d82a9b9-2980-47f0-9c4c-027ec81c9bd1"}
1542025-01-21T15:53:44.959Z{"msg":"Upstairs opts: Upstairs UUID: a9d7f264-c321-49b9-aed8-ffda226931b6, 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-21T15:53:44.489053974Z","hostname":"w-01JJ4RN3GTHENBNQ4DERAKAPSN","pid":1235,"session_id":"5d82a9b9-2980-47f0-9c4c-027ec81c9bd1"}
1552025-01-21T15:53:44.959Z{"msg":"Crucible stats registered with UUID: a9d7f264-c321-49b9-aed8-ffda226931b6","v":0,"name":"crucible","level":30,"time":"2025-01-21T15:53:44.489092402Z","hostname":"w-01JJ4RN3GTHENBNQ4DERAKAPSN","pid":1235,"session_id":"5d82a9b9-2980-47f0-9c4c-027ec81c9bd1"}
1562025-01-21T15:53:44.959Z{"msg":"could not find Downstairs address for Nexus","v":0,"name":"crucible","level":40,"time":"2025-01-21T15:53:44.489128031Z","hostname":"w-01JJ4RN3GTHENBNQ4DERAKAPSN","pid":1235,"session_id":"5d82a9b9-2980-47f0-9c4c-027ec81c9bd1"}
1572025-01-21T15:53:44.959Z{"msg":"Downstairs in volume = 6","v":0,"name":"crucible","level":30,"time":"2025-01-21T15:53:44.489765547Z","hostname":"w-01JJ4RN3GTHENBNQ4DERAKAPSN","pid":1235,"task":"crutest"}
1582025-01-21T15:53:44.959Z{"msg":"The guest has requested activation with gen:31","v":0,"name":"crucible","level":30,"time":"2025-01-21T15:53:44.489811625Z","hostname":"w-01JJ4RN3GTHENBNQ4DERAKAPSN","pid":1235}
1592025-01-21T15:53:44.959Z{"msg":"a9d7f264-c321-49b9-aed8-ffda226931b6 active request set","v":0,"name":"crucible","level":30,"time":"2025-01-21T15:53:44.489835854Z","hostname":"w-01JJ4RN3GTHENBNQ4DERAKAPSN","pid":1235,"session_id":"ec2bb7dd-941f-47d9-9b9c-fa81586ecc65"}
1602025-01-21T15:53:44.959Z{"msg":"sending connect oneshot to client","v":0,"name":"crucible","level":30,"time":"2025-01-21T15:53:44.489869263Z","hostname":"w-01JJ4RN3GTHENBNQ4DERAKAPSN","pid":1235,"client":"0","":"downstairs","session_id":"ec2bb7dd-941f-47d9-9b9c-fa81586ecc65"}
1612025-01-21T15:53:44.959Z{"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-21T15:53:44.489922581Z","hostname":"w-01JJ4RN3GTHENBNQ4DERAKAPSN","pid":1235,"client":"0","":"downstairs","session_id":"ec2bb7dd-941f-47d9-9b9c-fa81586ecc65"}
1622025-01-21T15:53:44.959Z{"msg":"sending connect oneshot to client","v":0,"name":"crucible","level":30,"time":"2025-01-21T15:53:44.48994577Z","hostname":"w-01JJ4RN3GTHENBNQ4DERAKAPSN","pid":1235,"client":"1","":"downstairs","session_id":"ec2bb7dd-941f-47d9-9b9c-fa81586ecc65"}
1632025-01-21T15:53:44.960Z{"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-21T15:53:44.489966429Z","hostname":"w-01JJ4RN3GTHENBNQ4DERAKAPSN","pid":1235,"client":"1","":"downstairs","session_id":"ec2bb7dd-941f-47d9-9b9c-fa81586ecc65"}
1642025-01-21T15:53:44.960Z{"msg":"sending connect oneshot to client","v":0,"name":"crucible","level":30,"time":"2025-01-21T15:53:44.490006418Z","hostname":"w-01JJ4RN3GTHENBNQ4DERAKAPSN","pid":1235,"client":"2","":"downstairs","session_id":"ec2bb7dd-941f-47d9-9b9c-fa81586ecc65"}
1652025-01-21T15:53:44.960Z{"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-21T15:53:44.490042336Z","hostname":"w-01JJ4RN3GTHENBNQ4DERAKAPSN","pid":1235,"client":"2","":"downstairs","session_id":"ec2bb7dd-941f-47d9-9b9c-fa81586ecc65"}
1662025-01-21T15:53:44.960Z{"msg":"connecting to 127.0.0.1:8830","v":0,"name":"crucible","level":30,"time":"2025-01-21T15:53:44.490064395Z","hostname":"w-01JJ4RN3GTHENBNQ4DERAKAPSN","pid":1235,"":"io task","client":"2","":"downstairs","session_id":"ec2bb7dd-941f-47d9-9b9c-fa81586ecc65"}
1672025-01-21T15:53:44.960Z{"msg":"connecting to 127.0.0.1:8810","v":0,"name":"crucible","level":30,"time":"2025-01-21T15:53:44.490095384Z","hostname":"w-01JJ4RN3GTHENBNQ4DERAKAPSN","pid":1235,"":"io task","client":"0","":"downstairs","session_id":"ec2bb7dd-941f-47d9-9b9c-fa81586ecc65"}
1682025-01-21T15:53:44.960Z{"msg":"connecting to 127.0.0.1:8820","v":0,"name":"crucible","level":30,"time":"2025-01-21T15:53:44.490293767Z","hostname":"w-01JJ4RN3GTHENBNQ4DERAKAPSN","pid":1235,"":"io task","client":"1","":"downstairs","session_id":"ec2bb7dd-941f-47d9-9b9c-fa81586ecc65"}
1692025-01-21T15:53:44.960Z{"msg":"ds_connection connected from Ok(127.0.0.1:46791)","v":0,"name":"crucible","level":30,"time":"2025-01-21T15:53:44.490345754Z","hostname":"w-01JJ4RN3GTHENBNQ4DERAKAPSN","pid":1235,"":"io task","client":"0","":"downstairs","session_id":"ec2bb7dd-941f-47d9-9b9c-fa81586ecc65"}
1702025-01-21T15:53:44.960Z{"msg":"ds_connection connected from Ok(127.0.0.1:60931)","v":0,"name":"crucible","level":30,"time":"2025-01-21T15:53:44.490370104Z","hostname":"w-01JJ4RN3GTHENBNQ4DERAKAPSN","pid":1235,"":"io task","client":"2","":"downstairs","session_id":"ec2bb7dd-941f-47d9-9b9c-fa81586ecc65"}
1712025-01-21T15:53:44.960Z{"msg":"ds_connection connected from Ok(127.0.0.1:52194)","v":0,"name":"crucible","level":30,"time":"2025-01-21T15:53:44.490390133Z","hostname":"w-01JJ4RN3GTHENBNQ4DERAKAPSN","pid":1235,"":"io task","client":"1","":"downstairs","session_id":"ec2bb7dd-941f-47d9-9b9c-fa81586ecc65"}
1722025-01-21T15:53:44.960Z{"msg":"version negotiation from state Connecting { state: WaitForPromote, mode: New }","v":0,"name":"crucible","level":30,"time":"2025-01-21T15:53:44.490780968Z","hostname":"w-01JJ4RN3GTHENBNQ4DERAKAPSN","pid":1235,"client":"1","":"downstairs","session_id":"ec2bb7dd-941f-47d9-9b9c-fa81586ecc65"}
1732025-01-21T15:53:44.960Z{"msg":"version negotiation from state Connecting { state: WaitForPromote, mode: New }","v":0,"name":"crucible","level":30,"time":"2025-01-21T15:53:44.490812657Z","hostname":"w-01JJ4RN3GTHENBNQ4DERAKAPSN","pid":1235,"client":"2","":"downstairs","session_id":"ec2bb7dd-941f-47d9-9b9c-fa81586ecc65"}
1742025-01-21T15:53:44.960Z{"msg":"version negotiation from state Connecting { state: WaitForPromote, mode: New }","v":0,"name":"crucible","level":30,"time":"2025-01-21T15:53:44.490827626Z","hostname":"w-01JJ4RN3GTHENBNQ4DERAKAPSN","pid":1235,"client":"0","":"downstairs","session_id":"ec2bb7dd-941f-47d9-9b9c-fa81586ecc65"}
1752025-01-21T15:53:44.960Z{"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-21T15:53:44.491352926Z","hostname":"w-01JJ4RN3GTHENBNQ4DERAKAPSN","pid":1235,"client":"1","":"downstairs","session_id":"ec2bb7dd-941f-47d9-9b9c-fa81586ecc65"}
1762025-01-21T15:53:44.960Z{"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-21T15:53:44.491396765Z","hostname":"w-01JJ4RN3GTHENBNQ4DERAKAPSN","pid":1235,"client":"0","":"downstairs","session_id":"ec2bb7dd-941f-47d9-9b9c-fa81586ecc65"}
1772025-01-21T15:53:44.964Z{"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-21T15:53:44.49152401Z","hostname":"w-01JJ4RN3GTHENBNQ4DERAKAPSN","pid":1235,"client":"2","":"downstairs","session_id":"ec2bb7dd-941f-47d9-9b9c-fa81586ecc65"}
1782025-01-21T15:53:44.964Z{"msg":"Waiting for more clients to be ready","v":0,"name":"crucible","level":30,"time":"2025-01-21T15:53:44.49176104Z","hostname":"w-01JJ4RN3GTHENBNQ4DERAKAPSN","pid":1235,"session_id":"ec2bb7dd-941f-47d9-9b9c-fa81586ecc65"}
1792025-01-21T15:53:44.964Z{"msg":"Waiting for more clients to be ready","v":0,"name":"crucible","level":30,"time":"2025-01-21T15:53:44.491923364Z","hostname":"w-01JJ4RN3GTHENBNQ4DERAKAPSN","pid":1235,"session_id":"ec2bb7dd-941f-47d9-9b9c-fa81586ecc65"}
1802025-01-21T15:53:44.964Z{"msg":"[0]R flush_numbers: [3996, 3996, 3996, 3996, 3996]","v":0,"name":"crucible","level":30,"time":"2025-01-21T15:53:44.491960053Z","hostname":"w-01JJ4RN3GTHENBNQ4DERAKAPSN","pid":1235,"":"downstairs","":"downstairs","session_id":"ec2bb7dd-941f-47d9-9b9c-fa81586ecc65"}
1812025-01-21T15:53:44.964Z{"msg":"[0]R generation: [25, 25, 25, 25, 25]","v":0,"name":"crucible","level":30,"time":"2025-01-21T15:53:44.491983392Z","hostname":"w-01JJ4RN3GTHENBNQ4DERAKAPSN","pid":1235,"":"downstairs","":"downstairs","session_id":"ec2bb7dd-941f-47d9-9b9c-fa81586ecc65"}
1822025-01-21T15:53:44.964Z{"msg":"[0]R dirty: [false, false, false, false, false]","v":0,"name":"crucible","level":30,"time":"2025-01-21T15:53:44.491997371Z","hostname":"w-01JJ4RN3GTHENBNQ4DERAKAPSN","pid":1235,"":"downstairs","":"downstairs","session_id":"ec2bb7dd-941f-47d9-9b9c-fa81586ecc65"}
1832025-01-21T15:53:44.964Z{"msg":"[1]R flush_numbers: [3996, 3996, 3996, 3996, 3996]","v":0,"name":"crucible","level":30,"time":"2025-01-21T15:53:44.492012041Z","hostname":"w-01JJ4RN3GTHENBNQ4DERAKAPSN","pid":1235,"":"downstairs","":"downstairs","session_id":"ec2bb7dd-941f-47d9-9b9c-fa81586ecc65"}
1842025-01-21T15:53:44.964Z{"msg":"[1]R generation: [25, 25, 25, 25, 25]","v":0,"name":"crucible","level":30,"time":"2025-01-21T15:53:44.492025701Z","hostname":"w-01JJ4RN3GTHENBNQ4DERAKAPSN","pid":1235,"":"downstairs","":"downstairs","session_id":"ec2bb7dd-941f-47d9-9b9c-fa81586ecc65"}
1852025-01-21T15:53:44.964Z{"msg":"[1]R dirty: [false, false, false, false, false]","v":0,"name":"crucible","level":30,"time":"2025-01-21T15:53:44.49203877Z","hostname":"w-01JJ4RN3GTHENBNQ4DERAKAPSN","pid":1235,"":"downstairs","":"downstairs","session_id":"ec2bb7dd-941f-47d9-9b9c-fa81586ecc65"}
1862025-01-21T15:53:44.964Z{"msg":"[2]R flush_numbers: [3996, 3996, 3996, 3996, 3996]","v":0,"name":"crucible","level":30,"time":"2025-01-21T15:53:44.492060089Z","hostname":"w-01JJ4RN3GTHENBNQ4DERAKAPSN","pid":1235,"":"downstairs","":"downstairs","session_id":"ec2bb7dd-941f-47d9-9b9c-fa81586ecc65"}
1872025-01-21T15:53:44.964Z{"msg":"[2]R generation: [25, 25, 25, 25, 25]","v":0,"name":"crucible","level":30,"time":"2025-01-21T15:53:44.492074739Z","hostname":"w-01JJ4RN3GTHENBNQ4DERAKAPSN","pid":1235,"":"downstairs","":"downstairs","session_id":"ec2bb7dd-941f-47d9-9b9c-fa81586ecc65"}
1882025-01-21T15:53:44.964Z{"msg":"[2]R dirty: [false, false, false, false, false]","v":0,"name":"crucible","level":30,"time":"2025-01-21T15:53:44.492095288Z","hostname":"w-01JJ4RN3GTHENBNQ4DERAKAPSN","pid":1235,"":"downstairs","":"downstairs","session_id":"ec2bb7dd-941f-47d9-9b9c-fa81586ecc65"}
1892025-01-21T15:53:44.964Z{"msg":"Max found gen is 26","v":0,"name":"crucible","level":30,"time":"2025-01-21T15:53:44.492108247Z","hostname":"w-01JJ4RN3GTHENBNQ4DERAKAPSN","pid":1235,"":"downstairs","":"downstairs","session_id":"ec2bb7dd-941f-47d9-9b9c-fa81586ecc65"}
1902025-01-21T15:53:44.964Z{"msg":"Generation requested: 31 >= found:26","v":0,"name":"crucible","level":30,"time":"2025-01-21T15:53:44.492121507Z","hostname":"w-01JJ4RN3GTHENBNQ4DERAKAPSN","pid":1235,"":"downstairs","":"downstairs","session_id":"ec2bb7dd-941f-47d9-9b9c-fa81586ecc65"}
1912025-01-21T15:53:44.964Z{"msg":"Next flush: 3997","v":0,"name":"crucible","level":30,"time":"2025-01-21T15:53:44.492133896Z","hostname":"w-01JJ4RN3GTHENBNQ4DERAKAPSN","pid":1235,"":"downstairs","":"downstairs","session_id":"ec2bb7dd-941f-47d9-9b9c-fa81586ecc65"}
1922025-01-21T15:53:44.965Z{"msg":"All extents match","v":0,"name":"crucible","level":30,"time":"2025-01-21T15:53:44.492146286Z","hostname":"w-01JJ4RN3GTHENBNQ4DERAKAPSN","pid":1235,"":"downstairs","":"downstairs","session_id":"ec2bb7dd-941f-47d9-9b9c-fa81586ecc65"}
1932025-01-21T15:53:44.965Z{"msg":"No downstairs reconciliation required","v":0,"name":"crucible","level":30,"time":"2025-01-21T15:53:44.492158885Z","hostname":"w-01JJ4RN3GTHENBNQ4DERAKAPSN","pid":1235,"session_id":"ec2bb7dd-941f-47d9-9b9c-fa81586ecc65"}
1942025-01-21T15:53:44.965Z{"msg":"Transition from WaitQuorum to Active","v":0,"name":"crucible","level":30,"time":"2025-01-21T15:53:44.492177395Z","hostname":"w-01JJ4RN3GTHENBNQ4DERAKAPSN","pid":1235,"client":"0","":"downstairs","session_id":"ec2bb7dd-941f-47d9-9b9c-fa81586ecc65"}
1952025-01-21T15:53:44.965Z{"msg":"Transition from WaitQuorum to Active","v":0,"name":"crucible","level":30,"time":"2025-01-21T15:53:44.492190604Z","hostname":"w-01JJ4RN3GTHENBNQ4DERAKAPSN","pid":1235,"client":"1","":"downstairs","session_id":"ec2bb7dd-941f-47d9-9b9c-fa81586ecc65"}
1962025-01-21T15:53:44.965Z{"msg":"Transition from WaitQuorum to Active","v":0,"name":"crucible","level":30,"time":"2025-01-21T15:53:44.492210214Z","hostname":"w-01JJ4RN3GTHENBNQ4DERAKAPSN","pid":1235,"client":"2","":"downstairs","session_id":"ec2bb7dd-941f-47d9-9b9c-fa81586ecc65"}
1972025-01-21T15:53:44.965Z{"msg":"All required reconciliation work is completed","v":0,"name":"crucible","level":30,"time":"2025-01-21T15:53:44.492223063Z","hostname":"w-01JJ4RN3GTHENBNQ4DERAKAPSN","pid":1235,"session_id":"ec2bb7dd-941f-47d9-9b9c-fa81586ecc65"}
1982025-01-21T15:53:44.965Z{"msg":"Set Downstairs and Upstairs active after reconciliation","v":0,"name":"crucible","level":30,"time":"2025-01-21T15:53:44.492273541Z","hostname":"w-01JJ4RN3GTHENBNQ4DERAKAPSN","pid":1235,"session_id":"ec2bb7dd-941f-47d9-9b9c-fa81586ecc65"}
1992025-01-21T15:53:44.965Z{"msg":"a9d7f264-c321-49b9-aed8-ffda226931b6 is now active with session: ec2bb7dd-941f-47d9-9b9c-fa81586ecc65","v":0,"name":"crucible","level":30,"time":"2025-01-21T15:53:44.49230734Z","hostname":"w-01JJ4RN3GTHENBNQ4DERAKAPSN","pid":1235,"session_id":"ec2bb7dd-941f-47d9-9b9c-fa81586ecc65"}
2002025-01-21T15:53:44.965Z{"msg":"Set Active after no reconciliation","v":0,"name":"crucible","level":30,"time":"2025-01-21T15:53:44.492332099Z","hostname":"w-01JJ4RN3GTHENBNQ4DERAKAPSN","pid":1235,"session_id":"ec2bb7dd-941f-47d9-9b9c-fa81586ecc65"}
2012025-01-21T15:53:44.965Z{"msg":"The guest has finished waiting for activation with:31","v":0,"name":"crucible","level":30,"time":"2025-01-21T15:53:44.492363408Z","hostname":"w-01JJ4RN3GTHENBNQ4DERAKAPSN","pid":1235}
2022025-01-21T15:53:44.965Z{"msg":"The guest has requested activation with gen:31","v":0,"name":"crucible","level":30,"time":"2025-01-21T15:53:44.492384867Z","hostname":"w-01JJ4RN3GTHENBNQ4DERAKAPSN","pid":1235}
2032025-01-21T15:53:44.965Z{"msg":"a9d7f264-c321-49b9-aed8-ffda226931b6 active request set","v":0,"name":"crucible","level":30,"time":"2025-01-21T15:53:44.492406476Z","hostname":"w-01JJ4RN3GTHENBNQ4DERAKAPSN","pid":1235,"session_id":"5d82a9b9-2980-47f0-9c4c-027ec81c9bd1"}
2042025-01-21T15:53:44.965Z{"msg":"sending connect oneshot to client","v":0,"name":"crucible","level":30,"time":"2025-01-21T15:53:44.492427305Z","hostname":"w-01JJ4RN3GTHENBNQ4DERAKAPSN","pid":1235,"client":"0","":"downstairs","session_id":"5d82a9b9-2980-47f0-9c4c-027ec81c9bd1"}
2052025-01-21T15:53:44.965Z{"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-21T15:53:44.492517812Z","hostname":"w-01JJ4RN3GTHENBNQ4DERAKAPSN","pid":1235,"client":"0","":"downstairs","session_id":"5d82a9b9-2980-47f0-9c4c-027ec81c9bd1"}
2062025-01-21T15:53:44.965Z{"msg":"sending connect oneshot to client","v":0,"name":"crucible","level":30,"time":"2025-01-21T15:53:44.492545781Z","hostname":"w-01JJ4RN3GTHENBNQ4DERAKAPSN","pid":1235,"client":"1","":"downstairs","session_id":"5d82a9b9-2980-47f0-9c4c-027ec81c9bd1"}
2072025-01-21T15:53:44.965Z{"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-21T15:53:44.492583209Z","hostname":"w-01JJ4RN3GTHENBNQ4DERAKAPSN","pid":1235,"client":"1","":"downstairs","session_id":"5d82a9b9-2980-47f0-9c4c-027ec81c9bd1"}
2082025-01-21T15:53:44.965Z{"msg":"sending connect oneshot to client","v":0,"name":"crucible","level":30,"time":"2025-01-21T15:53:44.492597759Z","hostname":"w-01JJ4RN3GTHENBNQ4DERAKAPSN","pid":1235,"client":"2","":"downstairs","session_id":"5d82a9b9-2980-47f0-9c4c-027ec81c9bd1"}
2092025-01-21T15:53:44.965Z{"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-21T15:53:44.492615448Z","hostname":"w-01JJ4RN3GTHENBNQ4DERAKAPSN","pid":1235,"client":"2","":"downstairs","session_id":"5d82a9b9-2980-47f0-9c4c-027ec81c9bd1"}
2102025-01-21T15:53:44.965Z{"msg":"connecting to 127.0.0.1:8860","v":0,"name":"crucible","level":30,"time":"2025-01-21T15:53:44.492636057Z","hostname":"w-01JJ4RN3GTHENBNQ4DERAKAPSN","pid":1235,"":"io task","client":"2","":"downstairs","session_id":"5d82a9b9-2980-47f0-9c4c-027ec81c9bd1"}
2112025-01-21T15:53:44.965Z{"msg":"connecting to 127.0.0.1:8840","v":0,"name":"crucible","level":30,"time":"2025-01-21T15:53:44.492658266Z","hostname":"w-01JJ4RN3GTHENBNQ4DERAKAPSN","pid":1235,"":"io task","client":"0","":"downstairs","session_id":"5d82a9b9-2980-47f0-9c4c-027ec81c9bd1"}
2122025-01-21T15:53:44.965Z{"msg":"connecting to 127.0.0.1:8850","v":0,"name":"crucible","level":30,"time":"2025-01-21T15:53:44.492695455Z","hostname":"w-01JJ4RN3GTHENBNQ4DERAKAPSN","pid":1235,"":"io task","client":"1","":"downstairs","session_id":"5d82a9b9-2980-47f0-9c4c-027ec81c9bd1"}
2132025-01-21T15:53:44.965Z{"msg":"ds_connection connected from Ok(127.0.0.1:63777)","v":0,"name":"crucible","level":30,"time":"2025-01-21T15:53:44.492712484Z","hostname":"w-01JJ4RN3GTHENBNQ4DERAKAPSN","pid":1235,"":"io task","client":"0","":"downstairs","session_id":"5d82a9b9-2980-47f0-9c4c-027ec81c9bd1"}
2142025-01-21T15:53:44.965Z{"msg":"ds_connection connected from Ok(127.0.0.1:44312)","v":0,"name":"crucible","level":30,"time":"2025-01-21T15:53:44.492726944Z","hostname":"w-01JJ4RN3GTHENBNQ4DERAKAPSN","pid":1235,"":"io task","client":"2","":"downstairs","session_id":"5d82a9b9-2980-47f0-9c4c-027ec81c9bd1"}
2152025-01-21T15:53:44.965Z{"msg":"ds_connection connected from Ok(127.0.0.1:36075)","v":0,"name":"crucible","level":30,"time":"2025-01-21T15:53:44.492761962Z","hostname":"w-01JJ4RN3GTHENBNQ4DERAKAPSN","pid":1235,"":"io task","client":"1","":"downstairs","session_id":"5d82a9b9-2980-47f0-9c4c-027ec81c9bd1"}
2162025-01-21T15:53:44.965Z{"msg":"version negotiation from state Connecting { state: WaitForPromote, mode: New }","v":0,"name":"crucible","level":30,"time":"2025-01-21T15:53:44.492902027Z","hostname":"w-01JJ4RN3GTHENBNQ4DERAKAPSN","pid":1235,"client":"2","":"downstairs","session_id":"5d82a9b9-2980-47f0-9c4c-027ec81c9bd1"}
2172025-01-21T15:53:44.965Z{"msg":"version negotiation from state Connecting { state: WaitForPromote, mode: New }","v":0,"name":"crucible","level":30,"time":"2025-01-21T15:53:44.493108749Z","hostname":"w-01JJ4RN3GTHENBNQ4DERAKAPSN","pid":1235,"client":"0","":"downstairs","session_id":"5d82a9b9-2980-47f0-9c4c-027ec81c9bd1"}
2182025-01-21T15:53:44.965Z{"msg":"version negotiation from state Connecting { state: WaitForPromote, mode: New }","v":0,"name":"crucible","level":30,"time":"2025-01-21T15:53:44.493136198Z","hostname":"w-01JJ4RN3GTHENBNQ4DERAKAPSN","pid":1235,"client":"1","":"downstairs","session_id":"5d82a9b9-2980-47f0-9c4c-027ec81c9bd1"}
2192025-01-21T15:53:44.965Z{"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-21T15:53:44.493579641Z","hostname":"w-01JJ4RN3GTHENBNQ4DERAKAPSN","pid":1235,"client":"2","":"downstairs","session_id":"5d82a9b9-2980-47f0-9c4c-027ec81c9bd1"}
2202025-01-21T15:53:44.965Z{"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-21T15:53:44.493725406Z","hostname":"w-01JJ4RN3GTHENBNQ4DERAKAPSN","pid":1235,"client":"0","":"downstairs","session_id":"5d82a9b9-2980-47f0-9c4c-027ec81c9bd1"}
2212025-01-21T15:53:44.965Z{"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-21T15:53:44.493768294Z","hostname":"w-01JJ4RN3GTHENBNQ4DERAKAPSN","pid":1235,"client":"1","":"downstairs","session_id":"5d82a9b9-2980-47f0-9c4c-027ec81c9bd1"}
2222025-01-21T15:53:44.965Z{"msg":"Waiting for more clients to be ready","v":0,"name":"crucible","level":30,"time":"2025-01-21T15:53:44.493991036Z","hostname":"w-01JJ4RN3GTHENBNQ4DERAKAPSN","pid":1235,"session_id":"5d82a9b9-2980-47f0-9c4c-027ec81c9bd1"}
2232025-01-21T15:53:44.965Z{"msg":"Waiting for more clients to be ready","v":0,"name":"crucible","level":30,"time":"2025-01-21T15:53:44.494112721Z","hostname":"w-01JJ4RN3GTHENBNQ4DERAKAPSN","pid":1235,"session_id":"5d82a9b9-2980-47f0-9c4c-027ec81c9bd1"}
2242025-01-21T15:53:44.965Z{"msg":"[0]R flush_numbers: [5318, 5318, 5314, 5318, 5318]","v":0,"name":"crucible","level":30,"time":"2025-01-21T15:53:44.49414838Z","hostname":"w-01JJ4RN3GTHENBNQ4DERAKAPSN","pid":1235,"":"downstairs","":"downstairs","session_id":"5d82a9b9-2980-47f0-9c4c-027ec81c9bd1"}
2252025-01-21T15:53:44.965Z{"msg":"[0]R generation: [14, 14, 12, 14, 14]","v":0,"name":"crucible","level":30,"time":"2025-01-21T15:53:44.494164039Z","hostname":"w-01JJ4RN3GTHENBNQ4DERAKAPSN","pid":1235,"":"downstairs","":"downstairs","session_id":"5d82a9b9-2980-47f0-9c4c-027ec81c9bd1"}
2262025-01-21T15:53:44.965Z{"msg":"[0]R dirty: [false, false, false, false, false]","v":0,"name":"crucible","level":30,"time":"2025-01-21T15:53:44.494185028Z","hostname":"w-01JJ4RN3GTHENBNQ4DERAKAPSN","pid":1235,"":"downstairs","":"downstairs","session_id":"5d82a9b9-2980-47f0-9c4c-027ec81c9bd1"}
2272025-01-21T15:53:44.965Z{"msg":"[1]R flush_numbers: [5318, 5318, 5314, 5318, 5318]","v":0,"name":"crucible","level":30,"time":"2025-01-21T15:53:44.494198648Z","hostname":"w-01JJ4RN3GTHENBNQ4DERAKAPSN","pid":1235,"":"downstairs","":"downstairs","session_id":"5d82a9b9-2980-47f0-9c4c-027ec81c9bd1"}
2282025-01-21T15:53:44.965Z{"msg":"[1]R generation: [14, 14, 12, 14, 14]","v":0,"name":"crucible","level":30,"time":"2025-01-21T15:53:44.494212337Z","hostname":"w-01JJ4RN3GTHENBNQ4DERAKAPSN","pid":1235,"":"downstairs","":"downstairs","session_id":"5d82a9b9-2980-47f0-9c4c-027ec81c9bd1"}
2292025-01-21T15:53:44.965Z{"msg":"[1]R dirty: [false, false, false, false, false]","v":0,"name":"crucible","level":30Wait for a query_work_queue command to finish before sending IO
2302025-01-21T15:53:44.966Z,"time":"2025-01-21T15:53:44.494232157Z","hostname":"w-01JJ4RN3GTHENBNQ4DERAKAPSN","pid":1235,"":"downstairs","":"downstairs","session_id":"5d82a9b9-2980-47f0-9c4c-027ec81c9bd1"}
2312025-01-21T15:53:44.966Z{"msg":"[2]R flush_numbers: [5318, 5318, 5314, 5318, 5318]","v":0,"name":"crucible","level":30,"time":"2025-01-21T15:53:44.494249546Z","hostname":"w-01JJ4RN3GTHENBNQ4DERAKAPSN","pid":1235,"":"downstairs","":"downstairs","session_id":"5d82a9b9-2980-47f0-9c4c-027ec81c9bd1"}
2322025-01-21T15:53:44.966Z{"msg":"[2]R generation: [14, 14, 12, 14, 14]","v":0,"name":"crucible","level":30,"time":"2025-01-21T15:53:44.494269175Z","hostname":"w-01JJ4RN3GTHENBNQ4DERAKAPSN","pid":1235,"":"downstairs","":"downstairs","session_id":"5d82a9b9-2980-47f0-9c4c-027ec81c9bd1"}
2332025-01-21T15:53:44.966Z{"msg":"[2]R dirty: [false, false, false, false, false]","v":0,"name":"crucible","level":30,"time":"2025-01-21T15:53:44.494282424Z","hostname":"w-01JJ4RN3GTHENBNQ4DERAKAPSN","pid":1235,"":"downstairs","":"downstairs","session_id":"5d82a9b9-2980-47f0-9c4c-027ec81c9bd1"}
2342025-01-21T15:53:44.966Z{"msg":"Max found gen is 15","v":0,"name":"crucible","level":30,"time":"2025-01-21T15:53:44.494301844Z","hostname":"w-01JJ4RN3GTHENBNQ4DERAKAPSN","pid":1235,"":"downstairs","":"downstairs","session_id":"5d82a9b9-2980-47f0-9c4c-027ec81c9bd1"}
2352025-01-21T15:53:44.966Z{"msg":"Generation requested: 31 >= found:15","v":0,"name":"crucible","level":30,"time":"2025-01-21T15:53:44.494314743Z","hostname":"w-01JJ4RN3GTHENBNQ4DERAKAPSN","pid":1235,"":"downstairs","":"downstairs","session_id":"5d82a9b9-2980-47f0-9c4c-027ec81c9bd1"}
2362025-01-21T15:53:44.966Z{"msg":"Next flush: 5319","v":0,"name":"crucible","level":30,"time":"2025-01-21T15:53:44.494333902Z","hostname":"w-01JJ4RN3GTHENBNQ4DERAKAPSN","pid":1235,"":"downstairs","":"downstairs","session_id":"5d82a9b9-2980-47f0-9c4c-027ec81c9bd1"}
2372025-01-21T15:53:44.966Z{"msg":"All extents match","v":0,"name":"crucible","level":30,"time":"2025-01-21T15:53:44.494346802Z","hostname":"w-01JJ4RN3GTHENBNQ4DERAKAPSN","pid":1235,"":"downstairs","":"downstairs","session_id":"5d82a9b9-2980-47f0-9c4c-027ec81c9bd1"}
2382025-01-21T15:53:44.966Z{"msg":"No downstairs reconciliation required","v":0,"name":"crucible","level":30,"time":"2025-01-21T15:53:44.494359292Z","hostname":"w-01JJ4RN3GTHENBNQ4DERAKAPSN","pid":1235,"session_id":"5d82a9b9-2980-47f0-9c4c-027ec81c9bd1"}
2392025-01-21T15:53:44.966Z{"msg":"Transition from WaitQuorum to Active","v":0,"name":"crucible","level":30,"time":"2025-01-21T15:53:44.494378081Z","hostname":"w-01JJ4RN3GTHENBNQ4DERAKAPSN","pid":1235,"client":"0","":"downstairs","session_id":"5d82a9b9-2980-47f0-9c4c-027ec81c9bd1"}
2402025-01-21T15:53:44.966Z{"msg":"Transition from WaitQuorum to Active","v":0,"name":"crucible","level":30,"time":"2025-01-21T15:53:44.49439123Z","hostname":"w-01JJ4RN3GTHENBNQ4DERAKAPSN","pid":1235,"client":"1","":"downstairs","session_id":"5d82a9b9-2980-47f0-9c4c-027ec81c9bd1"}
2412025-01-21T15:53:44.966Z{"msg":"Transition from WaitQuorum to Active","v":0,"name":"crucible","level":30,"time":"2025-01-21T15:53:44.4944042Z","hostname":"w-01JJ4RN3GTHENBNQ4DERAKAPSN","pid":1235,"client":"2","":"downstairs","session_id":"5d82a9b9-2980-47f0-9c4c-027ec81c9bd1"}
2422025-01-21T15:53:44.966Z{"msg":"All required reconciliation work is completed","v":0,"name":"crucible","level":30,"time":"2025-01-21T15:53:44.494423599Z","hostname":"w-01JJ4RN3GTHENBNQ4DERAKAPSN","pid":1235,"session_id":"5d82a9b9-2980-47f0-9c4c-027ec81c9bd1"}
2432025-01-21T15:53:44.966Z{"msg":"Set Downstairs and Upstairs active after reconciliation","v":0,"name":"crucible","level":30,"time":"2025-01-21T15:53:44.494435809Z","hostname":"w-01JJ4RN3GTHENBNQ4DERAKAPSN","pid":1235,"session_id":"5d82a9b9-2980-47f0-9c4c-027ec81c9bd1"}
2442025-01-21T15:53:44.966Z{"msg":"a9d7f264-c321-49b9-aed8-ffda226931b6 is now active with session: 5d82a9b9-2980-47f0-9c4c-027ec81c9bd1","v":0,"name":"crucible","level":30,"time":"2025-01-21T15:53:44.494455238Z","hostname":"w-01JJ4RN3GTHENBNQ4DERAKAPSN","pid":1235,"session_id":"5d82a9b9-2980-47f0-9c4c-027ec81c9bd1"}
2452025-01-21T15:53:44.966Z{"msg":"Set Active after no reconciliation","v":0,"name":"crucible","level":30,"time":"2025-01-21T15:53:44.494467048Z","hostname":"w-01JJ4RN3GTHENBNQ4DERAKAPSN","pid":1235,"session_id":"5d82a9b9-2980-47f0-9c4c-027ec81c9bd1"}
2462025-01-21T15:53:44.966Z{"msg":"The guest has finished waiting for activation with:31","v":0,"name":"crucible","level":30,"time":"2025-01-21T15:53:44.494479447Z","hostname":"w-01JJ4RN3GTHENBNQ4DERAKAPSN","pid":1235}
2472025-01-21T15:53:44.966ZDisk: sv:2 bs:4096 ts:409600 tb:100 max_io:100 or 409600
2482025-01-21T15:53:44.966ZFill test
2492025-01-21T15:53:45.005ZRead and Verify all blocks (0..100 range:false)
2502025-01-21T15:53:45.085ZWrote out file "/var/tmp/test_up-build/verify_file"
2512025-01-21T15:53:45.085ZCLIENT: Tests done. All submitted work has been ACK'd
2522025-01-21T15:53:45.088Z----------------------------------------------------------------
2532025-01-21T15:53:45.088Z Crucible gen:31 GIO:true work queues: Upstairs:0 downstairs:1
2542025-01-21T15:53:45.088ZStates: Active Active Active
2552025-01-21T15:53:45.088ZJOBID ACK TYPE BKS/EXT DS:0 DS:1 DS:2 REPLAY
2562025-01-21T15:53:45.088Z 1002 Acked Read 50 Done Done Done false
2572025-01-21T15:53:45.088Z STATES DS:0 DS:1 DS:2 TOTAL
2582025-01-21T15:53:45.088Z Sent 0 0 0 0
2592025-01-21T15:53:45.088Z Done 1 1 1 3
2602025-01-21T15:53:45.088Z Skipped 0 0 0 0
2612025-01-21T15:53:45.088Z Error 0 0 0 0
2622025-01-21T15:53:45.088ZLast Flush: 1001 1001 1001
2632025-01-21T15:53:45.088ZDownstairs last five completed: 1001 1000
2642025-01-21T15:53:45.088ZUpstairs last five completed: 1002 1001 1000
2652025-01-21T15:53:45.088Z----------------------------------------------------------------
2662025-01-21T15:53:45.088Z Crucible gen:31 GIO:true work queues: Upstairs:0 downstairs:1
2672025-01-21T15:53:45.088ZStates: Active Active Active
2682025-01-21T15:53:45.088ZJOBID ACK TYPE BKS/EXT DS:0 DS:1 DS:2 REPLAY
2692025-01-21T15:53:45.088Z 1002 Acked Read 50 Done Done Done false
2702025-01-21T15:53:45.088Z STATES DS:0 DS:1 DS:2 TOTAL
2712025-01-21T15:53:45.088Z Sent 0 0 0 0
2722025-01-21T15:53:45.088Z Done 1 1 1 3
2732025-01-21T15:53:45.088Z Skipped 0 0 0 0
2742025-01-21T15:53:45.088Z Error 0 0 0 0
2752025-01-21T15:53:45.089ZLast Flush: 1001 1001 1001
2762025-01-21T15:53:45.089ZDownstairs last five completed: 1001 1000
2772025-01-21T15:53:45.089ZUpstairs last five completed: 1002 1001 1000
2782025-01-21T15:53:45.089ZCLIENT: Up:0 ds:2 act:6
2792025-01-21T15:53:49.087Z----------------------------------------------------------------
2802025-01-21T15:53:49.087Z Crucible gen:31 GIO:true work queues: Upstairs:0 downstairs:0
2812025-01-21T15:53:49.087ZDownstairs last five completed: 1003 1002 1001 1000
2822025-01-21T15:53:49.087ZUpstairs last five completed: 1003 1002 1001 1000
2832025-01-21T15:53:49.087Z----------------------------------------------------------------
2842025-01-21T15:53:49.087Z Crucible gen:31 GIO:true work queues: Upstairs:0 downstairs:0
2852025-01-21T15:53:49.087ZDownstairs last five completed: 1003 1002 1001 1000
2862025-01-21T15:53:49.087ZUpstairs last five completed: 1003 1002 1001 1000
2872025-01-21T15:53:49.090ZCLIENT: Up:0 ds:0 act:6
2882025-01-21T15:53:49.090ZCLIENT: All crucible jobs finished, exiting program
2892025-01-21T15:53:49.090Z{"msg":"Guest handle has been dropped","v":0,"name":"crucible","level":40,"time":"2025-01-21T15:53:48.620058501Z","hostname":"w-01JJ4RN3GTHENBNQ4DERAKAPSN","pid":1235}
2902025-01-21T15:53:49.098ZRepair setup passed
2912025-01-21T15:53:49.102ZCopy the region for /var/tmp/test_up-build/8830
2922025-01-21T15:53:49.105Zcp -r /var/tmp/test_up-build/8830 /var/tmp/test_up-build/previous
2932025-01-21T15:53:49.107Z/var/tmp/bins/crutest fill -g 32 -q --key wR+F1olsh8k3doPjXFwJ2Zs1S4Z3J9BWk6o9Zds2Hdg= --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-21T15:53:49.165Z{"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-21T15:53:48.697314589Z","hostname":"w-01JJ4RN3GTHENBNQ4DERAKAPSN","pid":1241,"task":"crutest"}
2952025-01-21T15:53:49.167Z{"msg":"dsc has 6 regions. This means 2 sub_volumes","v":0,"name":"crucible","level":30,"time":"2025-01-21T15:53:48.697899826Z","hostname":"w-01JJ4RN3GTHENBNQ4DERAKAPSN","pid":1241,"task":"crutest"}
2962025-01-21T15:53:49.167Z{"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-21T15:53:48.699570403Z","hostname":"w-01JJ4RN3GTHENBNQ4DERAKAPSN","pid":1241,"task":"crutest"}
2972025-01-21T15:53:49.167Z{"msg":"Upstairs starts","v":0,"name":"crucible","level":30,"time":"2025-01-21T15:53:48.699749746Z","hostname":"w-01JJ4RN3GTHENBNQ4DERAKAPSN","pid":1241}
2982025-01-21T15:53:49.167Z{"msg":"Crucible Version: BuildInfo {\n version: \"0.0.1\",\n git_sha: \"5c2b227300b758c153f33da870809d67a5160dae\",\n git_commit_timestamp: \"2025-01-21T15:31:20.000000000Z\",\n git_branch: \"mkeeter/always-check-live-repair\",\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-21T15:53:48.699791684Z","hostname":"w-01JJ4RN3GTHENBNQ4DERAKAPSN","pid":1241}
2992025-01-21T15:53:49.167Z{"msg":"Upstairs <-> Downstairs Message Version: 12","v":0,"name":"crucible","level":30,"time":"2025-01-21T15:53:48.699813303Z","hostname":"w-01JJ4RN3GTHENBNQ4DERAKAPSN","pid":1241}
3002025-01-21T15:53:49.167Z{"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-21T15:53:48.699827733Z","hostname":"w-01JJ4RN3GTHENBNQ4DERAKAPSN","pid":1241}
3012025-01-21T15:53:49.170Z{"msg":"Crucible 9ce53551-31f5-4e3b-bcc4-51e91d12ddf7 has session id: 037c1c20-617c-4383-b5a8-714c2ec1ec2f","v":0,"name":"crucible","level":30,"time":"2025-01-21T15:53:48.70042944Z","hostname":"w-01JJ4RN3GTHENBNQ4DERAKAPSN","pid":1241,"session_id":"037c1c20-617c-4383-b5a8-714c2ec1ec2f"}
3022025-01-21T15:53:49.170Z{"msg":"Upstairs opts: Upstairs UUID: 9ce53551-31f5-4e3b-bcc4-51e91d12ddf7, 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-21T15:53:48.700485348Z","hostname":"w-01JJ4RN3GTHENBNQ4DERAKAPSN","pid":1241,"session_id":"037c1c20-617c-4383-b5a8-714c2ec1ec2f"}
3032025-01-21T15:53:49.170Z{"msg":"Crucible stats registered with UUID: 9ce53551-31f5-4e3b-bcc4-51e91d12ddf7","v":0,"name":"crucible","level":30,"time":"2025-01-21T15:53:48.700503487Z","hostname":"w-01JJ4RN3GTHENBNQ4DERAKAPSN","pid":1241,"session_id":"037c1c20-617c-4383-b5a8-714c2ec1ec2f"}
3042025-01-21T15:53:49.170Z{"msg":"could not find Downstairs address for Nexus","v":0,"name":"crucible","level":40,"time":"2025-01-21T15:53:48.700516287Z","hostname":"w-01JJ4RN3GTHENBNQ4DERAKAPSN","pid":1241,"session_id":"037c1c20-617c-4383-b5a8-714c2ec1ec2f"}
3052025-01-21T15:53:49.170Z{"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-21T15:53:48.702458333Z","hostname":"w-01JJ4RN3GTHENBNQ4DERAKAPSN","pid":1241,"task":"crutest"}
3062025-01-21T15:53:49.170Z{"msg":"Upstairs starts","v":0,"name":"crucible","level":30,"time":"2025-01-21T15:53:48.702544909Z","hostname":"w-01JJ4RN3GTHENBNQ4DERAKAPSN","pid":1241}
3072025-01-21T15:53:49.170Z{"msg":"Crucible Version: BuildInfo {\n version: \"0.0.1\",\n git_sha: \"5c2b227300b758c153f33da870809d67a5160dae\",\n git_commit_timestamp: \"2025-01-21T15:31:20.000000000Z\",\n git_branch: \"mkeeter/always-check-live-repair\",\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-21T15:53:48.702579468Z","hostname":"w-01JJ4RN3GTHENBNQ4DERAKAPSN","pid":1241}
3082025-01-21T15:53:49.170Z{"msg":"Upstairs <-> Downstairs Message Version: 12","v":0,"name":"crucible","level":30,"time":"2025-01-21T15:53:48.702591828Z","hostname":"w-01JJ4RN3GTHENBNQ4DERAKAPSN","pid":1241}
3092025-01-21T15:53:49.170Z{"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-21T15:53:48.702605487Z","hostname":"w-01JJ4RN3GTHENBNQ4DERAKAPSN","pid":1241}
3102025-01-21T15:53:49.171Z{"msg":"Crucible 9ce53551-31f5-4e3b-bcc4-51e91d12ddf7 has session id: 4c3e748d-cb23-4fb0-93a5-084c609e3dcb","v":0,"name":"crucible","level":30,"time":"2025-01-21T15:53:48.703005962Z","hostname":"w-01JJ4RN3GTHENBNQ4DERAKAPSN","pid":1241,"session_id":"4c3e748d-cb23-4fb0-93a5-084c609e3dcb"}
3112025-01-21T15:53:49.171Z{"msg":"Upstairs opts: Upstairs UUID: 9ce53551-31f5-4e3b-bcc4-51e91d12ddf7, 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-21T15:53:48.703038911Z","hostname":"w-01JJ4RN3GTHENBNQ4DERAKAPSN","pid":1241,"session_id":"4c3e748d-cb23-4fb0-93a5-084c609e3dcb"}
3122025-01-21T15:53:49.171Z{"msg":"Crucible stats registered with UUID: 9ce53551-31f5-4e3b-bcc4-51e91d12ddf7","v":0,"name":"crucible","level":30,"time":"2025-01-21T15:53:48.703116038Z","hostname":"w-01JJ4RN3GTHENBNQ4DERAKAPSN","pid":1241,"session_id":"4c3e748d-cb23-4fb0-93a5-084c609e3dcb"}
3132025-01-21T15:53:49.171Z{"msg":"could not find Downstairs address for Nexus","v":0,"name":"crucible","level":40,"time":"2025-01-21T15:53:48.703144136Z","hostname":"w-01JJ4RN3GTHENBNQ4DERAKAPSN","pid":1241,"session_id":"4c3e748d-cb23-4fb0-93a5-084c609e3dcb"}
3142025-01-21T15:53:49.174Z{"msg":"Downstairs in volume = 6","v":0,"name":"crucible","level":30,"time":"2025-01-21T15:53:48.703741824Z","hostname":"w-01JJ4RN3GTHENBNQ4DERAKAPSN","pid":1241,"task":"crutest"}
3152025-01-21T15:53:49.174Z{"msg":"The guest has requested activation with gen:32","v":0,"name":"crucible","level":30,"time":"2025-01-21T15:53:48.703795482Z","hostname":"w-01JJ4RN3GTHENBNQ4DERAKAPSN","pid":1241}
3162025-01-21T15:53:49.174Z{"msg":"9ce53551-31f5-4e3b-bcc4-51e91d12ddf7 active request set","v":0,"name":"crucible","level":30,"time":"2025-01-21T15:53:48.703826781Z","hostname":"w-01JJ4RN3GTHENBNQ4DERAKAPSN","pid":1241,"session_id":"037c1c20-617c-4383-b5a8-714c2ec1ec2f"}
3172025-01-21T15:53:49.174Z{"msg":"sending connect oneshot to client","v":0,"name":"crucible","level":30,"time":"2025-01-21T15:53:48.70385546Z","hostname":"w-01JJ4RN3GTHENBNQ4DERAKAPSN","pid":1241,"client":"0","":"downstairs","session_id":"037c1c20-617c-4383-b5a8-714c2ec1ec2f"}
3182025-01-21T15:53:49.174Z{"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-21T15:53:48.703900368Z","hostname":"w-01JJ4RN3GTHENBNQ4DERAKAPSN","pid":1241,"client":"0","":"downstairs","session_id":"037c1c20-617c-4383-b5a8-714c2ec1ec2f"}
3192025-01-21T15:53:49.174Z{"msg":"sending connect oneshot to client","v":0,"name":"crucible","level":30,"time":"2025-01-21T15:53:48.703933977Z","hostname":"w-01JJ4RN3GTHENBNQ4DERAKAPSN","pid":1241,"client":"1","":"downstairs","session_id":"037c1c20-617c-4383-b5a8-714c2ec1ec2f"}
3202025-01-21T15:53:49.174Z{"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-21T15:53:48.703959465Z","hostname":"w-01JJ4RN3GTHENBNQ4DERAKAPSN","pid":1241,"client":"1","":"downstairs","session_id":"037c1c20-617c-4383-b5a8-714c2ec1ec2f"}
3212025-01-21T15:53:49.174Z{"msg":"sending connect oneshot to client","v":0,"name":"crucible","level":30,"time":"2025-01-21T15:53:48.704026373Z","hostname":"w-01JJ4RN3GTHENBNQ4DERAKAPSN","pid":1241,"client":"2","":"downstairs","session_id":"037c1c20-617c-4383-b5a8-714c2ec1ec2f"}
3222025-01-21T15:53:49.174Z{"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-21T15:53:48.704052812Z","hostname":"w-01JJ4RN3GTHENBNQ4DERAKAPSN","pid":1241,"client":"2","":"downstairs","session_id":"037c1c20-617c-4383-b5a8-714c2ec1ec2f"}
3232025-01-21T15:53:49.174Z{"msg":"connecting to 127.0.0.1:8830","v":0,"name":"crucible","level":30,"time":"2025-01-21T15:53:48.704076571Z","hostname":"w-01JJ4RN3GTHENBNQ4DERAKAPSN","pid":1241,"":"io task","client":"2","":"downstairs","session_id":"037c1c20-617c-4383-b5a8-714c2ec1ec2f"}
3242025-01-21T15:53:49.174Z{"msg":"connecting to 127.0.0.1:8810","v":0,"name":"crucible","level":30,"time":"2025-01-21T15:53:48.70411147Z","hostname":"w-01JJ4RN3GTHENBNQ4DERAKAPSN","pid":1241,"":"io task","client":"0","":"downstairs","session_id":"037c1c20-617c-4383-b5a8-714c2ec1ec2f"}
3252025-01-21T15:53:49.174Z{"msg":"connecting to 127.0.0.1:8820","v":0,"name":"crucible","level":30,"time":"2025-01-21T15:53:48.704137299Z","hostname":"w-01JJ4RN3GTHENBNQ4DERAKAPSN","pid":1241,"":"io task","client":"1","":"downstairs","session_id":"037c1c20-617c-4383-b5a8-714c2ec1ec2f"}
3262025-01-21T15:53:49.174Z{"msg":"ds_connection connected from Ok(127.0.0.1:61486)","v":0,"name":"crucible","level":30,"time":"2025-01-21T15:53:48.704160578Z","hostname":"w-01JJ4RN3GTHENBNQ4DERAKAPSN","pid":1241,"":"io task","client":"2","":"downstairs","session_id":"037c1c20-617c-4383-b5a8-714c2ec1ec2f"}
3272025-01-21T15:53:49.174Z{"msg":"ds_connection connected from Ok(127.0.0.1:51274)","v":0,"name":"crucible","level":30,"time":"2025-01-21T15:53:48.704185227Z","hostname":"w-01JJ4RN3GTHENBNQ4DERAKAPSN","pid":1241,"":"io task","client":"1","":"downstairs","session_id":"037c1c20-617c-4383-b5a8-714c2ec1ec2f"}
3282025-01-21T15:53:49.174Z{"msg":"ds_connection connected from Ok(127.0.0.1:46631)","v":0,"name":"crucible","level":30,"time":"2025-01-21T15:53:48.704314592Z","hostname":"w-01JJ4RN3GTHENBNQ4DERAKAPSN","pid":1241,"":"io task","client":"0","":"downstairs","session_id":"037c1c20-617c-4383-b5a8-714c2ec1ec2f"}
3292025-01-21T15:53:49.174Z{"msg":"version negotiation from state Connecting { state: WaitForPromote, mode: New }","v":0,"name":"crucible","level":30,"time":"2025-01-21T15:53:48.704841292Z","hostname":"w-01JJ4RN3GTHENBNQ4DERAKAPSN","pid":1241,"client":"1","":"downstairs","session_id":"037c1c20-617c-4383-b5a8-714c2ec1ec2f"}
3302025-01-21T15:53:49.174Z{"msg":"version negotiation from state Connecting { state: WaitForPromote, mode: New }","v":0,"name":"crucible","level":30,"time":"2025-01-21T15:53:48.704910059Z","hostname":"w-01JJ4RN3GTHENBNQ4DERAKAPSN","pid":1241,"client":"2","":"downstairs","session_id":"037c1c20-617c-4383-b5a8-714c2ec1ec2f"}
3312025-01-21T15:53:49.174Z{"msg":"version negotiation from state Connecting { state: WaitForPromote, mode: New }","v":0,"name":"crucible","level":30,"time":"2025-01-21T15:53:48.704962747Z","hostname":"w-01JJ4RN3GTHENBNQ4DERAKAPSN","pid":1241,"client":"0","":"downstairs","session_id":"037c1c20-617c-4383-b5a8-714c2ec1ec2f"}
3322025-01-21T15:53:49.174Z{"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-21T15:53:48.705461278Z","hostname":"w-01JJ4RN3GTHENBNQ4DERAKAPSN","pid":1241,"client":"1","":"downstairs","session_id":"037c1c20-617c-4383-b5a8-714c2ec1ec2f"}
3332025-01-21T15:53:49.174Z{"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-21T15:53:48.705502397Z","hostname":"w-01JJ4RN3GTHENBNQ4DERAKAPSN","pid":1241,"client":"0","":"downstairs","session_id":"037c1c20-617c-4383-b5a8-714c2ec1ec2f"}
3342025-01-21T15:53:49.174Z{"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-21T15:53:48.705586034Z","hostname":"w-01JJ4RN3GTHENBNQ4DERAKAPSN","pid":1241,"client":"2","":"downstairs","session_id":"037c1c20-617c-4383-b5a8-714c2ec1ec2f"}
3352025-01-21T15:53:49.174Z{"msg":"Waiting for more clients to be ready","v":0,"name":"crucible","level":30,"time":"2025-01-21T15:53:48.70592889Z","hostname":"w-01JJ4RN3GTHENBNQ4DERAKAPSN","pid":1241,"session_id":"037c1c20-617c-4383-b5a8-714c2ec1ec2f"}
3362025-01-21T15:53:49.174Z{"msg":"Waiting for more clients to be ready","v":0,"name":"crucible","level":30,"time":"2025-01-21T15:53:48.705963009Z","hostname":"w-01JJ4RN3GTHENBNQ4DERAKAPSN","pid":1241,"session_id":"037c1c20-617c-4383-b5a8-714c2ec1ec2f"}
3372025-01-21T15:53:49.174Z{"msg":"[0]R flush_numbers: [3997, 3997, 3997, 3997, 3997]","v":0,"name":"crucible","level":30,"time":"2025-01-21T15:53:48.706016987Z","hostname":"w-01JJ4RN3GTHENBNQ4DERAKAPSN","pid":1241,"":"downstairs","":"downstairs","session_id":"037c1c20-617c-4383-b5a8-714c2ec1ec2f"}
3382025-01-21T15:53:49.174Z{"msg":"[0]R generation: [31, 31, 31, 31, 31]","v":0,"name":"crucible","level":30,"time":"2025-01-21T15:53:48.706057165Z","hostname":"w-01JJ4RN3GTHENBNQ4DERAKAPSN","pid":1241,"":"downstairs","":"downstairs","session_id":"037c1c20-617c-4383-b5a8-714c2ec1ec2f"}
3392025-01-21T15:53:49.174Z{"msg":"[0]R dirty: [false, false, false, false, false]","v":0,"name":"crucible","level":30,"time":"2025-01-21T15:53:48.706073545Z","hostname":"w-01JJ4RN3GTHENBNQ4DERAKAPSN","pid":1241,"":"downstairs","":"downstairs","session_id":"037c1c20-617c-4383-b5a8-714c2ec1ec2f"}
3402025-01-21T15:53:49.175Z{"msg":"[1]R flush_numbers: [3997, 3997, 3997, 3997, 3997]","v":0,"name":"crucible","level":30,"time":"2025-01-21T15:53:48.706089744Z","hostname":"w-01JJ4RN3GTHENBNQ4DERAKAPSN","pid":1241,"":"downstairs","":"downstairs","session_id":"037c1c20-617c-4383-b5a8-714c2ec1ec2f"}
3412025-01-21T15:53:49.175Z{"msg":"[1]R generation: [31, 31, 31, 31, 31]","v":0,"name":"crucible","level":30,"time":"2025-01-21T15:53:48.706103434Z","hostname":"w-01JJ4RN3GTHENBNQ4DERAKAPSN","pid":1241,"":"downstairs","":"downstairs","session_id":"037c1c20-617c-4383-b5a8-714c2ec1ec2f"}
3422025-01-21T15:53:49.175Z{"msg":"[1]R dirty: [false, false, false, false, false]","v":0,"name":"crucible","level":30,"time":"2025-01-21T15:53:48.706125523Z","hostname":"w-01JJ4RN3GTHENBNQ4DERAKAPSN","pid":1241,"":"downstairs","":"downstairs","session_id":"037c1c20-617c-4383-b5a8-714c2ec1ec2f"}
3432025-01-21T15:53:49.175Z{"msg":"[2]R flush_numbers: [3997, 3997, 3997, 3997, 3997]","v":0,"name":"crucible","level":30,"time":"2025-01-21T15:53:48.706140102Z","hostname":"w-01JJ4RN3GTHENBNQ4DERAKAPSN","pid":1241,"":"downstairs","":"downstairs","session_id":"037c1c20-617c-4383-b5a8-714c2ec1ec2f"}
3442025-01-21T15:53:49.175Z{"msg":"[2]R generation: [31, 31, 31, 31, 31]","v":0,"name":"crucible","level":30,"time":"2025-01-21T15:53:48.706153952Z","hostname":"w-01JJ4RN3GTHENBNQ4DERAKAPSN","pid":1241,"":"downstairs","":"downstairs","session_id":"037c1c20-617c-4383-b5a8-714c2ec1ec2f"}
3452025-01-21T15:53:49.175Z{"msg":"[2]R dirty: [false, false, false, false, false]","v":0,"name":"crucible","level":30,"time":"2025-01-21T15:53:48.706166931Z","hostname":"w-01JJ4RN3GTHENBNQ4DERAKAPSN","pid":1241,"":"downstairs","":"downstairs","session_id":"037c1c20-617c-4383-b5a8-714c2ec1ec2f"}
3462025-01-21T15:53:49.175Z{"msg":"Max found gen is 32","v":0,"name":"crucible","level":30,"time":"2025-01-21T15:53:48.706186911Z","hostname":"w-01JJ4RN3GTHENBNQ4DERAKAPSN","pid":1241,"":"downstairs","":"downstairs","session_id":"037c1c20-617c-4383-b5a8-714c2ec1ec2f"}
3472025-01-21T15:53:49.175Z{"msg":"Generation requested: 32 >= found:32","v":0,"name":"crucible","level":30,"time":"2025-01-21T15:53:48.70620056Z","hostname":"w-01JJ4RN3GTHENBNQ4DERAKAPSN","pid":1241,"":"downstairs","":"downstairs","session_id":"037c1c20-617c-4383-b5a8-714c2ec1ec2f"}
3482025-01-21T15:53:49.175Z{"msg":"Next flush: 3998","v":0,"name":"crucible","level":30,"time":"2025-01-21T15:53:48.706243149Z","hostname":"w-01JJ4RN3GTHENBNQ4DERAKAPSN","pid":1241,"":"downstairs","":"downstairs","session_id":"037c1c20-617c-4383-b5a8-714c2ec1ec2f"}
3492025-01-21T15:53:49.175Z{"msg":"All extents match","v":0,"name":"crucible","level":30,"time":"2025-01-21T15:53:48.706257048Z","hostname":"w-01JJ4RN3GTHENBNQ4DERAKAPSN","pid":1241,"":"downstairs","":"downstairs","session_id":"037c1c20-617c-4383-b5a8-714c2ec1ec2f"}
3502025-01-21T15:53:49.175Z{"msg":"No downstairs reconciliation required","v":0,"name":"crucible","level":30,"time":"2025-01-21T15:53:48.706269997Z","hostname":"w-01JJ4RN3GTHENBNQ4DERAKAPSN","pid":1241,"session_id":"037c1c20-617c-4383-b5a8-714c2ec1ec2f"}
3512025-01-21T15:53:49.175Z{"msg":"Transition from WaitQuorum to Active","v":0,"name":"crucible","level":30,"time":"2025-01-21T15:53:48.706283017Z","hostname":"w-01JJ4RN3GTHENBNQ4DERAKAPSN","pid":1241,"client":"0","":"downstairs","session_id":"037c1c20-617c-4383-b5a8-714c2ec1ec2f"}
3522025-01-21T15:53:49.175Z{"msg":"Transition from WaitQuorum to Active","v":0,"name":"crucible","level":30,"time":"2025-01-21T15:53:48.706305466Z","hostname":"w-01JJ4RN3GTHENBNQ4DERAKAPSN","pid":1241,"client":"1","":"downstairs","session_id":"037c1c20-617c-4383-b5a8-714c2ec1ec2f"}
3532025-01-21T15:53:49.175Z{"msg":"Transition from WaitQuorum to Active","v":0,"name":"crucible","level":30,"time":"2025-01-21T15:53:48.706338095Z","hostname":"w-01JJ4RN3GTHENBNQ4DERAKAPSN","pid":1241,"client":"2","":"downstairs","session_id":"037c1c20-617c-4383-b5a8-714c2ec1ec2f"}
3542025-01-21T15:53:49.175Z{"msg":"All required reconciliation work is completed","v":0,"name":"crucible","level":30,"time":"2025-01-21T15:53:48.706364314Z","hostname":"w-01JJ4RN3GTHENBNQ4DERAKAPSN","pid":1241,"session_id":"037c1c20-617c-4383-b5a8-714c2ec1ec2f"}
3552025-01-21T15:53:49.175Z{"msg":"Set Downstairs and Upstairs active after reconciliation","v":0,"name":"crucible","level":30,"time":"2025-01-21T15:53:48.706387093Z","hostname":"w-01JJ4RN3GTHENBNQ4DERAKAPSN","pid":1241,"session_id":"037c1c20-617c-4383-b5a8-714c2ec1ec2f"}
3562025-01-21T15:53:49.175Z{"msg":"9ce53551-31f5-4e3b-bcc4-51e91d12ddf7 is now active with session: 037c1c20-617c-4383-b5a8-714c2ec1ec2f","v":0,"name":"crucible","level":30,"time":"2025-01-21T15:53:48.706410532Z","hostname":"w-01JJ4RN3GTHENBNQ4DERAKAPSN","pid":1241,"session_id":"037c1c20-617c-4383-b5a8-714c2ec1ec2f"}
3572025-01-21T15:53:49.178Z{"msg":"Set Active after no reconciliation","v":0,"name":"crucible","level":30,"time":"2025-01-21T15:53:48.706543687Z","hostname":"w-01JJ4RN3GTHENBNQ4DERAKAPSN","pid":1241,"session_id":"037c1c20-617c-4383-b5a8-714c2ec1ec2f"}
3582025-01-21T15:53:49.178Z{"msg":"The guest has finished waiting for activation with:32","v":0,"name":"crucible","level":30,"time":"2025-01-21T15:53:48.706596895Z","hostname":"w-01JJ4RN3GTHENBNQ4DERAKAPSN","pid":1241}
3592025-01-21T15:53:49.178Z{"msg":"The guest has requested activation with gen:32","v":0,"name":"crucible","level":30,"time":"2025-01-21T15:53:48.706674612Z","hostname":"w-01JJ4RN3GTHENBNQ4DERAKAPSN","pid":1241}
3602025-01-21T15:53:49.178Z{"msg":"9ce53551-31f5-4e3b-bcc4-51e91d12ddf7 active request set","v":0,"name":"crucible","level":30,"time":"2025-01-21T15:53:48.706704691Z","hostname":"w-01JJ4RN3GTHENBNQ4DERAKAPSN","pid":1241,"session_id":"4c3e748d-cb23-4fb0-93a5-084c609e3dcb"}
3612025-01-21T15:53:49.179Z{"msg":"sending connect oneshot to client","v":0,"name":"crucible","level":30,"time":"2025-01-21T15:53:48.70673169Z","hostname":"w-01JJ4RN3GTHENBNQ4DERAKAPSN","pid":1241,"client":"0","":"downstairs","session_id":"4c3e748d-cb23-4fb0-93a5-084c609e3dcb"}
3622025-01-21T15:53:49.179Z{"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-21T15:53:48.706761489Z","hostname":"w-01JJ4RN3GTHENBNQ4DERAKAPSN","pid":1241,"client":"0","":"downstairs","session_id":"4c3e748d-cb23-4fb0-93a5-084c609e3dcb"}
3632025-01-21T15:53:49.179Z{"msg":"sending connect oneshot to client","v":0,"name":"crucible","level":30,"time":"2025-01-21T15:53:48.706804697Z","hostname":"w-01JJ4RN3GTHENBNQ4DERAKAPSN","pid":1241,"client":"1","":"downstairs","session_id":"4c3e748d-cb23-4fb0-93a5-084c609e3dcb"}
3642025-01-21T15:53:49.179Z{"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-21T15:53:48.706836516Z","hostname":"w-01JJ4RN3GTHENBNQ4DERAKAPSN","pid":1241,"client":"1","":"downstairs","session_id":"4c3e748d-cb23-4fb0-93a5-084c609e3dcb"}
3652025-01-21T15:53:49.179Z{"msg":"sending connect oneshot to client","v":0,"name":"crucible","level":30,"time":"2025-01-21T15:53:48.706860995Z","hostname":"w-01JJ4RN3GTHENBNQ4DERAKAPSN","pid":1241,"client":"2","":"downstairs","session_id":"4c3e748d-cb23-4fb0-93a5-084c609e3dcb"}
3662025-01-21T15:53:49.179Z{"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-21T15:53:48.706895534Z","hostname":"w-01JJ4RN3GTHENBNQ4DERAKAPSN","pid":1241,"client":"2","":"downstairs","session_id":"4c3e748d-cb23-4fb0-93a5-084c609e3dcb"}
3672025-01-21T15:53:49.179Z{"msg":"connecting to 127.0.0.1:8860","v":0,"name":"crucible","level":30,"time":"2025-01-21T15:53:48.706919313Z","hostname":"w-01JJ4RN3GTHENBNQ4DERAKAPSN","pid":1241,"":"io task","client":"2","":"downstairs","session_id":"4c3e748d-cb23-4fb0-93a5-084c609e3dcb"}
3682025-01-21T15:53:49.179Z{"msg":"connecting to 127.0.0.1:8840","v":0,"name":"crucible","level":30,"time":"2025-01-21T15:53:48.706946082Z","hostname":"w-01JJ4RN3GTHENBNQ4DERAKAPSN","pid":1241,"":"io task","client":"0","":"downstairs","session_id":"4c3e748d-cb23-4fb0-93a5-084c609e3dcb"}
3692025-01-21T15:53:49.179Z{"msg":"connecting to 127.0.0.1:8850","v":0,"name":"crucible","level":30,"time":"2025-01-21T15:53:48.706969381Z","hostname":"w-01JJ4RN3GTHENBNQ4DERAKAPSN","pid":1241,"":"io task","client":"1","":"downstairs","session_id":"4c3e748d-cb23-4fb0-93a5-084c609e3dcb"}
3702025-01-21T15:53:49.179Z{"msg":"ds_connection connected from Ok(127.0.0.1:45177)","v":0,"name":"crucible","level":30,"time":"2025-01-21T15:53:48.70700354Z","hostname":"w-01JJ4RN3GTHENBNQ4DERAKAPSN","pid":1241,"":"io task","client":"0","":"downstairs","session_id":"4c3e748d-cb23-4fb0-93a5-084c609e3dcb"}
3712025-01-21T15:53:49.179Z{"msg":"ds_connection connected from Ok(127.0.0.1:55313)","v":0,"name":"crucible","level":30,"time":"2025-01-21T15:53:48.707032578Z","hostname":"w-01JJ4RN3GTHENBNQ4DERAKAPSN","pid":1241,"":"io task","client":"2","":"downstairs","session_id":"4c3e748d-cb23-4fb0-93a5-084c609e3dcb"}
3722025-01-21T15:53:49.179Z{"msg":"ds_connection connected from Ok(127.0.0.1:60691)","v":0,"name":"crucible","level":30,"time":"2025-01-21T15:53:48.707087306Z","hostname":"w-01JJ4RN3GTHENBNQ4DERAKAPSN","pid":1241,"":"io task","client":"1","":"downstairs","session_id":"4c3e748d-cb23-4fb0-93a5-084c609e3dcb"}
3732025-01-21T15:53:49.179Z{"msg":"version negotiation from state Connecting { state: WaitForPromote, mode: New }","v":0,"name":"crucible","level":30,"time":"2025-01-21T15:53:48.707139894Z","hostname":"w-01JJ4RN3GTHENBNQ4DERAKAPSN","pid":1241,"client":"2","":"downstairs","session_id":"4c3e748d-cb23-4fb0-93a5-084c609e3dcb"}
3742025-01-21T15:53:49.179Z{"msg":"version negotiation from state Connecting { state: WaitForPromote, mode: New }","v":0,"name":"crucible","level":30,"time":"2025-01-21T15:53:48.707169513Z","hostname":"w-01JJ4RN3GTHENBNQ4DERAKAPSN","pid":1241,"client":"1","":"downstairs","session_id":"4c3e748d-cb23-4fb0-93a5-084c609e3dcb"}
3752025-01-21T15:53:49.179Z{"msg":"version negotiation from state Connecting { state: WaitForPromote, mode: New }","v":0,"name":"crucible","level":30,"time":"2025-01-21T15:53:48.70726861Z","hostname":"w-01JJ4RN3GTHENBNQ4DERAKAPSN","pid":1241,"client":"0","":"downstairs","session_id":"4c3e748d-cb23-4fb0-93a5-084c609e3dcb"}
3762025-01-21T15:53:49.179Z{"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-21T15:53:48.707623496Z","hostname":"w-01JJ4RN3GTHENBNQ4DERAKAPSN","pid":1241,"client":"2","":"downstairs","session_id":"4c3e748d-cb23-4fb0-93a5-084c609e3dcb"}
3772025-01-21T15:53:49.179Z{"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-21T15:53:48.707676594Z","hostname":"w-01JJ4RN3GTHENBNQ4DERAKAPSN","pid":1241,"client":"1","":"downstairs","session_id":"4c3e748d-cb23-4fb0-93a5-084c609e3dcb"}
3782025-01-21T15:53:49.179Z{"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-21T15:53:48.707801629Z","hostname":"w-01JJ4RN3GTHENBNQ4DERAKAPSN","pid":1241,"client":"0","":"downstairs","session_id":"4c3e748d-cb23-4fb0-93a5-084c609e3dcb"}
3792025-01-21T15:53:49.179Z{"msg":"Waiting for more clients to be ready","v":0,"name":"crucible","level":30,"time":"2025-01-21T15:53:48.70802615Z","hostname":"w-01JJ4RN3GTHENBNQ4DERAKAPSN","pid":1241,"session_id":"4c3e748d-cb23-4fb0-93a5-084c609e3dcb"}
3802025-01-21T15:53:49.179Z{"msg":"Waiting for more clients to be ready","v":0,"name":"crucible","level":30,"time":"2025-01-21T15:53:48.708162095Z","hostname":"w-01JJ4RN3GTHENBNQ4DERAKAPSN","pid":1241,"session_id":"4c3e748d-cb23-4fb0-93a5-084c609e3dcb"}
3812025-01-21T15:53:49.179Z{"msg":"[0]R flush_numbers: [5319, 5319, 5319, 5319, 5319]","v":0,"name":"crucible","level":30,"time":"2025-01-21T15:53:48.708196774Z","hostname":"w-01JJ4RN3GTHENBNQ4DERAKAPSN","pid":1241,"":"downstairs","":"downstairs","session_id":"4c3e748d-cb23-4fb0-93a5-084c609e3dcb"}
3822025-01-21T15:53:49.179Z{"msg":"[0]R generation: [31, 31, 31, 31, 31]","v":0,"name":"crucible","level":30,"time":"2025-01-21T15:53:48.708212843Z","hostname":"w-01JJ4RN3GTHENBNQ4DERAKAPSN","pid":1241,"":"downstairs","":"downstairs","session_id":"4c3e748d-cb23-4fb0-93a5-084c609e3dcb"}
3832025-01-21T15:53:49.179Z{"msg":"[0]R dirty: [false, false, false, false, false]","v":0,"name":"crucible","level":30,"time":"2025-01-21T15:53:48.708227043Z","hostname":"w-01JJ4RN3GTHENBNQ4DERAKAPSN","pid":1241,"":"downstairs","":"downstairs","session_id":"4c3e748d-cb23-4fb0-93a5-084c609e3dcb"}
3842025-01-21T15:53:49.179Z{"msg":"[1]R flush_numbers: [5319, 5319, 5319, 5319, 5319]","v":0,"name":"crucible","level":30,"time":"2025-01-21T15:53:48.708240082Z","hostname":"w-01JJ4RN3GTHENBNQ4DERAKAPSN","pid":1241,"":"downstairs","":"downstairs","session_id":"4c3e748d-cb23-4fb0-93a5-084c609e3dcb"}
3852025-01-21T15:53:49.179Z{"msg":"[1]R generation: [31, 31, 31, 31, 31]","v":0,"name":"crucible","level":30,"time":"2025-01-21T15:53:48.708252752Z","hostname":"w-01JJ4RN3GTHENBNQ4DERAKAPSN","pid":1241,"":"downstairs","":"downstairs","session_id":"4c3e748d-cb23-4fb0-93a5-084c609e3dcb"}
3862025-01-21T15:53:49.179Z{"msg":"[1]R dirty: [false, false, false, false, false]","v":0,"name":"crucible","level":30,"time":"2025-01-21T15:53:48.708273481Z","hostname":"w-01JJ4RN3GTHENBNQ4DERAKAPSN","pid":1241,"":"downstairs","":"downstairs","session_id":"4c3e748d-cb23-4fb0-93a5-084c609e3dcb"}
3872025-01-21T15:53:49.179ZWait for a query_work_queue command to finish before sending IO
3882025-01-21T15:53:49.179Z{"msg":"[2]R flush_numbers: [5319, 5319, 5319, 5319, 5319]","v":0,"name":"crucible","level":30,"time":"2025-01-21T15:53:48.708322209Z","hostname":"w-01JJ4RN3GTHENBNQ4DERAKAPSN","pid":1241,"":"downstairs","":"downstairs","session_id":"4c3e748d-cb23-4fb0-93a5-084c609e3dcb"}
3892025-01-21T15:53:49.179Z{"msg":"[2]R generation: [31, 31, 31, 31, 31]","v":0,"name":"crucible","level":30,"time":"2025-01-21T15:53:48.708338109Z","hostname":"w-01JJ4RN3GTHENBNQ4DERAKAPSN","pid":1241,"":"downstairs","":"downstairs","session_id":"4c3e748d-cb23-4fb0-93a5-084c609e3dcb"}
3902025-01-21T15:53:49.179Z{"msg":"[2]R dirty: [false, false, false, false, false]","v":0,"name":"crucible","level":30,"time":"2025-01-21T15:53:48.708351058Z","hostname":"w-01JJ4RN3GTHENBNQ4DERAKAPSN","pid":1241,"":"downstairs","":"downstairs","session_id":"4c3e748d-cb23-4fb0-93a5-084c609e3dcb"}
3912025-01-21T15:53:49.179Z{"msg":"Max found gen is 32","v":0,"name":"crucible","level":30,"time":"2025-01-21T15:53:48.708371108Z","hostname":"w-01JJ4RN3GTHENBNQ4DERAKAPSN","pid":1241,"":"downstairs","":"downstairs","session_id":"4c3e748d-cb23-4fb0-93a5-084c609e3dcb"}
3922025-01-21T15:53:49.179Z{"msg":"Generation requested: 32 >= found:32","v":0,"name":"crucible","level":30,"time":"2025-01-21T15:53:48.708384227Z","hostname":"w-01JJ4RN3GTHENBNQ4DERAKAPSN","pid":1241,"":"downstairs","":"downstairs","session_id":"4c3e748d-cb23-4fb0-93a5-084c609e3dcb"}
3932025-01-21T15:53:49.179Z{"msg":"Next flush: 5320","v":0,"name":"crucible","level":30,"time":"2025-01-21T15:53:48.708403216Z","hostname":"w-01JJ4RN3GTHENBNQ4DERAKAPSN","pid":1241,"":"downstairs","":"downstairs","session_id":"4c3e748d-cb23-4fb0-93a5-084c609e3dcb"}
3942025-01-21T15:53:49.179Z{"msg":"All extents match","v":0,"name":"crucible","level":30,"time":"2025-01-21T15:53:48.708416766Z","hostname":"w-01JJ4RN3GTHENBNQ4DERAKAPSN","pid":1241,"":"downstairs","":"downstairs","session_id":"4c3e748d-cb23-4fb0-93a5-084c609e3dcb"}
3952025-01-21T15:53:49.179Z{"msg":"No downstairs reconciliation required","v":0,"name":"crucible","level":30,"time":"2025-01-21T15:53:48.708447254Z","hostname":"w-01JJ4RN3GTHENBNQ4DERAKAPSN","pid":1241,"session_id":"4c3e748d-cb23-4fb0-93a5-084c609e3dcb"}
3962025-01-21T15:53:49.179Z{"msg":"Transition from WaitQuorum to Active","v":0,"name":"crucible","level":30,"time":"2025-01-21T15:53:48.708467784Z","hostname":"w-01JJ4RN3GTHENBNQ4DERAKAPSN","pid":1241,"client":"0","":"downstairs","session_id":"4c3e748d-cb23-4fb0-93a5-084c609e3dcb"}
3972025-01-21T15:53:49.179Z{"msg":"Transition from WaitQuorum to Active","v":0,"name":"crucible","level":30,"time":"2025-01-21T15:53:48.708506812Z","hostname":"w-01JJ4RN3GTHENBNQ4DERAKAPSN","pid":1241,"client":"1","":"downstairs","session_id":"4c3e748d-cb23-4fb0-93a5-084c609e3dcb"}
3982025-01-21T15:53:49.179Z{"msg":"Transition from WaitQuorum to Active","v":0,"name":"crucible","level":30,"time":"2025-01-21T15:53:48.708544591Z","hostname":"w-01JJ4RN3GTHENBNQ4DERAKAPSN","pid":1241,"client":"2","":"downstairs","session_id":"4c3e748d-cb23-4fb0-93a5-084c609e3dcb"}
3992025-01-21T15:53:49.180Z{"msg":"All required reconciliation work is completed","v":0,"name":"crucible","level":30,"time":"2025-01-21T15:53:48.708581349Z","hostname":"w-01JJ4RN3GTHENBNQ4DERAKAPSN","pid":1241,"session_id":"4c3e748d-cb23-4fb0-93a5-084c609e3dcb"}
4002025-01-21T15:53:49.180Z{"msg":"Set Downstairs and Upstairs active after reconciliation","v":0,"name":"crucible","level":30,"time":"2025-01-21T15:53:48.708615808Z","hostname":"w-01JJ4RN3GTHENBNQ4DERAKAPSN","pid":1241,"session_id":"4c3e748d-cb23-4fb0-93a5-084c609e3dcb"}
4012025-01-21T15:53:49.180Z{"msg":"9ce53551-31f5-4e3b-bcc4-51e91d12ddf7 is now active with session: 4c3e748d-cb23-4fb0-93a5-084c609e3dcb","v":0,"name":"crucible","level":30,"time":"2025-01-21T15:53:48.708654617Z","hostname":"w-01JJ4RN3GTHENBNQ4DERAKAPSN","pid":1241,"session_id":"4c3e748d-cb23-4fb0-93a5-084c609e3dcb"}
4022025-01-21T15:53:49.180Z{"msg":"Set Active after no reconciliation","v":0,"name":"crucible","level":30,"time":"2025-01-21T15:53:48.708689625Z","hostname":"w-01JJ4RN3GTHENBNQ4DERAKAPSN","pid":1241,"session_id":"4c3e748d-cb23-4fb0-93a5-084c609e3dcb"}
4032025-01-21T15:53:49.180Z{"msg":"The guest has finished waiting for activation with:32","v":0,"name":"crucible","level":30Disk: sv:2 bs:4096 ts:409600 tb:100 max_io:100 or 409600
4042025-01-21T15:53:49.180Z,"time":"2025-01-21T15:53:48.708726694Z","hostname":"w-01JJ4RN3GTHENBNQ4DERAKAPSN","pid":1241}
4052025-01-21T15:53:49.180ZLoading write count information from file "/var/tmp/test_up-build/verify_file"
4062025-01-21T15:53:49.180ZFill test
4072025-01-21T15:53:49.219ZRead and Verify all blocks (0..100 range:false)
4082025-01-21T15:53:49.298ZWrote out file "/var/tmp/test_up-build/verify_file"
4092025-01-21T15:53:49.298ZCLIENT: Tests done. All submitted work has been ACK'd
4102025-01-21T15:53:49.301Z----------------------------------------------------------------
4112025-01-21T15:53:49.301Z Crucible gen:32 GIO:true work queues: Upstairs:0 downstairs:1
4122025-01-21T15:53:49.301ZStates: Active Active Active
4132025-01-21T15:53:49.301ZJOBID ACK TYPE BKS/EXT DS:0 DS:1 DS:2 REPLAY
4142025-01-21T15:53:49.301Z 1002 Acked Read 50 Done Done Done false
4152025-01-21T15:53:49.301Z STATES DS:0 DS:1 DS:2 TOTAL
4162025-01-21T15:53:49.301Z Sent 0 0 0 0
4172025-01-21T15:53:49.301Z Done 1 1 1 3
4182025-01-21T15:53:49.301Z Skipped 0 0 0 0
4192025-01-21T15:53:49.301Z Error 0 0 0 0
4202025-01-21T15:53:49.301ZLast Flush: 1001 1001 1001
4212025-01-21T15:53:49.301ZDownstairs last five completed: 1001 1000
4222025-01-21T15:53:49.301ZUpstairs last five completed: 1002 1001 1000
4232025-01-21T15:53:49.301Z----------------------------------------------------------------
4242025-01-21T15:53:49.301Z Crucible gen:32 GIO:true work queues: Upstairs:0 downstairs:1
4252025-01-21T15:53:49.301ZStates: Active Active Active
4262025-01-21T15:53:49.301ZJOBID ACK TYPE BKS/EXT DS:0 DS:1 DS:2 REPLAY
4272025-01-21T15:53:49.301Z 1002 Acked Read 50 Done Done Done false
4282025-01-21T15:53:49.301Z STATES DS:0 DS:1 DS:2 TOTAL
4292025-01-21T15:53:49.301Z Sent 0 0 0 0
4302025-01-21T15:53:49.301Z Done 1 1 1 3
4312025-01-21T15:53:49.301Z Skipped 0 0 0 0
4322025-01-21T15:53:49.301Z Error 0 0 0 0
4332025-01-21T15:53:49.301ZLast Flush: 1001 1001 1001
4342025-01-21T15:53:49.301ZDownstairs last five completed: 1001 1000
4352025-01-21T15:53:49.301ZUpstairs last five completed: 1002 1001 1000
4362025-01-21T15:53:49.302ZCLIENT: Up:0 ds:2 act:6
4372025-01-21T15:53:53.300Z----------------------------------------------------------------
4382025-01-21T15:53:53.300Z Crucible gen:32 GIO:true work queues: Upstairs:0 downstairs:0
4392025-01-21T15:53:53.301ZDownstairs last five completed: 1003 1002 1001 1000
4402025-01-21T15:53:53.301ZUpstairs last five completed: 1003 1002 1001 1000
4412025-01-21T15:53:53.303Z----------------------------------------------------------------
4422025-01-21T15:53:53.303Z Crucible gen:32 GIO:true work queues: Upstairs:0 downstairs:0
4432025-01-21T15:53:53.303ZDownstairs last five completed: 1003 1002 1001 1000
4442025-01-21T15:53:53.303ZUpstairs last five completed: 1003 1002 1001 1000
4452025-01-21T15:53:53.303ZCLIENT: Up:0 ds:0 act:6
4462025-01-21T15:53:53.303ZCLIENT: All crucible jobs finished, exiting program
4472025-01-21T15:53:53.303Z{"msg":"Guest handle has been dropped","v":0,"name":"crucible","level":40,"time":"2025-01-21T15:53:52.833374993Z","hostname":"w-01JJ4RN3GTHENBNQ4DERAKAPSN","pid":1241}
4482025-01-21T15:53:53.308ZRepair part 1 passed
4492025-01-21T15:53:53.310Z
4502025-01-21T15:53:53.310ZKill the current downstairs
4512025-01-21T15:53:53.477ZDownstairs 2 stopped
4522025-01-21T15:53:53.477Zmv /var/tmp/test_up-build/8830 /var/tmp/test_up-build/new
4532025-01-21T15:53:53.480ZNow put back the original so we have a mismatch
4542025-01-21T15:53:53.480Zmv /var/tmp/test_up-build/previous /var/tmp/test_up-build/8830
4552025-01-21T15:53:53.482ZRestart downstairs with old directory
4562025-01-21T15:53:53.536Z/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-21T15:53:53.554ZEXT BLOCKS GEN0 GEN1 GEN2 FL0 FL1 FL2 D0 D1 D2 DIFF
4582025-01-21T15:53:53.557Z 0 000-009 32 32 31 3998 3998 3997 F F F <---
4592025-01-21T15:53:53.557Z 1 010-019 32 32 31 3998 3998 3997 F F F <---
4602025-01-21T15:53:53.557Z 2 020-029 32 32 31 3998 3998 3997 F F F <---
4612025-01-21T15:53:53.557Z 3 030-039 32 32 31 3998 3998 3997 F F F <---
4622025-01-21T15:53:53.557Z 4 040-049 32 32 31 3998 3998 3997 F F F <---
4632025-01-21T15:53:53.557ZMax gen: 32, Max flush: 3998
4642025-01-21T15:53:53.557ZError: Difference in extent metadata found!
4652025-01-21T15:53:53.560Zdump test found error as expected
4662025-01-21T15:53:53.560Z
4672025-01-21T15:53:53.560Z
4682025-01-21T15:53:53.560Z/var/tmp/bins/crutest verify --range -g 33 -q --key wR+F1olsh8k3doPjXFwJ2Zs1S4Z3J9BWk6o9Zds2Hdg= --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-21T15:53:53.615Z{"msg":"Use this region info from dsc: RegionExtentInfo { block_size: 4096, blocks_per_extent: 10, extent_count: 5 }","v":0,"name":"crucible","level":30,"time":"2025-01-21T15:53:53.147463938Z","hostname":"w-01JJ4RN3GTHENBNQ4DERAKAPSN","pid":1249,"task":"crutest"}
4702025-01-21T15:53:53.619Z{"msg":"dsc has 6 regions. This means 2 sub_volumes","v":0,"name":"crucible","level":30,"time":"2025-01-21T15:53:53.148040597Z","hostname":"w-01JJ4RN3GTHENBNQ4DERAKAPSN","pid":1249,"task":"crutest"}
4712025-01-21T15:53:53.619Z{"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-21T15:53:53.149625666Z","hostname":"w-01JJ4RN3GTHENBNQ4DERAKAPSN","pid":1249,"task":"crutest"}
4722025-01-21T15:53:53.619Z{"msg":"Upstairs starts","v":0,"name":"crucible","level":30,"time":"2025-01-21T15:53:53.1498044Z","hostname":"w-01JJ4RN3GTHENBNQ4DERAKAPSN","pid":1249}
4732025-01-21T15:53:53.619Z{"msg":"Crucible Version: BuildInfo {\n version: \"0.0.1\",\n git_sha: \"5c2b227300b758c153f33da870809d67a5160dae\",\n git_commit_timestamp: \"2025-01-21T15:31:20.000000000Z\",\n git_branch: \"mkeeter/always-check-live-repair\",\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-21T15:53:53.149856898Z","hostname":"w-01JJ4RN3GTHENBNQ4DERAKAPSN","pid":1249}
4742025-01-21T15:53:53.619Z{"msg":"Upstairs <-> Downstairs Message Version: 12","v":0,"name":"crucible","level":30,"time":"2025-01-21T15:53:53.149885746Z","hostname":"w-01JJ4RN3GTHENBNQ4DERAKAPSN","pid":1249}
4752025-01-21T15:53:53.619Z{"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-21T15:53:53.149904426Z","hostname":"w-01JJ4RN3GTHENBNQ4DERAKAPSN","pid":1249}
4762025-01-21T15:53:53.619Z{"msg":"Crucible c3911807-d3ae-4055-b043-bf4370bd3be3 has session id: 238127dc-b0c1-41a6-9526-9ef1956bea3b","v":0,"name":"crucible","level":30,"time":"2025-01-21T15:53:53.150516012Z","hostname":"w-01JJ4RN3GTHENBNQ4DERAKAPSN","pid":1249,"session_id":"238127dc-b0c1-41a6-9526-9ef1956bea3b"}
4772025-01-21T15:53:53.619Z{"msg":"Upstairs opts: Upstairs UUID: c3911807-d3ae-4055-b043-bf4370bd3be3, 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-21T15:53:53.15057082Z","hostname":"w-01JJ4RN3GTHENBNQ4DERAKAPSN","pid":1249,"session_id":"238127dc-b0c1-41a6-9526-9ef1956bea3b"}
4782025-01-21T15:53:53.619Z{"msg":"Crucible stats registered with UUID: c3911807-d3ae-4055-b043-bf4370bd3be3","v":0,"name":"crucible","level":30,"time":"2025-01-21T15:53:53.150599559Z","hostname":"w-01JJ4RN3GTHENBNQ4DERAKAPSN","pid":1249,"session_id":"238127dc-b0c1-41a6-9526-9ef1956bea3b"}
4792025-01-21T15:53:53.619Z{"msg":"could not find Downstairs address for Nexus","v":0,"name":"crucible","level":40,"time":"2025-01-21T15:53:53.150631178Z","hostname":"w-01JJ4RN3GTHENBNQ4DERAKAPSN","pid":1249,"session_id":"238127dc-b0c1-41a6-9526-9ef1956bea3b"}
4802025-01-21T15:53:53.622Z{"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-21T15:53:53.152640081Z","hostname":"w-01JJ4RN3GTHENBNQ4DERAKAPSN","pid":1249,"task":"crutest"}
4812025-01-21T15:53:53.622Z{"msg":"Upstairs starts","v":0,"name":"crucible","level":30,"time":"2025-01-21T15:53:53.152751127Z","hostname":"w-01JJ4RN3GTHENBNQ4DERAKAPSN","pid":1249}
4822025-01-21T15:53:53.622Z{"msg":"Crucible Version: BuildInfo {\n version: \"0.0.1\",\n git_sha: \"5c2b227300b758c153f33da870809d67a5160dae\",\n git_commit_timestamp: \"2025-01-21T15:31:20.000000000Z\",\n git_branch: \"mkeeter/always-check-live-repair\",\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-21T15:53:53.152795166Z","hostname":"w-01JJ4RN3GTHENBNQ4DERAKAPSN","pid":1249}
4832025-01-21T15:53:53.622Z{"msg":"Upstairs <-> Downstairs Message Version: 12","v":0,"name":"crucible","level":30,"time":"2025-01-21T15:53:53.152809285Z","hostname":"w-01JJ4RN3GTHENBNQ4DERAKAPSN","pid":1249}
4842025-01-21T15:53:53.622Z{"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-21T15:53:53.152831094Z","hostname":"w-01JJ4RN3GTHENBNQ4DERAKAPSN","pid":1249}
4852025-01-21T15:53:53.622Z{"msg":"Crucible c3911807-d3ae-4055-b043-bf4370bd3be3 has session id: 02f7b7fe-55ab-4096-a633-ef34b137c738","v":0,"name":"crucible","level":30,"time":"2025-01-21T15:53:53.15320174Z","hostname":"w-01JJ4RN3GTHENBNQ4DERAKAPSN","pid":1249,"session_id":"02f7b7fe-55ab-4096-a633-ef34b137c738"}
4862025-01-21T15:53:53.622Z{"msg":"Upstairs opts: Upstairs UUID: c3911807-d3ae-4055-b043-bf4370bd3be3, 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-21T15:53:53.153255248Z","hostname":"w-01JJ4RN3GTHENBNQ4DERAKAPSN","pid":1249,"session_id":"02f7b7fe-55ab-4096-a633-ef34b137c738"}
4872025-01-21T15:53:53.622Z{"msg":"Crucible stats registered with UUID: c3911807-d3ae-4055-b043-bf4370bd3be3","v":0,"name":"crucible","level":30,"time":"2025-01-21T15:53:53.153294027Z","hostname":"w-01JJ4RN3GTHENBNQ4DERAKAPSN","pid":1249,"session_id":"02f7b7fe-55ab-4096-a633-ef34b137c738"}
4882025-01-21T15:53:53.622Z{"msg":"could not find Downstairs address for Nexus","v":0,"name":"crucible","level":40,"time":"2025-01-21T15:53:53.153330595Z","hostname":"w-01JJ4RN3GTHENBNQ4DERAKAPSN","pid":1249,"session_id":"02f7b7fe-55ab-4096-a633-ef34b137c738"}
4892025-01-21T15:53:53.622Z{"msg":"Downstairs in volume = 6","v":0,"name":"crucible","level":30,"time":"2025-01-21T15:53:53.154065147Z","hostname":"w-01JJ4RN3GTHENBNQ4DERAKAPSN","pid":1249,"task":"crutest"}
4902025-01-21T15:53:53.622Z{"msg":"The guest has requested activation with gen:33","v":0,"name":"crucible","level":30,"time":"2025-01-21T15:53:53.154095716Z","hostname":"w-01JJ4RN3GTHENBNQ4DERAKAPSN","pid":1249}
4912025-01-21T15:53:53.622Z{"msg":"c3911807-d3ae-4055-b043-bf4370bd3be3 active request set","v":0,"name":"crucible","level":30,"time":"2025-01-21T15:53:53.154184313Z","hostname":"w-01JJ4RN3GTHENBNQ4DERAKAPSN","pid":1249,"session_id":"238127dc-b0c1-41a6-9526-9ef1956bea3b"}
4922025-01-21T15:53:53.622Z{"msg":"sending connect oneshot to client","v":0,"name":"crucible","level":30,"time":"2025-01-21T15:53:53.154220391Z","hostname":"w-01JJ4RN3GTHENBNQ4DERAKAPSN","pid":1249,"client":"0","":"downstairs","session_id":"238127dc-b0c1-41a6-9526-9ef1956bea3b"}
4932025-01-21T15:53:53.622Z{"msg":"client set_active_request while in Connecting { state: Start { auto_promote: true }, mode: New }; waiting...","v":0,"name":"crucible","level":30,"time":"2025-01-21T15:53:53.154275539Z","hostname":"w-01JJ4RN3GTHENBNQ4DERAKAPSN","pid":1249,"client":"0","":"downstairs","session_id":"238127dc-b0c1-41a6-9526-9ef1956bea3b"}
4942025-01-21T15:53:53.622Z{"msg":"sending connect oneshot to client","v":0,"name":"crucible","level":30,"time":"2025-01-21T15:53:53.154340617Z","hostname":"w-01JJ4RN3GTHENBNQ4DERAKAPSN","pid":1249,"client":"1","":"downstairs","session_id":"238127dc-b0c1-41a6-9526-9ef1956bea3b"}
4952025-01-21T15:53:53.622Z{"msg":"client set_active_request while in Connecting { state: Start { auto_promote: true }, mode: New }; waiting...","v":0,"name":"crucible","level":30,"time":"2025-01-21T15:53:53.154402924Z","hostname":"w-01JJ4RN3GTHENBNQ4DERAKAPSN","pid":1249,"client":"1","":"downstairs","session_id":"238127dc-b0c1-41a6-9526-9ef1956bea3b"}
4962025-01-21T15:53:53.622Z{"msg":"sending connect oneshot to client","v":0,"name":"crucible","level":30,"time":"2025-01-21T15:53:53.154439313Z","hostname":"w-01JJ4RN3GTHENBNQ4DERAKAPSN","pid":1249,"client":"2","":"downstairs","session_id":"238127dc-b0c1-41a6-9526-9ef1956bea3b"}
4972025-01-21T15:53:53.622Z{"msg":"client set_active_request while in Connecting { state: Start { auto_promote: true }, mode: New }; waiting...","v":0,"name":"crucible","level":30,"time":"2025-01-21T15:53:53.154466372Z","hostname":"w-01JJ4RN3GTHENBNQ4DERAKAPSN","pid":1249,"client":"2","":"downstairs","session_id":"238127dc-b0c1-41a6-9526-9ef1956bea3b"}
4982025-01-21T15:53:53.622Z{"msg":"connecting to 127.0.0.1:8810","v":0,"name":"crucible","level":30,"time":"2025-01-21T15:53:53.154497091Z","hostname":"w-01JJ4RN3GTHENBNQ4DERAKAPSN","pid":1249,"":"io task","client":"0","":"downstairs","session_id":"238127dc-b0c1-41a6-9526-9ef1956bea3b"}
4992025-01-21T15:53:53.625Z{"msg":"connecting to 127.0.0.1:8830","v":0,"name":"crucible","level":30,"time":"2025-01-21T15:53:53.15452304Z","hostname":"w-01JJ4RN3GTHENBNQ4DERAKAPSN","pid":1249,"":"io task","client":"2","":"downstairs","session_id":"238127dc-b0c1-41a6-9526-9ef1956bea3b"}
5002025-01-21T15:53:53.625Z{"msg":"connecting to 127.0.0.1:8820","v":0,"name":"crucible","level":30,"time":"2025-01-21T15:53:53.154564368Z","hostname":"w-01JJ4RN3GTHENBNQ4DERAKAPSN","pid":1249,"":"io task","client":"1","":"downstairs","session_id":"238127dc-b0c1-41a6-9526-9ef1956bea3b"}
5012025-01-21T15:53:53.625Z{"msg":"ds_connection connected from Ok(127.0.0.1:62702)","v":0,"name":"crucible","level":30,"time":"2025-01-21T15:53:53.154592837Z","hostname":"w-01JJ4RN3GTHENBNQ4DERAKAPSN","pid":1249,"":"io task","client":"0","":"downstairs","session_id":"238127dc-b0c1-41a6-9526-9ef1956bea3b"}
5022025-01-21T15:53:53.625Z{"msg":"ds_connection connected from Ok(127.0.0.1:48951)","v":0,"name":"crucible","level":30,"time":"2025-01-21T15:53:53.154640685Z","hostname":"w-01JJ4RN3GTHENBNQ4DERAKAPSN","pid":1249,"":"io task","client":"1","":"downstairs","session_id":"238127dc-b0c1-41a6-9526-9ef1956bea3b"}
5032025-01-21T15:53:53.625Z{"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-21T15:53:53.154788259Z","hostname":"w-01JJ4RN3GTHENBNQ4DERAKAPSN","pid":1249,"":"io task","client":"2","":"downstairs","session_id":"238127dc-b0c1-41a6-9526-9ef1956bea3b"}
5042025-01-21T15:53:53.626Z{"msg":"client task is sending Done(ConnectionFailed(Os { code: 146, kind: ConnectionRefused, message: \"Connection refused\" }))","v":0,"name":"crucible","level":40,"time":"2025-01-21T15:53:53.154827888Z","hostname":"w-01JJ4RN3GTHENBNQ4DERAKAPSN","pid":1249,"":"io task","client":"2","":"downstairs","session_id":"238127dc-b0c1-41a6-9526-9ef1956bea3b"}
5052025-01-21T15:53:53.626Z{"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-21T15:53:53.154859417Z","hostname":"w-01JJ4RN3GTHENBNQ4DERAKAPSN","pid":1249,"session_id":"238127dc-b0c1-41a6-9526-9ef1956bea3b"}
5062025-01-21T15:53:53.626Z{"msg":"client task is exiting","v":0,"name":"crucible","level":30,"time":"2025-01-21T15:53:53.154954753Z","hostname":"w-01JJ4RN3GTHENBNQ4DERAKAPSN","pid":1249,"":"io task","client":"2","":"downstairs","session_id":"238127dc-b0c1-41a6-9526-9ef1956bea3b"}
5072025-01-21T15:53:53.626Z{"msg":"version negotiation from state Connecting { state: WaitForPromote, mode: New }","v":0,"name":"crucible","level":30,"time":"2025-01-21T15:53:53.155195334Z","hostname":"w-01JJ4RN3GTHENBNQ4DERAKAPSN","pid":1249,"client":"1","":"downstairs","session_id":"238127dc-b0c1-41a6-9526-9ef1956bea3b"}
5082025-01-21T15:53:53.626Z{"msg":"version negotiation from state Connecting { state: WaitForPromote, mode: New }","v":0,"name":"crucible","level":30,"time":"2025-01-21T15:53:53.155245572Z","hostname":"w-01JJ4RN3GTHENBNQ4DERAKAPSN","pid":1249,"client":"0","":"downstairs","session_id":"238127dc-b0c1-41a6-9526-9ef1956bea3b"}
5092025-01-21T15:53:53.626Z{"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-21T15:53:53.155785102Z","hostname":"w-01JJ4RN3GTHENBNQ4DERAKAPSN","pid":1249,"client":"1","":"downstairs","session_id":"238127dc-b0c1-41a6-9526-9ef1956bea3b"}
5102025-01-21T15:53:53.626Z{"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-21T15:53:53.155891997Z","hostname":"w-01JJ4RN3GTHENBNQ4DERAKAPSN","pid":1249,"client":"0","":"downstairs","session_id":"238127dc-b0c1-41a6-9526-9ef1956bea3b"}
5112025-01-21T15:53:53.626Z{"msg":"Waiting for more clients to be ready","v":0,"name":"crucible","level":30,"time":"2025-01-21T15:53:53.156166997Z","hostname":"w-01JJ4RN3GTHENBNQ4DERAKAPSN","pid":1249,"session_id":"238127dc-b0c1-41a6-9526-9ef1956bea3b"}
5122025-01-21T15:53:53.626Z{"msg":"Waiting for more clients to be ready","v":0,"name":"crucible","level":30,"time":"2025-01-21T15:53:53.156258654Z","hostname":"w-01JJ4RN3GTHENBNQ4DERAKAPSN","pid":1249,"session_id":"238127dc-b0c1-41a6-9526-9ef1956bea3b"}
5132025-01-21T15:54:03.625Z{"msg":"connecting to 127.0.0.1:8830","v":0,"name":"crucible","level":30,"time":"2025-01-21T15:54:03.15686738Z","hostname":"w-01JJ4RN3GTHENBNQ4DERAKAPSN","pid":1249,"":"io task","client":"2","":"downstairs","session_id":"238127dc-b0c1-41a6-9526-9ef1956bea3b"}
5142025-01-21T15:54:03.630Z{"msg":"ds_connection connected from Ok(127.0.0.1:57443)","v":0,"name":"crucible","level":30,"time":"2025-01-21T15:54:03.157265065Z","hostname":"w-01JJ4RN3GTHENBNQ4DERAKAPSN","pid":1249,"":"io task","client":"2","":"downstairs","session_id":"238127dc-b0c1-41a6-9526-9ef1956bea3b"}
5152025-01-21T15:54:03.630Z{"msg":"version negotiation from state Connecting { state: WaitForPromote, mode: New }","v":0,"name":"crucible","level":30,"time":"2025-01-21T15:54:03.158257507Z","hostname":"w-01JJ4RN3GTHENBNQ4DERAKAPSN","pid":1249,"client":"2","":"downstairs","session_id":"238127dc-b0c1-41a6-9526-9ef1956bea3b"}
5162025-01-21T15:54:03.630Z{"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-21T15:54:03.158797716Z","hostname":"w-01JJ4RN3GTHENBNQ4DERAKAPSN","pid":1249,"client":"2","":"downstairs","session_id":"238127dc-b0c1-41a6-9526-9ef1956bea3b"}
5172025-01-21T15:54:03.630Z{"msg":"[0]R flush_numbers: [3998, 3998, 3998, 3998, 3998]","v":0,"name":"crucible","level":30,"time":"2025-01-21T15:54:03.15922567Z","hostname":"w-01JJ4RN3GTHENBNQ4DERAKAPSN","pid":1249,"":"downstairs","":"downstairs","session_id":"238127dc-b0c1-41a6-9526-9ef1956bea3b"}
5182025-01-21T15:54:03.630Z{"msg":"[0]R generation: [32, 32, 32, 32, 32]","v":0,"name":"crucible","level":30,"time":"2025-01-21T15:54:03.159265568Z","hostname":"w-01JJ4RN3GTHENBNQ4DERAKAPSN","pid":1249,"":"downstairs","":"downstairs","session_id":"238127dc-b0c1-41a6-9526-9ef1956bea3b"}
5192025-01-21T15:54:03.630Z{"msg":"[0]R dirty: [false, false, false, false, false]","v":0,"name":"crucible","level":30,"time":"2025-01-21T15:54:03.159296497Z","hostname":"w-01JJ4RN3GTHENBNQ4DERAKAPSN","pid":1249,"":"downstairs","":"downstairs","session_id":"238127dc-b0c1-41a6-9526-9ef1956bea3b"}
5202025-01-21T15:54:03.630Z{"msg":"[1]R flush_numbers: [3998, 3998, 3998, 3998, 3998]","v":0,"name":"crucible","level":30,"time":"2025-01-21T15:54:03.159314216Z","hostname":"w-01JJ4RN3GTHENBNQ4DERAKAPSN","pid":1249,"":"downstairs","":"downstairs","session_id":"238127dc-b0c1-41a6-9526-9ef1956bea3b"}
5212025-01-21T15:54:03.630Z{"msg":"[1]R generation: [32, 32, 32, 32, 32]","v":0,"name":"crucible","level":30,"time":"2025-01-21T15:54:03.159341095Z","hostname":"w-01JJ4RN3GTHENBNQ4DERAKAPSN","pid":1249,"":"downstairs","":"downstairs","session_id":"238127dc-b0c1-41a6-9526-9ef1956bea3b"}
5222025-01-21T15:54:03.630Z{"msg":"[1]R dirty: [false, false, false, false, false]","v":0,"name":"crucible","level":30,"time":"2025-01-21T15:54:03.159358425Z","hostname":"w-01JJ4RN3GTHENBNQ4DERAKAPSN","pid":1249,"":"downstairs","":"downstairs","session_id":"238127dc-b0c1-41a6-9526-9ef1956bea3b"}
5232025-01-21T15:54:03.630Z{"msg":"[2]R flush_numbers: [3997, 3997, 3997, 3997, 3997]","v":0,"name":"crucible","level":30,"time":"2025-01-21T15:54:03.159384394Z","hostname":"w-01JJ4RN3GTHENBNQ4DERAKAPSN","pid":1249,"":"downstairs","":"downstairs","session_id":"238127dc-b0c1-41a6-9526-9ef1956bea3b"}
5242025-01-21T15:54:03.630Z{"msg":"[2]R generation: [31, 31, 31, 31, 31]","v":0,"name":"crucible","level":30,"time":"2025-01-21T15:54:03.159401153Z","hostname":"w-01JJ4RN3GTHENBNQ4DERAKAPSN","pid":1249,"":"downstairs","":"downstairs","session_id":"238127dc-b0c1-41a6-9526-9ef1956bea3b"}
5252025-01-21T15:54:03.630Z{"msg":"[2]R dirty: [false, false, false, false, false]","v":0,"name":"crucible","level":30,"time":"2025-01-21T15:54:03.159418922Z","hostname":"w-01JJ4RN3GTHENBNQ4DERAKAPSN","pid":1249,"":"downstairs","":"downstairs","session_id":"238127dc-b0c1-41a6-9526-9ef1956bea3b"}
5262025-01-21T15:54:03.630Z{"msg":"Max found gen is 33","v":0,"name":"crucible","level":30,"time":"2025-01-21T15:54:03.159444511Z","hostname":"w-01JJ4RN3GTHENBNQ4DERAKAPSN","pid":1249,"":"downstairs","":"downstairs","session_id":"238127dc-b0c1-41a6-9526-9ef1956bea3b"}
5272025-01-21T15:54:03.631Z{"msg":"Generation requested: 33 >= found:33","v":0,"name":"crucible","level":30,"time":"2025-01-21T15:54:03.159461461Z","hostname":"w-01JJ4RN3GTHENBNQ4DERAKAPSN","pid":1249,"":"downstairs","":"downstairs","session_id":"238127dc-b0c1-41a6-9526-9ef1956bea3b"}
5282025-01-21T15:54:03.631Z{"msg":"Next flush: 3999","v":0,"name":"crucible","level":30,"time":"2025-01-21T15:54:03.15948665Z","hostname":"w-01JJ4RN3GTHENBNQ4DERAKAPSN","pid":1249,"":"downstairs","":"downstairs","session_id":"238127dc-b0c1-41a6-9526-9ef1956bea3b"}
5292025-01-21T15:54:03.631Z{"msg":"extent 0 needs reconciliation: ExtentMetadata { gen: 32, flush: 3998, dirty: false } ExtentMetadata { gen: 32, flush: 3998, dirty: false } ExtentMetadata { gen: 31, flush: 3997, dirty: false }","v":0,"name":"crucible","level":30,"time":"2025-01-21T15:54:03.159505549Z","hostname":"w-01JJ4RN3GTHENBNQ4DERAKAPSN","pid":1249,"":"mend","":"downstairs","":"downstairs","session_id":"238127dc-b0c1-41a6-9526-9ef1956bea3b"}
5302025-01-21T15:54:03.631Z{"msg":"extent:0 [ExtentMetadata { gen: 32, flush: 3998, dirty: false }, ExtentMetadata { gen: 32, flush: 3998, dirty: false }, ExtentMetadata { gen: 31, flush: 3997, dirty: false }] => 0","v":0,"name":"crucible","level":30,"time":"2025-01-21T15:54:03.159533218Z","hostname":"w-01JJ4RN3GTHENBNQ4DERAKAPSN","pid":1249,"":"mend","":"downstairs","":"downstairs","session_id":"238127dc-b0c1-41a6-9526-9ef1956bea3b"}
5312025-01-21T15:54:03.631Z{"msg":"found dest for source 0 for extent at index 0 => [ClientId(2)]","v":0,"name":"crucible","level":30,"time":"2025-01-21T15:54:03.159560097Z","hostname":"w-01JJ4RN3GTHENBNQ4DERAKAPSN","pid":1249,"":"mend","":"downstairs","":"downstairs","session_id":"238127dc-b0c1-41a6-9526-9ef1956bea3b"}
5322025-01-21T15:54:03.631Z{"msg":"extent 1 needs reconciliation: ExtentMetadata { gen: 32, flush: 3998, dirty: false } ExtentMetadata { gen: 32, flush: 3998, dirty: false } ExtentMetadata { gen: 31, flush: 3997, dirty: false }","v":0,"name":"crucible","level":30,"time":"2025-01-21T15:54:03.159582536Z","hostname":"w-01JJ4RN3GTHENBNQ4DERAKAPSN","pid":1249,"":"mend","":"downstairs","":"downstairs","session_id":"238127dc-b0c1-41a6-9526-9ef1956bea3b"}
5332025-01-21T15:54:03.631Z{"msg":"extent:0 [ExtentMetadata { gen: 32, flush: 3998, dirty: false }, ExtentMetadata { gen: 32, flush: 3998, dirty: false }, ExtentMetadata { gen: 31, flush: 3997, dirty: false }] => 0","v":0,"name":"crucible","level":30,"time":"2025-01-21T15:54:03.159610535Z","hostname":"w-01JJ4RN3GTHENBNQ4DERAKAPSN","pid":1249,"":"mend","":"downstairs","":"downstairs","session_id":"238127dc-b0c1-41a6-9526-9ef1956bea3b"}
5342025-01-21T15:54:03.631Z{"msg":"found dest for source 0 for extent at index 1 => [ClientId(2)]","v":0,"name":"crucible","level":30,"time":"2025-01-21T15:54:03.159635344Z","hostname":"w-01JJ4RN3GTHENBNQ4DERAKAPSN","pid":1249,"":"mend","":"downstairs","":"downstairs","session_id":"238127dc-b0c1-41a6-9526-9ef1956bea3b"}
5352025-01-21T15:54:03.631Z{"msg":"extent 2 needs reconciliation: ExtentMetadata { gen: 32, flush: 3998, dirty: false } ExtentMetadata { gen: 32, flush: 3998, dirty: false } ExtentMetadata { gen: 31, flush: 3997, dirty: false }","v":0,"name":"crucible","level":30,"time":"2025-01-21T15:54:03.159651763Z","hostname":"w-01JJ4RN3GTHENBNQ4DERAKAPSN","pid":1249,"":"mend","":"downstairs","":"downstairs","session_id":"238127dc-b0c1-41a6-9526-9ef1956bea3b"}
5362025-01-21T15:54:03.631Z{"msg":"extent:0 [ExtentMetadata { gen: 32, flush: 3998, dirty: false }, ExtentMetadata { gen: 32, flush: 3998, dirty: false }, ExtentMetadata { gen: 31, flush: 3997, dirty: false }] => 0","v":0,"name":"crucible","level":30,"time":"2025-01-21T15:54:03.159673313Z","hostname":"w-01JJ4RN3GTHENBNQ4DERAKAPSN","pid":1249,"":"mend","":"downstairs","":"downstairs","session_id":"238127dc-b0c1-41a6-9526-9ef1956bea3b"}
5372025-01-21T15:54:03.631Z{"msg":"found dest for source 0 for extent at index 2 => [ClientId(2)]","v":0,"name":"crucible","level":30,"time":"2025-01-21T15:54:03.159687962Z","hostname":"w-01JJ4RN3GTHENBNQ4DERAKAPSN","pid":1249,"":"mend","":"downstairs","":"downstairs","session_id":"238127dc-b0c1-41a6-9526-9ef1956bea3b"}
5382025-01-21T15:54:03.631Z{"msg":"extent 3 needs reconciliation: ExtentMetadata { gen: 32, flush: 3998, dirty: false } ExtentMetadata { gen: 32, flush: 3998, dirty: false } ExtentMetadata { gen: 31, flush: 3997, dirty: false }","v":0,"name":"crucible","level":30,"time":"2025-01-21T15:54:03.159710701Z","hostname":"w-01JJ4RN3GTHENBNQ4DERAKAPSN","pid":1249,"":"mend","":"downstairs","":"downstairs","session_id":"238127dc-b0c1-41a6-9526-9ef1956bea3b"}
5392025-01-21T15:54:03.631Z{"msg":"extent:0 [ExtentMetadata { gen: 32, flush: 3998, dirty: false }, ExtentMetadata { gen: 32, flush: 3998, dirty: false }, ExtentMetadata { gen: 31, flush: 3997, dirty: false }] => 0","v":0,"name":"crucible","level":30,"time":"2025-01-21T15:54:03.159726991Z","hostname":"w-01JJ4RN3GTHENBNQ4DERAKAPSN","pid":1249,"":"mend","":"downstairs","":"downstairs","session_id":"238127dc-b0c1-41a6-9526-9ef1956bea3b"}
5402025-01-21T15:54:03.631Z{"msg":"found dest for source 0 for extent at index 3 => [ClientId(2)]","v":0,"name":"crucible","level":30,"time":"2025-01-21T15:54:03.15974023Z","hostname":"w-01JJ4RN3GTHENBNQ4DERAKAPSN","pid":1249,"":"mend","":"downstairs","":"downstairs","session_id":"238127dc-b0c1-41a6-9526-9ef1956bea3b"}
5412025-01-21T15:54:03.631Z{"msg":"extent 4 needs reconciliation: ExtentMetadata { gen: 32, flush: 3998, dirty: false } ExtentMetadata { gen: 32, flush: 3998, dirty: false } ExtentMetadata { gen: 31, flush: 3997, dirty: false }","v":0,"name":"crucible","level":30,"time":"2025-01-21T15:54:03.159762949Z","hostname":"w-01JJ4RN3GTHENBNQ4DERAKAPSN","pid":1249,"":"mend","":"downstairs","":"downstairs","session_id":"238127dc-b0c1-41a6-9526-9ef1956bea3b"}
5422025-01-21T15:54:03.631Z{"msg":"extent:0 [ExtentMetadata { gen: 32, flush: 3998, dirty: false }, ExtentMetadata { gen: 32, flush: 3998, dirty: false }, ExtentMetadata { gen: 31, flush: 3997, dirty: false }] => 0","v":0,"name":"crucible","level":30,"time":"2025-01-21T15:54:03.159779459Z","hostname":"w-01JJ4RN3GTHENBNQ4DERAKAPSN","pid":1249,"":"mend","":"downstairs","":"downstairs","session_id":"238127dc-b0c1-41a6-9526-9ef1956bea3b"}
5432025-01-21T15:54:03.631Z{"msg":"found dest for source 0 for extent at index 4 => [ClientId(2)]","v":0,"name":"crucible","level":30,"time":"2025-01-21T15:54:03.159799898Z","hostname":"w-01JJ4RN3GTHENBNQ4DERAKAPSN","pid":1249,"":"mend","":"downstairs","":"downstairs","session_id":"238127dc-b0c1-41a6-9526-9ef1956bea3b"}
5442025-01-21T15:54:03.631Z{"msg":"Transition from Connecting { state: WaitQuorum, mode: New } to Reconcile","v":0,"name":"crucible","level":30,"time":"2025-01-21T15:54:03.159821987Z","hostname":"w-01JJ4RN3GTHENBNQ4DERAKAPSN","pid":1249,"client":"0","":"downstairs","session_id":"238127dc-b0c1-41a6-9526-9ef1956bea3b"}
5452025-01-21T15:54:03.631Z{"msg":"Transition from Connecting { state: WaitQuorum, mode: New } to Reconcile","v":0,"name":"crucible","level":30,"time":"2025-01-21T15:54:03.159836996Z","hostname":"w-01JJ4RN3GTHENBNQ4DERAKAPSN","pid":1249,"client":"1","":"downstairs","session_id":"238127dc-b0c1-41a6-9526-9ef1956bea3b"}
5462025-01-21T15:54:03.631Z{"msg":"Transition from Connecting { state: WaitQuorum, mode: New } to Reconcile","v":0,"name":"crucible","level":30,"time":"2025-01-21T15:54:03.159858466Z","hostname":"w-01JJ4RN3GTHENBNQ4DERAKAPSN","pid":1249,"client":"2","":"downstairs","session_id":"238127dc-b0c1-41a6-9526-9ef1956bea3b"}
5472025-01-21T15:54:03.631Z{"msg":"Full repair list: {ExtentId(4): ExtentFix { source: ClientId(0), dest: [ClientId(2)] }, ExtentId(2): ExtentFix { source: ClientId(0), dest: [ClientId(2)] }, ExtentId(0): ExtentFix { source: ClientId(0), dest: [ClientId(2)] }, ExtentId(3): ExtentFix { source: ClientId(0), dest: [ClientId(2)] }, ExtentId(1): ExtentFix { source: ClientId(0), dest: [ClientId(2)] }}","v":0,"name":"crucible","level":30,"time":"2025-01-21T15:54:03.159903874Z","hostname":"w-01JJ4RN3GTHENBNQ4DERAKAPSN","pid":1249,"":"downstairs","":"downstairs","session_id":"238127dc-b0c1-41a6-9526-9ef1956bea3b"}
5482025-01-21T15:54:03.631Z{"msg":"Task list: [ReconcileIO { id: ReconciliationId(0), op: ExtentFlush { repair_id: ReconciliationId(0), extent_id: ExtentId(4), client_id: ClientId(0), flush_number: 3999, gen_number: 33 }, state: ClientData([New, New, New]) }, ReconcileIO { id: ReconciliationId(1), op: ExtentClose { repair_id: ReconciliationId(1), extent_id: ExtentId(4) }, state: ClientData([New, New, New]) }, ReconcileIO { id: ReconciliationId(2), op: ExtentRepair { repair_id: ReconciliationId(2), 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(3), op: ExtentReopen { repair_id: ReconciliationId(3), extent_id: ExtentId(4) }, state: ClientData([New, New, New]) }, ReconcileIO { id: ReconciliationId(4), op: ExtentFlush { repair_id: ReconciliationId(4), extent_id: ExtentId(2), client_id: ClientId(0), flush_number: 3999, gen_number: 33 }, state: ClientData([New, New, New]) }, ReconcileIO { id: ReconciliationId(5), op: ExtentClose { repair_id: ReconciliationId(5), extent_id: ExtentId(2) }, state: ClientData([New, New, New]) }, ReconcileIO { id: ReconciliationId(6), op: ExtentRepair { repair_id: ReconciliationId(6), extent_id: ExtentId(2), source_client_id: ClientId(0), source_repair_address: 0.0.0.0:12810, dest_clients: [ClientId(2)] }, state: ClientData([New, New, New]) }, ReconcileIO { id: ReconciliationId(7), op: ExtentReopen { repair_id: ReconciliationId(7), extent_id: ExtentId(2) }, state: ClientData([New, New, New]) }, ReconcileIO { id: ReconciliationId(8), op: ExtentFlush { repair_id: ReconciliationId(8), extent_id: ExtentId(0), client_id: ClientId(0), flush_number: 3999, gen_number: 33 }, state: ClientData([New, New, New]) }, ReconcileIO { id: ReconciliationId(9), op: ExtentClose { repair_id: ReconciliationId(9), extent_id: ExtentId(0) }, state: ClientData([New, New, New]) }, ReconcileIO { id: ReconciliationId(10), op: ExtentRepair { repair_id: ReconciliationId(10), extent_id: ExtentId(0), source_client_id: ClientId(0), source_repair_address: 0.0.0.0:12810, dest_clients: [ClientId(2)] }, state: ClientData([New, New, New]) }, ReconcileIO { id: ReconciliationId(11), op: ExtentReopen { repair_id: ReconciliationId(11), extent_id: ExtentId(0) }, state: ClientData([New, New, New]) }, ReconcileIO { id: ReconciliationId(12), op: ExtentFlush { repair_id: ReconciliationId(12), extent_id: ExtentId(3), client_id: ClientId(0), flush_number: 3999, gen_number: 33 }, state: ClientData([New, New, New]) }, ReconcileIO { id: ReconciliationId(13), op: ExtentClose { repair_id: ReconciliationId(13), extent_id: ExtentId(3) }, state: ClientData([New, New, New]) }, ReconcileIO { id: ReconciliationId(14), op: ExtentRepair { repair_id: ReconciliationId(14), extent_id: ExtentId(3), source_client_id: ClientId(0), source_repair_address: 0.0.0.0:12810, dest_clients: [ClientId(2)] }, state: ClientData([New, New, New]) }, ReconcileIO { id: ReconciliationId(15), op: ExtentReopen { repair_id: ReconciliationId(15), extent_id: ExtentId(3) }, state: ClientData([New, New, New]) }, ReconcileIO { id: ReconciliationId(16), op: ExtentFlush { repair_id: ReconciliationId(16), extent_id: ExtentId(1), client_id: ClientId(0), flush_number: 3999, gen_number: 33 }, state: ClientData([New, New, New]) }, ReconcileIO { id: ReconciliationId(17), op: ExtentClose { repair_id: ReconciliationId(17), extent_id: ExtentId(1) }, state: ClientData([New, New, New]) }, ReconcileIO { id: ReconciliationId(18), op: ExtentRepair { repair_id: ReconciliationId(18), extent_id: ExtentId(1), source_client_id: ClientId(0), source_repair_address: 0.0.0.0:12810, dest_clients: [ClientId(2)] }, state: ClientData([New, New, New]) }, ReconcileIO { id: ReconciliationId(19), op: ExtentReopen { repair_id: ReconciliationId(19), extent_id: ExtentId(1) }, state: ClientData([New, New, New]) }]","v":0,"name":"crucible","level":30,"time":"2025-01-21T15:54:03.160057498Z","hostname":"w-01JJ4RN3GTHENBNQ4DERAKAPSN","pid":1249,"":"downstairs","":"downstairs","session_id":"238127dc-b0c1-41a6-9526-9ef1956bea3b"}
5492025-01-21T15:54:03.631Z{"msg":"starting reconciliation f98d3f7f-bab3-4e63-8cff-04d028f13657: found 20 extents that need repair","v":0,"name":"crucible","level":30,"time":"2025-01-21T15:54:03.160084937Z","hostname":"w-01JJ4RN3GTHENBNQ4DERAKAPSN","pid":1249,"":"downstairs","":"downstairs","session_id":"238127dc-b0c1-41a6-9526-9ef1956bea3b"}
5502025-01-21T15:54:03.634Z{"msg":"sending reconcile request ReconciliationId(2)","v":0,"name":"crucible","level":30,"time":"2025-01-21T15:54:03.160200133Z","hostname":"w-01JJ4RN3GTHENBNQ4DERAKAPSN","pid":1249,"client":"2","":"downstairs","session_id":"238127dc-b0c1-41a6-9526-9ef1956bea3b"}
5512025-01-21T15:54:03.637Z{"msg":"sending reconcile request ReconciliationId(6)","v":0,"name":"crucible","level":30,"time":"2025-01-21T15:54:03.169232429Z","hostname":"w-01JJ4RN3GTHENBNQ4DERAKAPSN","pid":1249,"client":"2","":"downstairs","session_id":"238127dc-b0c1-41a6-9526-9ef1956bea3b"}
5522025-01-21T15:54:03.641Z{"msg":"sending reconcile request ReconciliationId(10)","v":0,"name":"crucible","level":30,"time":"2025-01-21T15:54:03.17285672Z","hostname":"w-01JJ4RN3GTHENBNQ4DERAKAPSN","pid":1249,"client":"2","":"downstairs","session_id":"238127dc-b0c1-41a6-9526-9ef1956bea3b"}
5532025-01-21T15:54:03.644Z{"msg":"sending reconcile request ReconciliationId(14)","v":0,"name":"crucible","level":30,"time":"2025-01-21T15:54:03.176358267Z","hostname":"w-01JJ4RN3GTHENBNQ4DERAKAPSN","pid":1249,"client":"2","":"downstairs","session_id":"238127dc-b0c1-41a6-9526-9ef1956bea3b"}
5542025-01-21T15:54:03.648Z{"msg":"sending reconcile request ReconciliationId(18)","v":0,"name":"crucible","level":30,"time":"2025-01-21T15:54:03.179793626Z","hostname":"w-01JJ4RN3GTHENBNQ4DERAKAPSN","pid":1249,"client":"2","":"downstairs","session_id":"238127dc-b0c1-41a6-9526-9ef1956bea3b"}
5552025-01-21T15:54:03.651Z{"msg":"done with reconciliation","v":0,"name":"crucible","level":30,"time":"2025-01-21T15:54:03.182729015Z","hostname":"w-01JJ4RN3GTHENBNQ4DERAKAPSN","pid":1249,"":"downstairs","":"downstairs","session_id":"238127dc-b0c1-41a6-9526-9ef1956bea3b"}
5562025-01-21T15:54:03.651Z{"msg":"Transition from Reconcile to Active","v":0,"name":"crucible","level":30,"time":"2025-01-21T15:54:03.182756083Z","hostname":"w-01JJ4RN3GTHENBNQ4DERAKAPSN","pid":1249,"client":"0","":"downstairs","session_id":"238127dc-b0c1-41a6-9526-9ef1956bea3b"}
5572025-01-21T15:54:03.651Z{"msg":"Transition from Reconcile to Active","v":0,"name":"crucible","level":30,"time":"2025-01-21T15:54:03.182771403Z","hostname":"w-01JJ4RN3GTHENBNQ4DERAKAPSN","pid":1249,"client":"1","":"downstairs","session_id":"238127dc-b0c1-41a6-9526-9ef1956bea3b"}
5582025-01-21T15:54:03.651Z{"msg":"Transition from Reconcile to Active","v":0,"name":"crucible","level":30,"time":"2025-01-21T15:54:03.182785292Z","hostname":"w-01JJ4RN3GTHENBNQ4DERAKAPSN","pid":1249,"client":"2","":"downstairs","session_id":"238127dc-b0c1-41a6-9526-9ef1956bea3b"}
5592025-01-21T15:54:03.651Z{"msg":"All required reconciliation work is completed","v":0,"name":"crucible","level":30,"time":"2025-01-21T15:54:03.182802332Z","hostname":"w-01JJ4RN3GTHENBNQ4DERAKAPSN","pid":1249,"session_id":"238127dc-b0c1-41a6-9526-9ef1956bea3b"}
5602025-01-21T15:54:03.654Z{"msg":"Set Downstairs and Upstairs active after reconciliation","v":0,"name":"crucible","level":30,"time":"2025-01-21T15:54:03.182824651Z","hostname":"w-01JJ4RN3GTHENBNQ4DERAKAPSN","pid":1249,"session_id":"238127dc-b0c1-41a6-9526-9ef1956bea3b"}
5612025-01-21T15:54:03.654Z{"msg":"c3911807-d3ae-4055-b043-bf4370bd3be3 is now active with session: 238127dc-b0c1-41a6-9526-9ef1956bea3b","v":0,"name":"crucible","level":30,"time":"2025-01-21T15:54:03.182864339Z","hostname":"w-01JJ4RN3GTHENBNQ4DERAKAPSN","pid":1249,"session_id":"238127dc-b0c1-41a6-9526-9ef1956bea3b"}
5622025-01-21T15:54:03.654Z{"msg":"The guest has finished waiting for activation with:33","v":0,"name":"crucible","level":30,"time":"2025-01-21T15:54:03.182891308Z","hostname":"w-01JJ4RN3GTHENBNQ4DERAKAPSN","pid":1249}
5632025-01-21T15:54:03.654Z{"msg":"The guest has requested activation with gen:33","v":0,"name":"crucible","level":30,"time":"2025-01-21T15:54:03.182923117Z","hostname":"w-01JJ4RN3GTHENBNQ4DERAKAPSN","pid":1249}
5642025-01-21T15:54:03.654Z{"msg":"c3911807-d3ae-4055-b043-bf4370bd3be3 active request set","v":0,"name":"crucible","level":30,"time":"2025-01-21T15:54:03.182936436Z","hostname":"w-01JJ4RN3GTHENBNQ4DERAKAPSN","pid":1249,"session_id":"02f7b7fe-55ab-4096-a633-ef34b137c738"}
5652025-01-21T15:54:03.654Z{"msg":"sending connect oneshot to client","v":0,"name":"crucible","level":30,"time":"2025-01-21T15:54:03.182957276Z","hostname":"w-01JJ4RN3GTHENBNQ4DERAKAPSN","pid":1249,"client":"0","":"downstairs","session_id":"02f7b7fe-55ab-4096-a633-ef34b137c738"}
5662025-01-21T15:54:03.654Z{"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-21T15:54:03.182971945Z","hostname":"w-01JJ4RN3GTHENBNQ4DERAKAPSN","pid":1249,"client":"0","":"downstairs","session_id":"02f7b7fe-55ab-4096-a633-ef34b137c738"}
5672025-01-21T15:54:03.654Z{"msg":"sending connect oneshot to client","v":0,"name":"crucible","level":30,"time":"2025-01-21T15:54:03.182989214Z","hostname":"w-01JJ4RN3GTHENBNQ4DERAKAPSN","pid":1249,"client":"1","":"downstairs","session_id":"02f7b7fe-55ab-4096-a633-ef34b137c738"}
5682025-01-21T15:54:03.654Z{"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-21T15:54:03.183023733Z","hostname":"w-01JJ4RN3GTHENBNQ4DERAKAPSN","pid":1249,"client":"1","":"downstairs","session_id":"02f7b7fe-55ab-4096-a633-ef34b137c738"}
5692025-01-21T15:54:03.654Z{"msg":"sending connect oneshot to client","v":0,"name":"crucible","level":30,"time":"2025-01-21T15:54:03.183047102Z","hostname":"w-01JJ4RN3GTHENBNQ4DERAKAPSN","pid":1249,"client":"2","":"downstairs","session_id":"02f7b7fe-55ab-4096-a633-ef34b137c738"}
5702025-01-21T15:54:03.654Z{"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-21T15:54:03.183062272Z","hostname":"w-01JJ4RN3GTHENBNQ4DERAKAPSN","pid":1249,"client":"2","":"downstairs","session_id":"02f7b7fe-55ab-4096-a633-ef34b137c738"}
5712025-01-21T15:54:03.654Z{"msg":"connecting to 127.0.0.1:8860","v":0,"name":"crucible","level":30,"time":"2025-01-21T15:54:03.183075171Z","hostname":"w-01JJ4RN3GTHENBNQ4DERAKAPSN","pid":1249,"":"io task","client":"2","":"downstairs","session_id":"02f7b7fe-55ab-4096-a633-ef34b137c738"}
5722025-01-21T15:54:03.654Z{"msg":"connecting to 127.0.0.1:8840","v":0,"name":"crucible","level":30,"time":"2025-01-21T15:54:03.18309729Z","hostname":"w-01JJ4RN3GTHENBNQ4DERAKAPSN","pid":1249,"":"io task","client":"0","":"downstairs","session_id":"02f7b7fe-55ab-4096-a633-ef34b137c738"}
5732025-01-21T15:54:03.654Z{"msg":"connecting to 127.0.0.1:8850","v":0,"name":"crucible","level":30,"time":"2025-01-21T15:54:03.183119989Z","hostname":"w-01JJ4RN3GTHENBNQ4DERAKAPSN","pid":1249,"":"io task","client":"1","":"downstairs","session_id":"02f7b7fe-55ab-4096-a633-ef34b137c738"}
5742025-01-21T15:54:03.654Z{"msg":"ds_connection connected from Ok(127.0.0.1:55301)","v":0,"name":"crucible","level":30,"time":"2025-01-21T15:54:03.183142109Z","hostname":"w-01JJ4RN3GTHENBNQ4DERAKAPSN","pid":1249,"":"io task","client":"0","":"downstairs","session_id":"02f7b7fe-55ab-4096-a633-ef34b137c738"}
5752025-01-21T15:54:03.654Z{"msg":"ds_connection connected from Ok(127.0.0.1:39794)","v":0,"name":"crucible","level":30,"time":"2025-01-21T15:54:03.183165668Z","hostname":"w-01JJ4RN3GTHENBNQ4DERAKAPSN","pid":1249,"":"io task","client":"1","":"downstairs","session_id":"02f7b7fe-55ab-4096-a633-ef34b137c738"}
5762025-01-21T15:54:03.654Z{"msg":"ds_connection connected from Ok(127.0.0.1:49558)","v":0,"name":"crucible","level":30,"time":"2025-01-21T15:54:03.183189767Z","hostname":"w-01JJ4RN3GTHENBNQ4DERAKAPSN","pid":1249,"":"io task","client":"2","":"downstairs","session_id":"02f7b7fe-55ab-4096-a633-ef34b137c738"}
5772025-01-21T15:54:03.654Z{"msg":"version negotiation from state Connecting { state: WaitForPromote, mode: New }","v":0,"name":"crucible","level":30,"time":"2025-01-21T15:54:03.183568703Z","hostname":"w-01JJ4RN3GTHENBNQ4DERAKAPSN","pid":1249,"client":"1","":"downstairs","session_id":"02f7b7fe-55ab-4096-a633-ef34b137c738"}
5782025-01-21T15:54:03.654Z{"msg":"version negotiation from state Connecting { state: WaitForPromote, mode: New }","v":0,"name":"crucible","level":30,"time":"2025-01-21T15:54:03.183603851Z","hostname":"w-01JJ4RN3GTHENBNQ4DERAKAPSN","pid":1249,"client":"0","":"downstairs","session_id":"02f7b7fe-55ab-4096-a633-ef34b137c738"}
5792025-01-21T15:54:03.654Z{"msg":"version negotiation from state Connecting { state: WaitForPromote, mode: New }","v":0,"name":"crucible","level":30,"time":"2025-01-21T15:54:03.183647829Z","hostname":"w-01JJ4RN3GTHENBNQ4DERAKAPSN","pid":1249,"client":"2","":"downstairs","session_id":"02f7b7fe-55ab-4096-a633-ef34b137c738"}
5802025-01-21T15:54:03.654Z{"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-21T15:54:03.184110202Z","hostname":"w-01JJ4RN3GTHENBNQ4DERAKAPSN","pid":1249,"client":"0","":"downstairs","session_id":"02f7b7fe-55ab-4096-a633-ef34b137c738"}
5812025-01-21T15:54:03.654Z{"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-21T15:54:03.184268496Z","hostname":"w-01JJ4RN3GTHENBNQ4DERAKAPSN","pid":1249,"client":"1","":"downstairs","session_id":"02f7b7fe-55ab-4096-a633-ef34b137c738"}
5822025-01-21T15:54:03.654Z{"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-21T15:54:03.184304644Z","hostname":"w-01JJ4RN3GTHENBNQ4DERAKAPSN","pid":1249,"client":"2","":"downstairs","session_id":"02f7b7fe-55ab-4096-a633-ef34b137c738"}
5832025-01-21T15:54:03.654Z{"msg":"Waiting for more clients to be ready","v":0,"name":"crucible","level":30,"time":"2025-01-21T15:54:03.184470628Z","hostname":"w-01JJ4RN3GTHENBNQ4DERAKAPSN","pid":1249,"session_id":"02f7b7fe-55ab-4096-a633-ef34b137c738"}
5842025-01-21T15:54:03.654Z{"msg":"Waiting for more clients to be ready","v":0,"name":"crucible","level":30,"time":"2025-01-21T15:54:03.184652471Z","hostname":"w-01JJ4RN3GTHENBNQ4DERAKAPSN","pid":1249,"session_id":"02f7b7fe-55ab-4096-a633-ef34b137c738"}
5852025-01-21T15:54:03.654Z{"msg":"[0]R flush_numbers: [5320, 5320, 5320, 5320, 5320]","v":0,"name":"crucible","level":30,"time":"2025-01-21T15:54:03.184745268Z","hostname":"w-01JJ4RN3GTHENBNQ4DERAKAPSN","pid":1249,"":"downstairs","":"downstairs","session_id":"02f7b7fe-55ab-4096-a633-ef34b137c738"}
5862025-01-21T15:54:03.654Z{"msg":"[0]R generation: [32, 32, 32, 32, 32]","v":0,"name":"crucible","level":30,"time":"2025-01-21T15:54:03.184780276Z","hostname":"w-01JJ4RN3GTHENBNQ4DERAKAPSN","pid":1249,"":"downstairs","":"downstairs","session_id":"02f7b7fe-55ab-4096-a633-ef34b137c738"}
5872025-01-21T15:54:03.655Z{"msg":"[0]R dirty: [false, false, false, false, false]","v":0,"name":"crucible","level":30,"time":"2025-01-21T15:54:03.184811595Z","hostname":"w-01JJ4RN3GTHENBNQ4DERAKAPSN","pid":1249,"":"downstairs","":"downstairs","session_id":"02f7b7fe-55ab-4096-a633-ef34b137c738"}
5882025-01-21T15:54:03.655Z{"msg":"[1]R flush_numbers: [5320, 5320, 5320, 5320, 5320]","v":0,"name":"crucible","level":30,"time":"2025-01-21T15:54:03.184836324Z","hostname":"w-01JJ4RN3GTHENBNQ4DERAKAPSN","pid":1249,"":"downstairs","":"downstairs","session_id":"02f7b7fe-55ab-4096-a633-ef34b137c738"}
5892025-01-21T15:54:03.655Z{"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-21T15:54:03.655Z,"time":"2025-01-21T15:54:03.184885392Z","hostname":"w-01JJ4RN3GTHENBNQ4DERAKAPSN","pid":1249,"":"downstairs","":"downstairs","session_id":"02f7b7fe-55ab-4096-a633-ef34b137c738"}
5912025-01-21T15:54:03.655Z{"msg":"[1]R dirty: [false, false, false, false, false]","v":0,"name":"crucible","level":30,"time":"2025-01-21T15:54:03.184910131Z","hostname":"w-01JJ4RN3GTHENBNQ4DERAKAPSN","pid":1249,"":"downstairs","":"downstairs","session_id":"02f7b7fe-55ab-4096-a633-ef34b137c738"}
5922025-01-21T15:54:03.655Z{"msg":"[2]R flush_numbers: [5320, 5320, 5320, 5320, 5320]","v":0,"name":"crucible","level":30,"time":"2025-01-21T15:54:03.184924161Z","hostname":"w-01JJ4RN3GTHENBNQ4DERAKAPSN","pid":1249,"":"downstairs","":"downstairs","session_id":"02f7b7fe-55ab-4096-a633-ef34b137c738"}
5932025-01-21T15:54:03.655Z{"msg":"[2]R generation: [32, 32, 32, 32, 32]","v":0,"name":"crucible","level":30,"time":"2025-01-21T15:54:03.18494908Z","hostname":"w-01JJ4RN3GTHENBNQ4DERAKAPSN","pid":1249,"":"downstairs","":"downstairs","session_id":"02f7b7fe-55ab-4096-a633-ef34b137c738"}
5942025-01-21T15:54:03.655Z{"msg":"[2]R dirty: [false, false, false, false, false]","v":0,"name":"crucible","level":30,"time":"2025-01-21T15:54:03.184983718Z","hostname":"w-01JJ4RN3GTHENBNQ4DERAKAPSN","pid":1249,"":"downstairs","":"downstairs","session_id":"02f7b7fe-55ab-4096-a633-ef34b137c738"}
5952025-01-21T15:54:03.655Z{"msg":"Max found gen is 33","v":0,"name":"crucible","level":30,"time":"2025-01-21T15:54:03.185018997Z","hostname":"w-01JJ4RN3GTHENBNQ4DERAKAPSN","pid":1249,"":"downstairs","":"downstairs","session_id":"02f7b7fe-55ab-4096-a633-ef34b137c738"}
5962025-01-21T15:54:03.655Z{"msg":"Generation requested: 33 >= found:33","v":0,"name":"crucible","level":30,"time":"2025-01-21T15:54:03.185054646Z","hostname":"w-01JJ4RN3GTHENBNQ4DERAKAPSN","pid":1249,"":"downstairs","":"downstairs","session_id":"02f7b7fe-55ab-4096-a633-ef34b137c738"}
5972025-01-21T15:54:03.655Z{"msg":"Next flush: 5321","v":0,"name":"crucible","level":30,"time":"2025-01-21T15:54:03.185092105Z","hostname":"w-01JJ4RN3GTHENBNQ4DERAKAPSN","pid":1249,"":"downstairs","":"downstairs","session_id":"02f7b7fe-55ab-4096-a633-ef34b137c738"}
5982025-01-21T15:54:03.655Z{"msg":"All extents match","v":0,"name":"crucible","level":30,"time":"2025-01-21T15:54:03.185132413Z","hostname":"w-01JJ4RN3GTHENBNQ4DERAKAPSN","pid":1249,"":"downstairs","":"downstairs","session_id":"02f7b7fe-55ab-4096-a633-ef34b137c738"}
5992025-01-21T15:54:03.655Z{"msg":"No downstairs reconciliation required","v":0,"name":"crucible","level":30,"time":"2025-01-21T15:54:03.185171931Z","hostname":"w-01JJ4RN3GTHENBNQ4DERAKAPSN","pid":1249,"session_id":"02f7b7fe-55ab-4096-a633-ef34b137c738"}
6002025-01-21T15:54:03.655Z{"msg":"Transition from WaitQuorum to Active","v":0,"name":"crucible","level":30,"time":"2025-01-21T15:54:03.18520614Z","hostname":"w-01JJ4RN3GTHENBNQ4DERAKAPSN","pid":1249,"client":"0","":"downstairs","session_id":"02f7b7fe-55ab-4096-a633-ef34b137c738"}
6012025-01-21T15:54:03.655Z{"msg":"Transition from WaitQuorum to Active","v":0,"name":"crucible","level":30,"time":"2025-01-21T15:54:03.185244039Z","hostname":"w-01JJ4RN3GTHENBNQ4DERAKAPSN","pid":1249,"client":"1","":"downstairs","session_id":"02f7b7fe-55ab-4096-a633-ef34b137c738"}
6022025-01-21T15:54:03.655ZDisk: sv:2 bs:4096 ts:409600 tb:100 max_io:100 or 409600
6032025-01-21T15:54:03.655Z{"msg":"Transition from WaitQuorum to Active","v":0,"name":"crucible","level":30,"time":"2025-01-21T15:54:03.185285827Z","hostname":"w-01JJ4RN3GTHENBNQ4DERAKAPSN","pid":1249,"client":"2","":"downstairs","session_id":"02f7b7fe-55ab-4096-a633-ef34b137c738"}
6042025-01-21T15:54:03.655Z{"msg":"All required reconciliation work is completed","v":0,"name":"crucible","level":30,"time":"2025-01-21T15:54:03.185312786Z","hostname":"w-01JJ4RN3GTHENBNQ4DERAKAPSN","pid":1249,"session_id":"02f7b7fe-55ab-4096-a633-ef34b137c738"}
6052025-01-21T15:54:03.655Z{"msg":"Set Downstairs and Upstairs active after reconciliation","v":0,"name":"crucible","level":30,"time":"2025-01-21T15:54:03.185326325Z","hostname":"w-01JJ4RN3GTHENBNQ4DERAKAPSN","pid":1249,"session_id":"02f7b7fe-55ab-4096-a633-ef34b137c738"}
6062025-01-21T15:54:03.655Z{"msg":"c3911807-d3ae-4055-b043-bf4370bd3be3 is now active with session: 02f7b7fe-55ab-4096-a633-ef34b137c738","v":0,"name":"crucible","level":30,"time":"2025-01-21T15:54:03.185346005Z","hostname":"w-01JJ4RN3GTHENBNQ4DERAKAPSN","pid":1249,"session_id":"02f7b7fe-55ab-4096-a633-ef34b137c738"}
6072025-01-21T15:54:03.655Z{"msg":"Set Active after no reconciliation","v":0,"name":"crucible","level":30,"time":"2025-01-21T15:54:03.185358074Z","hostname":"w-01JJ4RN3GTHENBNQ4DERAKAPSN","pid":1249,"session_id":"02f7b7fe-55ab-4096-a633-ef34b137c738"}
6082025-01-21T15:54:03.655Z{"msg":"The guest has finished waiting for activation with:33","v":0,"name":"crucible","level":30,"time":"2025-01-21T15:54:03.185376314Z","hostname":"w-01JJ4RN3GTHENBNQ4DERAKAPSN","pid":1249}
6092025-01-21T15:54:03.655ZLoading write count information from file "/var/tmp/test_up-build/verify_file"
6102025-01-21T15:54:03.658ZRead and Verify all blocks (0..100 range:true)
6112025-01-21T15:54:03.734ZWrote out file "/var/tmp/test_up-build/verify_file"
6122025-01-21T15:54:03.734ZVerify test completed
6132025-01-21T15:54:03.737ZWrote out file "/var/tmp/test_up-build/verify_file"
6142025-01-21T15:54:03.737ZCLIENT: Tests done. All submitted work has been ACK'd
6152025-01-21T15:54:03.737Z----------------------------------------------------------------
6162025-01-21T15:54:03.737Z Crucible gen:33 GIO:true work queues: Upstairs:0 downstairs:1
6172025-01-21T15:54:03.737ZStates: Active Active Active
6182025-01-21T15:54:03.737ZJOBID ACK TYPE BKS/EXT DS:0 DS:1 DS:2 REPLAY
6192025-01-21T15:54:03.737Z 1000 Acked Read 50 Done Done Done false
6202025-01-21T15:54:03.737Z STATES DS:0 DS:1 DS:2 TOTAL
6212025-01-21T15:54:03.737Z Sent 0 0 0 0
6222025-01-21T15:54:03.737Z Done 1 1 1 3
6232025-01-21T15:54:03.737Z Skipped 0 0 0 0
6242025-01-21T15:54:03.737Z Error 0 0 0 0
6252025-01-21T15:54:03.737ZLast Flush: 0 0 0
6262025-01-21T15:54:03.737ZDownstairs last five completed:
6272025-01-21T15:54:03.737ZUpstairs last five completed: 1000
6282025-01-21T15:54:03.737Z----------------------------------------------------------------
6292025-01-21T15:54:03.737Z Crucible gen:33 GIO:true work queues: Upstairs:0 downstairs:1
6302025-01-21T15:54:03.737ZStates: Active Active Active
6312025-01-21T15:54:03.737ZJOBID ACK TYPE BKS/EXT DS:0 DS:1 DS:2 REPLAY
6322025-01-21T15:54:03.737Z 1000 Acked Read 50 Done Done Done false
6332025-01-21T15:54:03.737Z STATES DS:0 DS:1 DS:2 TOTAL
6342025-01-21T15:54:03.737Z Sent 0 0 0 0
6352025-01-21T15:54:03.738Z Done 1 1 1 3
6362025-01-21T15:54:03.738Z Skipped 0 0 0 0
6372025-01-21T15:54:03.738Z Error 0 0 0 0
6382025-01-21T15:54:03.738ZLast Flush: 0 0 0
6392025-01-21T15:54:03.738ZDownstairs last five completed:
6402025-01-21T15:54:03.738ZUpstairs last five completed: 1000
6412025-01-21T15:54:03.738ZCLIENT: Up:0 ds:2 act:6
6422025-01-21T15:54:07.736Z----------------------------------------------------------------
6432025-01-21T15:54:07.737Z Crucible gen:33 GIO:true work queues: Upstairs:0 downstairs:0
6442025-01-21T15:54:07.737ZDownstairs last five completed: 1001 1000
6452025-01-21T15:54:07.737ZUpstairs last five completed: 1001 1000
6462025-01-21T15:54:07.737Z----------------------------------------------------------------
6472025-01-21T15:54:07.737Z Crucible gen:33 GIO:true work queues: Upstairs:0 downstairs:0
6482025-01-21T15:54:07.737ZDownstairs last five completed: 1001 1000
6492025-01-21T15:54:07.737ZUpstairs last five completed: 1001 1000
6502025-01-21T15:54:07.740ZCLIENT: Up:0 ds:0 act:6
6512025-01-21T15:54:07.740ZCLIENT: All crucible jobs finished, exiting program
6522025-01-21T15:54:07.740Z{"msg":"Guest handle has been dropped","v":0,"name":"crucible","level":40,"time":"2025-01-21T15:54:07.268391949Z","hostname":"w-01JJ4RN3GTHENBNQ4DERAKAPSN","pid":1249}
6532025-01-21T15:54:07.744ZRepair part 2 passed
6542025-01-21T15:54:07.747Z/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-21T15:54:07.763ZEXT BLOCKS GEN0 GEN1 GEN2 FL0 FL1 FL2 D0 D1 D2 DIFF
6562025-01-21T15:54:07.763Z 0 000-009 32 32 32 3998 3998 3998 F F F
6572025-01-21T15:54:07.763Z 1 010-019 32 32 32 3998 3998 3998 F F F
6582025-01-21T15:54:07.763Z 2 020-029 32 32 32 3998 3998 3998 F F F
6592025-01-21T15:54:07.763Z 3 030-039 32 32 32 3998 3998 3998 F F F
6602025-01-21T15:54:07.763Z 4 040-049 32 32 32 3998 3998 3998 F F F
6612025-01-21T15:54:07.766ZMax gen: 32, Max flush: 3998
6622025-01-21T15:54:07.768Zdump test passed
6632025-01-21T15:54:07.768Z/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-21T15:54:07.784Z Extent 1
6652025-01-21T15:54:07.787ZGEN 32 32 32
6662025-01-21T15:54:07.787ZFLUSH_ID 3998 3998 3998
6672025-01-21T15:54:07.787ZDIRTY
6682025-01-21T15:54:07.787Z
6692025-01-21T15:54:07.787ZBLOCK D0 D1 D2 C0 C1 C2 DIFF
6702025-01-21T15:54:07.787Z010 A A A A A A
6712025-01-21T15:54:07.790Z011 A A A A A A
6722025-01-21T15:54:07.790Z012 A A A A A A
6732025-01-21T15:54:07.792Z013 A A A A A A
6742025-01-21T15:54:07.792Z014 A A A A A A
6752025-01-21T15:54:07.792Z015 A A A A A A
6762025-01-21T15:54:07.795Z016 A A A A A A
6772025-01-21T15:54:07.797Z017 A A A A A A
6782025-01-21T15:54:07.797Z018 A A A A A A
6792025-01-21T15:54:07.800Z019 A A A A A A
6802025-01-21T15:54:07.803Zdump extent test passed
6812025-01-21T15:54:07.803Z/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-21T15:54:07.818ZExtent 2 Block in extent 0 Actual block 20
6832025-01-21T15:54:07.820Z
6842025-01-21T15:54:07.820Z DATA SHA256 VER
6852025-01-21T15:54:07.820Z------ ---------------------------------------------------------------- ---
6862025-01-21T15:54:07.823Z 0 aad7cd4cfee899c621168f182f00e7db01cfd51e6955baa6a2e714c5f971346e A
6872025-01-21T15:54:07.823Z 1 aad7cd4cfee899c621168f182f00e7db01cfd51e6955baa6a2e714c5f971346e A
6882025-01-21T15:54:07.823Z 2 aad7cd4cfee899c621168f182f00e7db01cfd51e6955baa6a2e714c5f971346e A
6892025-01-21T15:54:07.823Z
6902025-01-21T15:54:07.823ZNONCES 0 1 2 DIFF
6912025-01-21T15:54:07.823Z------ ------------------------ ------------------------ ------------------------ -----
6922025-01-21T15:54:07.823Z 0 3ee8246b75a5c636586f658b 3ee8246b75a5c636586f658b 3ee8246b75a5c636586f658b
6932025-01-21T15:54:07.823Z
6942025-01-21T15:54:07.823Z TAGS 0 1 2 DIFF
6952025-01-21T15:54:07.823Z------ -------------------------------- -------------------------------- -------------------------------- -----
6962025-01-21T15:54:07.823Z 0 0d59f7af3b082fcc8c9267cd1b37a725 0d59f7af3b082fcc8c9267cd1b37a725 0d59f7af3b082fcc8c9267cd1b37a725
6972025-01-21T15:54:07.823Z
6982025-01-21T15:54:07.823ZHASHES 0 1 2 DIFF
6992025-01-21T15:54:07.823Z------ ---------------- ---------------- ---------------- -----
7002025-01-21T15:54:07.823Z
7012025-01-21T15:54:07.826Zdump block test passed
7022025-01-21T15:54:07.826ZInitial upstairs tests have completed, stopping all downstairs
7032025-01-21T15:54:12.890ZCreating 7 larger downstairs regions
7042025-01-21T15:54:13.077ZStarting 7 downstairs
7052025-01-21T15:54:18.085Zdsc restarted at PID: 1265
7062025-01-21T15:54:18.472ZNow do the replace-reconcile test
7072025-01-21T15:54:18.526ZUsing 8870 for the replacement port
7082025-01-21T15:56:55.849ZCompleted test: replace-reconcile
7092025-01-21T15:56:55.849ZNow do the replace-before-active test
7102025-01-21T16:00:29.393ZCompleted test: replace-before-active
7112025-01-21T16:00:29.393ZAll tests have completed, stopping all downstairs
7122025-01-21T16:00:29.454Z
7132025-01-21T16:00:29.454ZAll Tests have passed
7142025-01-21T16:00:29.457Z13:24 Test duration
7152025-01-21T16:00:29.457Z
7162025-01-21T16:00:29.457Zreal 13:24.807564923
7172025-01-21T16:00:29.457Zuser 18:32.146377302
7182025-01-21T16:00:29.457Zsys 24.266410938
7192025-01-21T16:00:29.457Ztrap 0.525430578
7202025-01-21T16:00:29.457Ztflt 0.032396650
7212025-01-21T16:00:29.457Zdflt 0.033312577
7222025-01-21T16:00:29.457Zkflt 0.002201633
7232025-01-21T16:00:29.457Zlock 25:41:20.831046004
7242025-01-21T16:00:29.457Zslp 1:14:44.975291603
7252025-01-21T16:00:29.457Zlat 2:00.791573204
7262025-01-21T16:00:29.457Zstop 0.286610040
7272025-01-21T16:00:29.457Z+ echo 'test-up-2region-encrypted ends'
7282025-01-21T16:00:29.457Ztest-up-2region-encrypted ends
7292025-01-21T16:00:34.460Zprocess exited: duration 813039 ms, exit code 0
7302025-01-21T16:00:34.460Zexec warning: : stdio descriptors remain open after task exit; waiting 60 seconds for them to close
7312025-01-21T16:01:34.506Zexec warning: : stdout descriptor may be held open by a background process; giving up!
7322025-01-21T16:01:34.506Zexec warning: : stderr descriptor may be held open by a background process; giving up!
 
7332025-01-21T16:01:34.525Zfound 17 output files
7342025-01-21T16:01:34.525Zuploading: /tmp/test_up-build/dsc-out.txt (48902 bytes)
7352025-01-21T16:01:35.539Zuploaded: /tmp/test_up-build/dsc-out.txt
7362025-01-21T16:01:35.539Zuploading: /tmp/test_up-build/test_up_out.txt (8474415 bytes)
7372025-01-21T16:01:36.626Zuploaded: /tmp/test_up-build/test_up_out.txt
7382025-01-21T16:01:36.626Zuploading: /tmp/test_up-build/dsc/downstairs-8810.txt (147254 bytes)
7392025-01-21T16:01:37.642Zuploaded: /tmp/test_up-build/dsc/downstairs-8810.txt
7402025-01-21T16:01:37.642Zuploading: /tmp/test_up-build/dsc/downstairs-8820.txt (144652 bytes)
7412025-01-21T16:01:38.656Zuploaded: /tmp/test_up-build/dsc/downstairs-8820.txt
7422025-01-21T16:01:38.659Zuploading: /tmp/test_up-build/dsc/downstairs-8830.txt (251025 bytes)
7432025-01-21T16:01:39.671Zuploaded: /tmp/test_up-build/dsc/downstairs-8830.txt
7442025-01-21T16:01:39.674Zuploading: /tmp/test_up-build/dsc/downstairs-8840.txt (139435 bytes)
7452025-01-21T16:01:40.685Zuploaded: /tmp/test_up-build/dsc/downstairs-8840.txt
7462025-01-21T16:01:40.685Zuploading: /tmp/test_up-build/dsc/downstairs-8850.txt (2509 bytes)
7472025-01-21T16:01:41.693Zuploaded: /tmp/test_up-build/dsc/downstairs-8850.txt
7482025-01-21T16:01:41.693Zuploading: /tmp/test_up-build/dsc/downstairs-8860.txt (33801 bytes)
7492025-01-21T16:01:42.704Zuploaded: /tmp/test_up-build/dsc/downstairs-8860.txt
7502025-01-21T16:01:42.704Zuploading: /tmp/test_up-build/dsc/downstairs-8870.txt (735709 bytes)
7512025-01-21T16:01:43.724Zuploaded: /tmp/test_up-build/dsc/downstairs-8870.txt
7522025-01-21T16:01:43.725Zuploading: /tmp/debug/df.txt (1270 bytes)
7532025-01-21T16:01:44.733Zuploaded: /tmp/debug/df.txt
7542025-01-21T16:01:44.733Zuploading: /tmp/debug/dtrace.txt (997583 bytes)
7552025-01-21T16:01:45.755Zuploaded: /tmp/debug/dtrace.txt
7562025-01-21T16:01:45.755Zuploading: /tmp/debug/iostat.txt (261061 bytes)
7572025-01-21T16:01:45.769Zupload warning: file "/tmp/debug/iostat.txt" changed size mid upload: 261061 -> 264661
7582025-01-21T16:01:46.775Zuploaded: /tmp/debug/iostat.txt
7592025-01-21T16:01:46.775Zuploading: /tmp/debug/mpstat.txt (634243 bytes)
7602025-01-21T16:01:46.790Zupload warning: file "/tmp/debug/mpstat.txt" changed size mid upload: 634243 -> 643720
7612025-01-21T16:01:47.799Zuploaded: /tmp/debug/mpstat.txt
7622025-01-21T16:01:47.802Zuploading: /tmp/debug/paging.txt (113796 bytes)
7632025-01-21T16:01:48.822Zupload warning: file "/tmp/debug/paging.txt" changed size mid upload: 113796 -> 115837
7642025-01-21T16:01:49.829Zuploaded: /tmp/debug/paging.txt
7652025-01-21T16:01:49.829Zuploading: /tmp/debug/prstat.txt (1231708 bytes)
7662025-01-21T16:01:49.850Zupload warning: file "/tmp/debug/prstat.txt" changed size mid upload: 1231708 -> 1251097
7672025-01-21T16:01:50.856Zuploaded: /tmp/debug/prstat.txt
7682025-01-21T16:01:50.856Zuploading: /tmp/debug/psrinfo.txt (1528 bytes)
7692025-01-21T16:01:51.865Zuploaded: /tmp/debug/psrinfo.txt
7702025-01-21T16:01:51.867Zuploading: /tmp/debug/upstairs-info.txt (190536 bytes)
7712025-01-21T16:01:52.880Zuploaded: /tmp/debug/upstairs-info.txt