01JW9RGYXKS1RM53DT586RFR5C: 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: 01JW9RHAVJ2DP61E6ZX1C9H1GS

Tags:

Artefacts:

Output:

SEQ GLOBAL TIME DETAILS
12025-05-27T21:11:28.988Zjob dependencies complete; ready to run (waiting for 14 m 35 s)
22025-05-27T21:12:03.098Zjob assigned to worker 01JW9SC20PHVDTY2CNW5R6ERDR [factory gimlet-EVT22200007-propolis, EVT22200007/28524] (queued for 34 s)
32025-05-27T21:12:11.754Zdownloading input: /input/build/work/bins/crucible-downstairs.gz
42025-05-27T21:12:22.296Zdownloaded input: /input/build/work/bins/crucible-downstairs.gz
52025-05-27T21:12:22.296Zdownloading input: /input/build/work/bins/crucible-hammer.gz
62025-05-27T21:12:27.643Zdownloaded input: /input/build/work/bins/crucible-hammer.gz
72025-05-27T21:12:27.643Zdownloading input: /input/build/work/bins/crutest.gz
82025-05-27T21:12:36.016Zdownloaded input: /input/build/work/bins/crutest.gz
92025-05-27T21:12:36.016Zdownloading input: /input/build/work/bins/dsc.gz
102025-05-27T21:12:40.995Zdownloaded input: /input/build/work/bins/dsc.gz
112025-05-27T21:12:41.022Zdownloading input: /input/build/work/scripts/perf-downstairs-tick.d
122025-05-27T21:12:41.047Zdownloaded input: /input/build/work/scripts/perf-downstairs-tick.d
132025-05-27T21:12:41.047Zdownloading input: /input/build/work/scripts/test_ds.sh
142025-05-27T21:12:41.081Zdownloaded input: /input/build/work/scripts/test_ds.sh
152025-05-27T21:12:41.081Zdownloading input: /input/build/work/scripts/test_live_repair.sh
162025-05-27T21:12:41.125Zdownloaded input: /input/build/work/scripts/test_live_repair.sh
172025-05-27T21:12:41.125Zdownloading input: /input/build/work/scripts/test_repair.sh
182025-05-27T21:12:41.169Zdownloaded input: /input/build/work/scripts/test_repair.sh
192025-05-27T21:12:41.169Zdownloading input: /input/build/work/scripts/test_replay.sh
202025-05-27T21:12:41.217Zdownloaded input: /input/build/work/scripts/test_replay.sh
212025-05-27T21:12:41.217Zdownloading input: /input/build/work/scripts/test_up.sh
222025-05-27T21:12:41.260Zdownloaded input: /input/build/work/scripts/test_up.sh
232025-05-27T21:12:41.261Zdownloading input: /input/build/work/scripts/upstairs_info.d
242025-05-27T21:12:41.305Zdownloaded input: /input/build/work/scripts/upstairs_info.d
252025-05-27T21:12:41.330Zdownloading input: /input/build/tmp/cargo-test-out.log
262025-05-27T21:12:45.387Zdownloaded input: /input/build/tmp/cargo-test-out.log
 
272025-05-27T21:12:45.387Zstarting task 0: "setup"
282025-05-27T21:12:45.413Z++ uname -s
292025-05-27T21:12:45.413Z+ kern=SunOS
302025-05-27T21:12:45.413Z+ build_user=build
312025-05-27T21:12:45.413Z+ build_uid=12345
322025-05-27T21:12:45.413Z+ work_dir=/work
332025-05-27T21:12:45.413Z+ input_dir=/input
342025-05-27T21:12:45.413Z+ [[ 0 == 12345 ]]
352025-05-27T21:12:45.413Z+ case "$kern" in
362025-05-27T21:12:45.413Z+ groupadd -g 12345 build
372025-05-27T21:12:45.413Z+ useradd -u 12345 -g build -d /home/build -s /bin/bash -c build -P 'Primary Administrator' build
382025-05-27T21:12:47.416Z+ zfs create -o mountpoint=/work rpool/work
392025-05-27T21:12:47.450Z++ awk '$2 == "/home" { print $3 }' /etc/mnttab
402025-05-27T21:12:47.475Z+ home_fs=zfs
412025-05-27T21:12:47.475Z+ [[ zfs == autofs ]]
422025-05-27T21:12:47.475Z+ mkdir -p /home/build
432025-05-27T21:12:47.475Z+ chown build:build /home/build /work
442025-05-27T21:12:49.459Z+ chmod 0700 /home/build /work
452025-05-27T21:12:49.486Zprocess exited: duration 4075 ms, exit code 0
 
462025-05-27T21:12:49.538Zstarting task 1: "authentication"
472025-05-27T21:12:49.589Zprocess exited: duration 50 ms, exit code 0
 
482025-05-27T21:12:49.643Zstarting task 2: "build"
492025-05-27T21:12:49.669Z+ banner cores
502025-05-27T21:12:49.669Z
512025-05-27T21:12:49.669Z #### #### ##### ###### ####
522025-05-27T21:12:49.669Z # # # # # # # #
532025-05-27T21:12:49.669Z # # # # # ##### ####
542025-05-27T21:12:49.669Z # # # ##### # #
552025-05-27T21:12:49.669Z # # # # # # # # #
562025-05-27T21:12:49.669Z #### #### # # ###### ####
572025-05-27T21:12:49.669Z
582025-05-27T21:12:49.669Z+ pfexec coreadm -i /tmp/core.%f.%p -g /tmp/core.%f.%p -e global -e log -e proc-setid -e global-setid
592025-05-27T21:12:49.669Z+ banner unpack
602025-05-27T21:12:49.669Z
612025-05-27T21:12:49.670Z # # # # ##### ## #### # #
622025-05-27T21:12:49.670Z # # ## # # # # # # # # #
632025-05-27T21:12:49.670Z # # # # # # # # # # ####
642025-05-27T21:12:49.670Z # # # # # ##### ###### # # #
652025-05-27T21:12:49.670Z # # # ## # # # # # # #
662025-05-27T21:12:49.670Z #### # # # # # #### # #
672025-05-27T21:12:49.670Z
682025-05-27T21:12:49.670Z+ mkdir -p /var/tmp/bins
692025-05-27T21:12:49.670Z+ for t in "$input/bins/"*.gz
702025-05-27T21:12:49.670Z++ basename /input/build/work/bins/crucible-downstairs.gz
712025-05-27T21:12:49.696Z+ b=crucible-downstairs.gz
722025-05-27T21:12:49.696Z+ b=crucible-downstairs
732025-05-27T21:12:49.696Z+ gunzip
742025-05-27T21:12:52.785Z+ chmod +x /var/tmp/bins/crucible-downstairs
752025-05-27T21:12:52.813Z+ for t in "$input/bins/"*.gz
762025-05-27T21:12:52.813Z++ basename /input/build/work/bins/crucible-hammer.gz
772025-05-27T21:12:52.813Z+ b=crucible-hammer.gz
782025-05-27T21:12:52.813Z+ b=crucible-hammer
792025-05-27T21:12:52.814Z+ gunzip
802025-05-27T21:12:55.586Z+ chmod +x /var/tmp/bins/crucible-hammer
812025-05-27T21:12:55.611Z+ for t in "$input/bins/"*.gz
822025-05-27T21:12:55.611Z++ basename /input/build/work/bins/crutest.gz
832025-05-27T21:12:55.611Z+ b=crutest.gz
842025-05-27T21:12:55.611Z+ b=crutest
852025-05-27T21:12:55.611Z+ gunzip
862025-05-27T21:12:58.673Z+ chmod +x /var/tmp/bins/crutest
872025-05-27T21:12:58.698Z+ for t in "$input/bins/"*.gz
882025-05-27T21:12:58.698Z++ basename /input/build/work/bins/dsc.gz
892025-05-27T21:12:58.698Z+ b=dsc.gz
902025-05-27T21:12:58.698Z+ b=dsc
912025-05-27T21:12:58.698Z+ gunzip
922025-05-27T21:13:00.264Z+ chmod +x /var/tmp/bins/dsc
932025-05-27T21:13:00.290Z+ export BINDIR=/var/tmp/bins
942025-05-27T21:13:00.290Z+ BINDIR=/var/tmp/bins
952025-05-27T21:13:00.290Z+ jobpid=1153
962025-05-27T21:13:00.290Z+ echo 'Setup debug logging'
972025-05-27T21:13:00.290ZSetup debug logging
982025-05-27T21:13:00.290Z+ mkdir /tmp/debug
992025-05-27T21:13:00.290Z+ sleep 3600
1002025-05-27T21:13:00.290Z+ psrinfo -v
1012025-05-27T21:13:00.290Z+ df -h
1022025-05-27T21:13:00.290Zdf: cannot statvfs /var/metadata/iso: Permission denied
1032025-05-27T21:13:00.290Z+ true
1042025-05-27T21:13:00.290Z+ prstat -d d -mLc 1
1052025-05-27T21:13:00.290Z+ iostat -T d -xn 1
1062025-05-27T21:13:00.290Z+ mpstat -T d 1
1072025-05-27T21:13:00.315Z+ vmstat -T d -p 1
1082025-05-27T21:13:00.315Z+ pfexec dtrace -Z -s /input/build/work/scripts/perf-downstairs-tick.d
1092025-05-27T21:13:00.315Z+ banner test_up_2r_encrypted
1102025-05-27T21:13:00.315Z+ pfexec dtrace -Z -s /input/build/work/scripts/upstairs_info.d
1112025-05-27T21:13:00.315Z #####
1122025-05-27T21:13:00.315Z ##### ###### #### ##### # # ##### # # #####
1132025-05-27T21:13:00.315Z # # # # # # # # # # #
1142025-05-27T21:13:00.315Z # ##### #### # # # # # ##### # #
1152025-05-27T21:13:00.315Z # # # # # # ##### # #####
1162025-05-27T21:13:00.315Z # # # # # # # # # # #
1172025-05-27T21:13:00.315Z # ###### #### # ####### #### # ####### ####### # #
1182025-05-27T21:13:00.315Z
1192025-05-27T21:13:00.315Z+ ptime -m bash /input/build/work/scripts/test_up.sh -r 2 -N encrypted
1202025-05-27T21:13:00.315Z/input/build/work
1212025-05-27T21:13:00.340ZUsing 2 region sets
1222025-05-27T21:13:00.340ZTurn off color for downstairs dump
1232025-05-27T21:13:00.365ZUpstairs using key: CnZvPnPOKbrPY355yyOGXSwV1w0yrZFYdM2pVQH9kSE=
1242025-05-27T21:13:00.365Zdsc output goes to /tmp/test_up-build/dsc-out.txt
1252025-05-27T21:13:00.365ZCreating 6 downstairs regions
1262025-05-27T21:13:00.873ZStarting 6 downstairs
1272025-05-27T21:13:00.898Zdsc started at PID: 1201
1282025-05-27T21:13:06.372ZDisable automatic restart on all downstairs
1292025-05-27T21:13:06.451Z
1302025-05-27T21:13:06.451ZBegin tests, output goes to /tmp/test_up-build/test_up_out.txt
1312025-05-27T21:13:06.476ZRunning test: span
1322025-05-27T21:13:10.793ZCompleted test: span
1332025-05-27T21:13:15.803ZRunning test: big
1342025-05-27T21:13:20.579ZCompleted test: big
1352025-05-27T21:13:25.589ZRunning test: dep
1362025-05-27T21:14:01.444ZCompleted test: dep
1372025-05-27T21:14:06.454ZRunning test: balloon
1382025-05-27T21:19:13.392ZCompleted test: balloon
1392025-05-27T21:19:18.400ZRunning test: deactivate
1402025-05-27T21:20:13.184ZCompleted test: deactivate
1412025-05-27T21:20:18.192ZRunning hammer
1422025-05-27T21:20:39.798ZRun repair tests
1432025-05-27T21:20:39.823Z/var/tmp/bins/crutest fill -g 31 -q --key CnZvPnPOKbrPY355yyOGXSwV1w0yrZFYdM2pVQH9kSE= --dsc 127.0.0.1:9998 --verify-out /var/tmp/test_up-build/verify_file
1442025-05-27T21:20:39.877Z{"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-05-27T21:20:39.081245981Z","hostname":"bmat-EVT22200007-00006f6c","pid":1244,"task":"crutest"}
1452025-05-27T21:20:39.948Z{"msg":"dsc has 6 regions. This means 2 sub_volumes","v":0,"name":"crucible","level":30,"time":"2025-05-27T21:20:39.081900624Z","hostname":"bmat-EVT22200007-00006f6c","pid":1244,"task":"crutest"}
1462025-05-27T21:20:39.948Z{"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-05-27T21:20:39.084451943Z","hostname":"bmat-EVT22200007-00006f6c","pid":1244,"task":"crutest"}
1472025-05-27T21:20:39.948Z{"msg":"Upstairs starts","v":0,"name":"crucible","level":30,"time":"2025-05-27T21:20:39.084746008Z","hostname":"bmat-EVT22200007-00006f6c","pid":1244}
1482025-05-27T21:20:39.948Z{"msg":"Crucible Version: BuildInfo {\n version: \"0.0.1\",\n git_sha: \"dd892d47062b1dcb23800b8bbb5d2946e1dd1cb7\",\n git_commit_timestamp: \"2025-05-27T20:18:55.000000000Z\",\n git_branch: \"alan/agent-needs-workers\",\n rustc_semver: \"1.86.0\",\n rustc_channel: \"stable\",\n rustc_host_triple: \"x86_64-unknown-illumos\",\n rustc_commit_sha: \"05f9846f893b09a1be1fc8560e33fc3c815cfecb\",\n cargo_triple: \"x86_64-unknown-illumos\",\n debug: true,\n opt_level: 0,\n}","v":0,"name":"crucible","level":30,"time":"2025-05-27T21:20:39.084796459Z","hostname":"bmat-EVT22200007-00006f6c","pid":1244}
1492025-05-27T21:20:39.948Z{"msg":"Upstairs <-> Downstairs Message Version: 13","v":0,"name":"crucible","level":30,"time":"2025-05-27T21:20:39.084834124Z","hostname":"bmat-EVT22200007-00006f6c","pid":1244}
1502025-05-27T21:20:39.948Z{"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-05-27T21:20:39.084853142Z","hostname":"bmat-EVT22200007-00006f6c","pid":1244}
1512025-05-27T21:20:39.948Z{"msg":"Crucible 4fe115b2-d77c-4848-8c6e-0f45a40c9acf has session id: 53eaf899-ba90-4cf0-acc8-8e70a273d3da","v":0,"name":"crucible","level":30,"time":"2025-05-27T21:20:39.085958672Z","hostname":"bmat-EVT22200007-00006f6c","pid":1244,"session_id":"53eaf899-ba90-4cf0-acc8-8e70a273d3da"}
1522025-05-27T21:20:39.948Z{"msg":"Upstairs opts: Upstairs UUID: 4fe115b2-d77c-4848-8c6e-0f45a40c9acf, 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-05-27T21:20:39.086087048Z","hostname":"bmat-EVT22200007-00006f6c","pid":1244,"session_id":"53eaf899-ba90-4cf0-acc8-8e70a273d3da"}
1532025-05-27T21:20:39.948Z{"msg":"Crucible stats registered with UUID: 4fe115b2-d77c-4848-8c6e-0f45a40c9acf","v":0,"name":"crucible","level":30,"time":"2025-05-27T21:20:39.086106687Z","hostname":"bmat-EVT22200007-00006f6c","pid":1244,"session_id":"53eaf899-ba90-4cf0-acc8-8e70a273d3da"}
1542025-05-27T21:20:39.948Z{"msg":"could not find Downstairs address for Nexus","v":0,"name":"crucible","level":40,"time":"2025-05-27T21:20:39.086155685Z","hostname":"bmat-EVT22200007-00006f6c","pid":1244,"session_id":"53eaf899-ba90-4cf0-acc8-8e70a273d3da"}
1552025-05-27T21:20:39.948Z{"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-05-27T21:20:39.089540633Z","hostname":"bmat-EVT22200007-00006f6c","pid":1244,"task":"crutest"}
1562025-05-27T21:20:39.948Z{"msg":"Upstairs starts","v":0,"name":"crucible","level":30,"time":"2025-05-27T21:20:39.089660081Z","hostname":"bmat-EVT22200007-00006f6c","pid":1244}
1572025-05-27T21:20:39.949Z{"msg":"Crucible Version: BuildInfo {\n version: \"0.0.1\",\n git_sha: \"dd892d47062b1dcb23800b8bbb5d2946e1dd1cb7\",\n git_commit_timestamp: \"2025-05-27T20:18:55.000000000Z\",\n git_branch: \"alan/agent-needs-workers\",\n rustc_semver: \"1.86.0\",\n rustc_channel: \"stable\",\n rustc_host_triple: \"x86_64-unknown-illumos\",\n rustc_commit_sha: \"05f9846f893b09a1be1fc8560e33fc3c815cfecb\",\n cargo_triple: \"x86_64-unknown-illumos\",\n debug: true,\n opt_level: 0,\n}","v":0,"name":"crucible","level":30,"time":"2025-05-27T21:20:39.089709659Z","hostname":"bmat-EVT22200007-00006f6c","pid":1244}
1582025-05-27T21:20:39.949Z{"msg":"Upstairs <-> Downstairs Message Version: 13","v":0,"name":"crucible","level":30,"time":"2025-05-27T21:20:39.089726894Z","hostname":"bmat-EVT22200007-00006f6c","pid":1244}
1592025-05-27T21:20:39.949Z{"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-05-27T21:20:39.089757274Z","hostname":"bmat-EVT22200007-00006f6c","pid":1244}
1602025-05-27T21:20:39.949Z{"msg":"Crucible 4fe115b2-d77c-4848-8c6e-0f45a40c9acf has session id: 82d4e992-ed62-4418-8c2c-4ba79eedb568","v":0,"name":"crucible","level":30,"time":"2025-05-27T21:20:39.09081025Z","hostname":"bmat-EVT22200007-00006f6c","pid":1244,"session_id":"82d4e992-ed62-4418-8c2c-4ba79eedb568"}
1612025-05-27T21:20:39.949Z{"msg":"Upstairs opts: Upstairs UUID: 4fe115b2-d77c-4848-8c6e-0f45a40c9acf, 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-05-27T21:20:39.090893947Z","hostname":"bmat-EVT22200007-00006f6c","pid":1244,"session_id":"82d4e992-ed62-4418-8c2c-4ba79eedb568"}
1622025-05-27T21:20:39.949Z{"msg":"Crucible stats registered with UUID: 4fe115b2-d77c-4848-8c6e-0f45a40c9acf","v":0,"name":"crucible","level":30,"time":"2025-05-27T21:20:39.09091571Z","hostname":"bmat-EVT22200007-00006f6c","pid":1244,"session_id":"82d4e992-ed62-4418-8c2c-4ba79eedb568"}
1632025-05-27T21:20:39.949Z{"msg":"could not find Downstairs address for Nexus","v":0,"name":"crucible","level":40,"time":"2025-05-27T21:20:39.090932764Z","hostname":"bmat-EVT22200007-00006f6c","pid":1244,"session_id":"82d4e992-ed62-4418-8c2c-4ba79eedb568"}
1642025-05-27T21:20:39.949Z{"msg":"Downstairs in volume = 6","v":0,"name":"crucible","level":30,"time":"2025-05-27T21:20:39.093177553Z","hostname":"bmat-EVT22200007-00006f6c","pid":1244,"task":"crutest"}
1652025-05-27T21:20:39.949Z{"msg":"The guest has requested activation with gen:31","v":0,"name":"crucible","level":30,"time":"2025-05-27T21:20:39.093243634Z","hostname":"bmat-EVT22200007-00006f6c","pid":1244}
1662025-05-27T21:20:39.949Z{"msg":"4fe115b2-d77c-4848-8c6e-0f45a40c9acf active request set","v":0,"name":"crucible","level":30,"time":"2025-05-27T21:20:39.093268424Z","hostname":"bmat-EVT22200007-00006f6c","pid":1244,"session_id":"53eaf899-ba90-4cf0-acc8-8e70a273d3da"}
1672025-05-27T21:20:39.949Z{"msg":"sending connect oneshot to client","v":0,"name":"crucible","level":30,"time":"2025-05-27T21:20:39.093296239Z","hostname":"bmat-EVT22200007-00006f6c","pid":1244,"client":"0","":"downstairs","session_id":"53eaf899-ba90-4cf0-acc8-8e70a273d3da"}
1682025-05-27T21:20:39.949Z{"msg":"client set_active_request while in Connecting { state: Start { auto_promote: true }, mode: New }; waiting...","v":0,"name":"crucible","level":30,"time":"2025-05-27T21:20:39.093361509Z","hostname":"bmat-EVT22200007-00006f6c","pid":1244,"client":"0","":"downstairs","session_id":"53eaf899-ba90-4cf0-acc8-8e70a273d3da"}
1692025-05-27T21:20:39.949Z{"msg":"sending connect oneshot to client","v":0,"name":"crucible","level":30,"time":"2025-05-27T21:20:39.09339232Z","hostname":"bmat-EVT22200007-00006f6c","pid":1244,"client":"1","":"downstairs","session_id":"53eaf899-ba90-4cf0-acc8-8e70a273d3da"}
1702025-05-27T21:20:39.949Z{"msg":"client set_active_request while in Connecting { state: Start { auto_promote: true }, mode: New }; waiting...","v":0,"name":"crucible","level":30,"time":"2025-05-27T21:20:39.093440276Z","hostname":"bmat-EVT22200007-00006f6c","pid":1244,"client":"1","":"downstairs","session_id":"53eaf899-ba90-4cf0-acc8-8e70a273d3da"}
1712025-05-27T21:20:39.949Z{"msg":"sending connect oneshot to client","v":0,"name":"crucible","level":30,"time":"2025-05-27T21:20:39.09346741Z","hostname":"bmat-EVT22200007-00006f6c","pid":1244,"client":"2","":"downstairs","session_id":"53eaf899-ba90-4cf0-acc8-8e70a273d3da"}
1722025-05-27T21:20:39.949Z{"msg":"client set_active_request while in Connecting { state: Start { auto_promote: true }, mode: New }; waiting...","v":0,"name":"crucible","level":30,"time":"2025-05-27T21:20:39.093512279Z","hostname":"bmat-EVT22200007-00006f6c","pid":1244,"client":"2","":"downstairs","session_id":"53eaf899-ba90-4cf0-acc8-8e70a273d3da"}
1732025-05-27T21:20:39.949Z{"msg":"connecting to 127.0.0.1:8830","v":0,"name":"crucible","level":30,"time":"2025-05-27T21:20:39.093536578Z","hostname":"bmat-EVT22200007-00006f6c","pid":1244,"":"io task","client":"2","":"downstairs","session_id":"53eaf899-ba90-4cf0-acc8-8e70a273d3da"}
1742025-05-27T21:20:39.949Z{"msg":"connecting to 127.0.0.1:8810","v":0,"name":"crucible","level":30,"time":"2025-05-27T21:20:39.093565034Z","hostname":"bmat-EVT22200007-00006f6c","pid":1244,"":"io task","client":"0","":"downstairs","session_id":"53eaf899-ba90-4cf0-acc8-8e70a273d3da"}
1752025-05-27T21:20:39.949Z{"msg":"connecting to 127.0.0.1:8820","v":0,"name":"crucible","level":30,"time":"2025-05-27T21:20:39.093594924Z","hostname":"bmat-EVT22200007-00006f6c","pid":1244,"":"io task","client":"1","":"downstairs","session_id":"53eaf899-ba90-4cf0-acc8-8e70a273d3da"}
1762025-05-27T21:20:39.949Z{"msg":"ds_connection connected from Ok(127.0.0.1:50373)","v":0,"name":"crucible","level":30,"time":"2025-05-27T21:20:39.093989519Z","hostname":"bmat-EVT22200007-00006f6c","pid":1244,"":"io task","client":"2","":"downstairs","session_id":"53eaf899-ba90-4cf0-acc8-8e70a273d3da"}
1772025-05-27T21:20:39.949Z{"msg":"ds_connection connected from Ok(127.0.0.1:36766)","v":0,"name":"crucible","level":30,"time":"2025-05-27T21:20:39.094234888Z","hostname":"bmat-EVT22200007-00006f6c","pid":1244,"":"io task","client":"1","":"downstairs","session_id":"53eaf899-ba90-4cf0-acc8-8e70a273d3da"}
1782025-05-27T21:20:39.949Z{"msg":"ds_connection connected from Ok(127.0.0.1:53642)","v":0,"name":"crucible","level":30,"time":"2025-05-27T21:20:39.094325979Z","hostname":"bmat-EVT22200007-00006f6c","pid":1244,"":"io task","client":"0","":"downstairs","session_id":"53eaf899-ba90-4cf0-acc8-8e70a273d3da"}
1792025-05-27T21:20:39.949Z{"msg":"version negotiation from state Connecting { state: WaitForPromote, mode: New }","v":0,"name":"crucible","level":30,"time":"2025-05-27T21:20:39.094985332Z","hostname":"bmat-EVT22200007-00006f6c","pid":1244,"client":"2","":"downstairs","session_id":"53eaf899-ba90-4cf0-acc8-8e70a273d3da"}
1802025-05-27T21:20:39.949Z{"msg":"version negotiation from state Connecting { state: WaitForPromote, mode: New }","v":0,"name":"crucible","level":30,"time":"2025-05-27T21:20:39.095291431Z","hostname":"bmat-EVT22200007-00006f6c","pid":1244,"client":"1","":"downstairs","session_id":"53eaf899-ba90-4cf0-acc8-8e70a273d3da"}
1812025-05-27T21:20:39.949Z{"msg":"version negotiation from state Connecting { state: WaitForPromote, mode: New }","v":0,"name":"crucible","level":30,"time":"2025-05-27T21:20:39.09552685Z","hostname":"bmat-EVT22200007-00006f6c","pid":1244,"client":"0","":"downstairs","session_id":"53eaf899-ba90-4cf0-acc8-8e70a273d3da"}
1822025-05-27T21:20:39.950Z{"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-05-27T21:20:39.095946485Z","hostname":"bmat-EVT22200007-00006f6c","pid":1244,"client":"2","":"downstairs","session_id":"53eaf899-ba90-4cf0-acc8-8e70a273d3da"}
1832025-05-27T21:20:39.950Z{"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-05-27T21:20:39.096138107Z","hostname":"bmat-EVT22200007-00006f6c","pid":1244,"client":"1","":"downstairs","session_id":"53eaf899-ba90-4cf0-acc8-8e70a273d3da"}
1842025-05-27T21:20:39.950Z{"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-05-27T21:20:39.096176964Z","hostname":"bmat-EVT22200007-00006f6c","pid":1244,"client":"0","":"downstairs","session_id":"53eaf899-ba90-4cf0-acc8-8e70a273d3da"}
1852025-05-27T21:20:39.950Z{"msg":"Waiting for more clients to be ready","v":0,"name":"crucible","level":30,"time":"2025-05-27T21:20:39.096413685Z","hostname":"bmat-EVT22200007-00006f6c","pid":1244,"session_id":"53eaf899-ba90-4cf0-acc8-8e70a273d3da"}
1862025-05-27T21:20:39.950Z{"msg":"Waiting for more clients to be ready","v":0,"name":"crucible","level":30,"time":"2025-05-27T21:20:39.096618052Z","hostname":"bmat-EVT22200007-00006f6c","pid":1244,"session_id":"53eaf899-ba90-4cf0-acc8-8e70a273d3da"}
1872025-05-27T21:20:39.950Z{"msg":"[0]R flush_numbers: [3999, 3999, 3999, 3999, 3999]","v":0,"name":"crucible","level":30,"time":"2025-05-27T21:20:39.096700145Z","hostname":"bmat-EVT22200007-00006f6c","pid":1244,"":"downstairs","":"downstairs","session_id":"53eaf899-ba90-4cf0-acc8-8e70a273d3da"}
1882025-05-27T21:20:39.950Z{"msg":"[0]R generation: [25, 25, 25, 25, 25]","v":0,"name":"crucible","level":30,"time":"2025-05-27T21:20:39.096722169Z","hostname":"bmat-EVT22200007-00006f6c","pid":1244,"":"downstairs","":"downstairs","session_id":"53eaf899-ba90-4cf0-acc8-8e70a273d3da"}
1892025-05-27T21:20:39.950Z{"msg":"[0]R dirty: [false, false, false, false, false]","v":0,"name":"crucible","level":30,"time":"2025-05-27T21:20:39.096756447Z","hostname":"bmat-EVT22200007-00006f6c","pid":1244,"":"downstairs","":"downstairs","session_id":"53eaf899-ba90-4cf0-acc8-8e70a273d3da"}
1902025-05-27T21:20:39.950Z{"msg":"[1]R flush_numbers: [3999, 3999, 3999, 3999, 3999]","v":0,"name":"crucible","level":30,"time":"2025-05-27T21:20:39.096774443Z","hostname":"bmat-EVT22200007-00006f6c","pid":1244,"":"downstairs","":"downstairs","session_id":"53eaf899-ba90-4cf0-acc8-8e70a273d3da"}
1912025-05-27T21:20:39.950Z{"msg":"[1]R generation: [25, 25, 25, 25, 25]","v":0,"name":"crucible","level":30,"time":"2025-05-27T21:20:39.096806437Z","hostname":"bmat-EVT22200007-00006f6c","pid":1244,"":"downstairs","":"downstairs","session_id":"53eaf899-ba90-4cf0-acc8-8e70a273d3da"}
1922025-05-27T21:20:39.950Z{"msg":"[1]R dirty: [false, false, false, false, false]","v":0,"name":"crucible","level":30,"time":"2025-05-27T21:20:39.096823812Z","hostname":"bmat-EVT22200007-00006f6c","pid":1244,"":"downstairs","":"downstairs","session_id":"53eaf899-ba90-4cf0-acc8-8e70a273d3da"}
1932025-05-27T21:20:39.950Z{"msg":"[2]R flush_numbers: [3999, 3999, 3999, 3999, 3999]","v":0,"name":"crucible","level":30,"time":"2025-05-27T21:20:39.096839673Z","hostname":"bmat-EVT22200007-00006f6c","pid":1244,"":"downstairs","":"downstairs","session_id":"53eaf899-ba90-4cf0-acc8-8e70a273d3da"}
1942025-05-27T21:20:39.950Z{"msg":"[2]R generation: [25, 25, 25, 25, 25]","v":0,"name":"crucible","level":30,"time":"2025-05-27T21:20:39.096856286Z","hostname":"bmat-EVT22200007-00006f6c","pid":1244,"":"downstairs","":"downstairs","session_id":"53eaf899-ba90-4cf0-acc8-8e70a273d3da"}
1952025-05-27T21:20:39.950Z{"msg":"[2]R dirty: [false, false, false, false, false]","v":0,"name":"crucible","level":30,"time":"2025-05-27T21:20:39.096876717Z","hostname":"bmat-EVT22200007-00006f6c","pid":1244,"":"downstairs","":"downstairs","session_id":"53eaf899-ba90-4cf0-acc8-8e70a273d3da"}
1962025-05-27T21:20:39.950Z{"msg":"Max found gen is 26","v":0,"name":"crucible","level":30,"time":"2025-05-27T21:20:39.096892168Z","hostname":"bmat-EVT22200007-00006f6c","pid":1244,"":"downstairs","":"downstairs","session_id":"53eaf899-ba90-4cf0-acc8-8e70a273d3da"}
1972025-05-27T21:20:39.950Z{"msg":"Generation requested: 31 >= found:26","v":0,"name":"crucible","level":30,"time":"2025-05-27T21:20:39.096925995Z","hostname":"bmat-EVT22200007-00006f6c","pid":1244,"":"downstairs","":"downstairs","session_id":"53eaf899-ba90-4cf0-acc8-8e70a273d3da"}
1982025-05-27T21:20:39.950Z{"msg":"Next flush: 4000","v":0,"name":"crucible","level":30,"time":"2025-05-27T21:20:39.096941927Z","hostname":"bmat-EVT22200007-00006f6c","pid":1244,"":"downstairs","":"downstairs","session_id":"53eaf899-ba90-4cf0-acc8-8e70a273d3da"}
1992025-05-27T21:20:39.950Z{"msg":"All extents match","v":0,"name":"crucible","level":30,"time":"2025-05-27T21:20:39.096957728Z","hostname":"bmat-EVT22200007-00006f6c","pid":1244,"":"downstairs","":"downstairs","session_id":"53eaf899-ba90-4cf0-acc8-8e70a273d3da"}
2002025-05-27T21:20:39.950Z{"msg":"No downstairs reconciliation required","v":0,"name":"crucible","level":30,"time":"2025-05-27T21:20:39.096974451Z","hostname":"bmat-EVT22200007-00006f6c","pid":1244,"session_id":"53eaf899-ba90-4cf0-acc8-8e70a273d3da"}
2012025-05-27T21:20:39.950Z{"msg":"Transition from WaitQuorum to Active","v":0,"name":"crucible","level":30,"time":"2025-05-27T21:20:39.09698878Z","hostname":"bmat-EVT22200007-00006f6c","pid":1244,"client":"0","":"downstairs","session_id":"53eaf899-ba90-4cf0-acc8-8e70a273d3da"}
2022025-05-27T21:20:39.950Z{"msg":"Transition from WaitQuorum to Active","v":0,"name":"crucible","level":30,"time":"2025-05-27T21:20:39.097034341Z","hostname":"bmat-EVT22200007-00006f6c","pid":1244,"client":"1","":"downstairs","session_id":"53eaf899-ba90-4cf0-acc8-8e70a273d3da"}
2032025-05-27T21:20:39.950Z{"msg":"Transition from WaitQuorum to Active","v":0,"name":"crucible","level":30,"time":"2025-05-27T21:20:39.097050383Z","hostname":"bmat-EVT22200007-00006f6c","pid":1244,"client":"2","":"downstairs","session_id":"53eaf899-ba90-4cf0-acc8-8e70a273d3da"}
2042025-05-27T21:20:39.950Z{"msg":"All required reconciliation work is completed","v":0,"name":"crucible","level":30,"time":"2025-05-27T21:20:39.097081855Z","hostname":"bmat-EVT22200007-00006f6c","pid":1244,"session_id":"53eaf899-ba90-4cf0-acc8-8e70a273d3da"}
2052025-05-27T21:20:39.950Z{"msg":"Set Downstairs and Upstairs active after reconciliation","v":0,"name":"crucible","level":30,"time":"2025-05-27T21:20:39.097097697Z","hostname":"bmat-EVT22200007-00006f6c","pid":1244,"session_id":"53eaf899-ba90-4cf0-acc8-8e70a273d3da"}
2062025-05-27T21:20:39.950Z{"msg":"4fe115b2-d77c-4848-8c6e-0f45a40c9acf is now active with session: 53eaf899-ba90-4cf0-acc8-8e70a273d3da","v":0,"name":"crucible","level":30,"time":"2025-05-27T21:20:39.097113348Z","hostname":"bmat-EVT22200007-00006f6c","pid":1244,"session_id":"53eaf899-ba90-4cf0-acc8-8e70a273d3da"}
2072025-05-27T21:20:39.950Z{"msg":"Set Active after no reconciliation","v":0,"name":"crucible","level":30,"time":"2025-05-27T21:20:39.097141694Z","hostname":"bmat-EVT22200007-00006f6c","pid":1244,"session_id":"53eaf899-ba90-4cf0-acc8-8e70a273d3da"}
2082025-05-27T21:20:39.951Z{"msg":"The guest has finished waiting for activation with:31","v":0,"name":"crucible","level":30,"time":"2025-05-27T21:20:39.097157035Z","hostname":"bmat-EVT22200007-00006f6c","pid":1244}
2092025-05-27T21:20:39.951Z{"msg":"Activated sub_volume 4fe115b2-d77c-4848-8c6e-0f45a40c9acf","v":0,"name":"crucible","level":30,"time":"2025-05-27T21:20:39.097170993Z","hostname":"bmat-EVT22200007-00006f6c","pid":1244}
2102025-05-27T21:20:39.951Z{"msg":"The guest has requested activation with gen:31","v":0,"name":"crucible","level":30,"time":"2025-05-27T21:20:39.097198387Z","hostname":"bmat-EVT22200007-00006f6c","pid":1244}
2112025-05-27T21:20:39.951Z{"msg":"4fe115b2-d77c-4848-8c6e-0f45a40c9acf active request set","v":0,"name":"crucible","level":30,"time":"2025-05-27T21:20:39.097463896Z","hostname":"bmat-EVT22200007-00006f6c","pid":1244,"session_id":"82d4e992-ed62-4418-8c2c-4ba79eedb568"}
2122025-05-27T21:20:39.951Z{"msg":"sending connect oneshot to client","v":0,"name":"crucible","level":30,"time":"2025-05-27T21:20:39.097680096Z","hostname":"bmat-EVT22200007-00006f6c","pid":1244,"client":"0","":"downstairs","session_id":"82d4e992-ed62-4418-8c2c-4ba79eedb568"}
2132025-05-27T21:20:39.951Z{"msg":"client set_active_request while in Connecting { state: Start { auto_promote: true }, mode: New }; waiting...","v":0,"name":"crucible","level":30,"time":"2025-05-27T21:20:39.097706629Z","hostname":"bmat-EVT22200007-00006f6c","pid":1244,"client":"0","":"downstairs","session_id":"82d4e992-ed62-4418-8c2c-4ba79eedb568"}
2142025-05-27T21:20:39.951Z{"msg":"sending connect oneshot to client","v":0,"name":"crucible","level":30,"time":"2025-05-27T21:20:39.097884423Z","hostname":"bmat-EVT22200007-00006f6c","pid":1244,"client":"1","":"downstairs","session_id":"82d4e992-ed62-4418-8c2c-4ba79eedb568"}
2152025-05-27T21:20:39.951Z{"msg":"client set_active_request while in Connecting { state: Start { auto_promote: true }, mode: New }; waiting...","v":0,"name":"crucible","level":30,"time":"2025-05-27T21:20:39.097970835Z","hostname":"bmat-EVT22200007-00006f6c","pid":1244,"client":"1","":"downstairs","session_id":"82d4e992-ed62-4418-8c2c-4ba79eedb568"}
2162025-05-27T21:20:39.951Z{"msg":"sending connect oneshot to client","v":0,"name":"crucible","level":30,"time":"2025-05-27T21:20:39.097991997Z","hostname":"bmat-EVT22200007-00006f6c","pid":1244,"client":"2","":"downstairs","session_id":"82d4e992-ed62-4418-8c2c-4ba79eedb568"}
2172025-05-27T21:20:39.951Z{"msg":"client set_active_request while in Connecting { state: Start { auto_promote: true }, mode: New }; waiting...","v":0,"name":"crucible","level":30,"time":"2025-05-27T21:20:39.098012237Z","hostname":"bmat-EVT22200007-00006f6c","pid":1244,"client":"2","":"downstairs","session_id":"82d4e992-ed62-4418-8c2c-4ba79eedb568"}
2182025-05-27T21:20:39.951Z{"msg":"connecting to 127.0.0.1:8860","v":0,"name":"crucible","level":30,"time":"2025-05-27T21:20:39.098031446Z","hostname":"bmat-EVT22200007-00006f6c","pid":1244,"":"io task","client":"2","":"downstairs","session_id":"82d4e992-ed62-4418-8c2c-4ba79eedb568"}
2192025-05-27T21:20:39.951Z{"msg":"connecting to 127.0.0.1:8850","v":0,"name":"crucible","level":30,"time":"2025-05-27T21:20:39.098065303Z","hostname":"bmat-EVT22200007-00006f6c","pid":1244,"":"io task","client":"1","":"downstairs","session_id":"82d4e992-ed62-4418-8c2c-4ba79eedb568"}
2202025-05-27T21:20:39.951Z{"msg":"connecting to 127.0.0.1:8840","v":0,"name":"crucible","level":30,"time":"2025-05-27T21:20:39.098084561Z","hostname":"bmat-EVT22200007-00006f6c","pid":1244,"":"io task","client":"0","":"downstairs","session_id":"82d4e992-ed62-4418-8c2c-4ba79eedb568"}
2212025-05-27T21:20:39.951Z{"msg":"ds_connection connected from Ok(127.0.0.1:42074)","v":0,"name":"crucible","level":30,"time":"2025-05-27T21:20:39.098117587Z","hostname":"bmat-EVT22200007-00006f6c","pid":1244,"":"io task","client":"2","":"downstairs","session_id":"82d4e992-ed62-4418-8c2c-4ba79eedb568"}
2222025-05-27T21:20:39.951Z{"msg":"ds_connection connected from Ok(127.0.0.1:55331)","v":0,"name":"crucible","level":30,"time":"2025-05-27T21:20:39.098137877Z","hostname":"bmat-EVT22200007-00006f6c","pid":1244,"":"io task","client":"1","":"downstairs","session_id":"82d4e992-ed62-4418-8c2c-4ba79eedb568"}
2232025-05-27T21:20:39.951Z{"msg":"ds_connection connected from Ok(127.0.0.1:46413)","v":0,"name":"crucible","level":30,"time":"2025-05-27T21:20:39.098171865Z","hostname":"bmat-EVT22200007-00006f6c","pid":1244,"":"io task","client":"0","":"downstairs","session_id":"82d4e992-ed62-4418-8c2c-4ba79eedb568"}
2242025-05-27T21:20:39.951Z{"msg":"version negotiation from state Connecting { state: WaitForPromote, mode: New }","v":0,"name":"crucible","level":30,"time":"2025-05-27T21:20:39.098193588Z","hostname":"bmat-EVT22200007-00006f6c","pid":1244,"client":"1","":"downstairs","session_id":"82d4e992-ed62-4418-8c2c-4ba79eedb568"}
2252025-05-27T21:20:39.951Z{"msg":"version negotiation from state Connecting { state: WaitForPromote, mode: New }","v":0,"name":"crucible","level":30,"time":"2025-05-27T21:20:39.098372655Z","hostname":"bmat-EVT22200007-00006f6c","pid":1244,"client":"2","":"downstairs","session_id":"82d4e992-ed62-4418-8c2c-4ba79eedb568"}
2262025-05-27T21:20:39.951Z{"msg":"version negotiation from state Connecting { state: WaitForPromote, mode: New }","v":0,"name":"crucible","level":30,"time":"2025-05-27T21:20:39.098483936Z","hostname":"bmat-EVT22200007-00006f6c","pid":1244,"client":"0","":"downstairs","session_id":"82d4e992-ed62-4418-8c2c-4ba79eedb568"}
2272025-05-27T21:20:39.952Z{"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-05-27T21:20:39.098997198Z","hostname":"bmat-EVT22200007-00006f6c","pid":1244,"client":"1","":"downstairs","session_id":"82d4e992-ed62-4418-8c2c-4ba79eedb568"}
2282025-05-27T21:20:39.952Z{"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-05-27T21:20:39.099558666Z","hostname":"bmat-EVT22200007-00006f6c","pid":1244,"client":"0","":"downstairs","session_id":"82d4e992-ed62-4418-8c2c-4ba79eedb568"}
2292025-05-27T21:20:39.952Z{"msg":"Waiting for more clients to be ready","v":0,"name":"crucible","level":30,"time":"2025-05-27T21:20:39.099657763Z","hostname":"bmat-EVT22200007-00006f6c","pid":1244,"session_id":"82d4e992-ed62-4418-8c2c-4ba79eedb568"}
2302025-05-27T21:20:39.952Z{"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-05-27T21:20:39.099677232Z","hostname":"bmat-EVT22200007-00006f6c","pid":1244,"client":"2","":"downstairs","session_id":"82d4e992-ed62-4418-8c2c-4ba79eedb568"}
2312025-05-27T21:20:39.952Z{"msg":"Waiting for more clients to be ready","v":0,"name":"crucible","level":30,"time":"2025-05-27T21:20:39.099856829Z","hostname":"bmat-EVT22200007-00006f6c","pid":1244,"session_id":"82d4e992-ed62-4418-8c2c-4ba79eedb568"}
2322025-05-27T21:20:39.952Z{"msg":"[0]R flush_numbers: [5318, 5320, 5317, 5316, 5307]","v":0,"name":"crucible","level":30,"time":"2025-05-27T21:20:39.100132799Z","hostname":"bmat-EVT22200007-00006f6c","pid":1244,"":"downstairs","":"downstairs","session_id":"82d4e992-ed62-4418-8c2c-4ba79eedb568"}
2332025-05-27T21:20:39.952Z{"msg":"[0]R generation: [14, 14, 13, 13, 10]","v":0,"name":"crucible","level":30,"time":"2025-05-27T21:20:39.100171846Z","hostname":"bmat-EVT22200007-00006f6c","pid":1244,"":"downstairs","":"downstairs","session_id":"82d4e992-ed62-4418-8c2c-4ba79eedb568"}
2342025-05-27T21:20:39.952Z{"msg":"[0]R dirty: [false, false, false, false, false]","v":0,"name":"crucible","level":30,"time":"2025-05-27T21:20:39.100205674Z","hostname":"bmat-EVT22200007-00006f6c","pid":1244,"":"downstairs","":"downstairs","session_id":"82d4e992-ed62-4418-8c2c-4ba79eedb568"}
2352025-05-27T21:20:39.952Z{"msg":"[1]R flush_numbers: [5318, 5320, 5317, 5316, 5307]","v":0,"name":"crucible","level":30,"time":"2025-05-27T21:20:39.100239661Z","hostname":"bmat-EVT22200007-00006f6c","pid":1244,"":"downstairs","":"downstairs","session_id":"82d4e992-ed62-4418-8c2c-4ba79eedb568"}
2362025-05-27T21:20:39.952Z{"msg":"[1]R generation: [14, 14, 13, 13, 10]","v":0,"name":"crucible","level":30,"time":"2025-05-27T21:20:39.100258379Z","hostname":"bmat-EVT22200007-00006f6c","pid":1244,"":"downstairs","":"downstairs","session_id":"82d4e992-ed62-4418-8c2c-4ba79eedb568"}
2372025-05-27T21:20:39.952Z{"msg":"[1]R dirty: [false, false, false, false, false]","v":0,"name":"crucible","level":30,"time":"2025-05-27T21:20:39.100289881Z","hostname":"bmat-EVT22200007-00006f6c","pid":1244,"":"downstairs","":"downstairs","session_id":"82d4e992-ed62-4418-8c2c-4ba79eedb568"}
2382025-05-27T21:20:39.952Z{"msg":"[2]R flush_numbers: [5318, 5320, 5317, 5316, 5307]","v":0,"name":"crucible","level":30,"time":"2025-05-27T21:20:39.100308398Z","hostname":"bmat-EVT22200007-00006f6c","pid":1244,"":"downstairs","":"downstairs","session_id":"82d4e992-ed62-4418-8c2c-4ba79eedb568"}
2392025-05-27T21:20:39.952Z{"msg":"[2]R generation: [14, 14, 13, 13, 10]","v":0,"name":"crucible","level":30,"time":"2025-05-27T21:20:39.10033936Z","hostname":"bmat-EVT22200007-00006f6c","pid":1244,"":"downstairs","":"downstairs","session_id":"82d4e992-ed62-4418-8c2c-4ba79eedb568"}
2402025-05-27T21:20:39.952Z{"msg":"[2]R dirty: [false, false, false, false, false]","v":0,"name":"crucible","level":30,"time":"2025-05-27T21:20:39.100357676Z","hostname":"bmat-EVT22200007-00006f6c","pid":1244,"":"downstairs","":"downstairs","session_id":"82d4e992-ed62-4418-8c2c-4ba79eedb568"}
2412025-05-27T21:20:39.952Z{"msg":"Max found gen is 15","v":0,"name":"crucible","level":30,"time":"2025-05-27T21:20:39.100374811Z","hostname":"bmat-EVT22200007-00006f6c","pid":1244,"":"downstairs","":"downstairs","session_id":"82d4e992-ed62-4418-8c2c-4ba79eedb568"}
2422025-05-27T21:20:39.952Z{"msg":"Generation requested: 31 >= found:15","v":0,"name":"crucible","level":30,"time":"2025-05-27T21:20:39.100392856Z","hostname":"bmat-EVT22200007-00006f6c","pid":1244,"":"downstairs","":"downstairs","session_id":"82d4e992-ed62-4418-8c2c-4ba79eedb568"}
2432025-05-27T21:20:39.952Z{"msg":"Next flush: 5321","v":0,"name":"crucible","level":30,"time":"2025-05-27T21:20:39.100409329Z","hostname":"bmat-EVT22200007-00006f6c","pid":1244,"":"downstairs","":"downstairs","session_id":"82d4e992-ed62-4418-8c2c-4ba79eedb568"}
2442025-05-27T21:20:39.952Z{"msg":"All extents match","v":0,"name":"crucible","level":30,"time":"2025-05-27T21:20:39.100426263Z","hostname":"bmat-EVT22200007-00006f6c","pid":1244,"":"downstairs","":"downstairs","session_id":"82d4e992-ed62-4418-8c2c-4ba79eedb568"}
2452025-05-27T21:20:39.978Z{"msg":"No downstairs reconciliation required","v":0,"name":"crucible","level":30,"time":"2025-05-27T21:20:39.100446062Z","hostname":"bmat-EVT22200007-00006f6c","pid":1244,"session_id":"82d4e992-ed62-4418-8c2c-4ba79eedb568"}
2462025-05-27T21:20:39.979Z{"msg":"Transition from WaitQuorum to Active","v":0,"name":"crucible","level":30,"time":"2025-05-27T21:20:39.100461944Z","hostname":"bmat-EVT22200007-00006f6c","pid":1244,"client":"0","":"downstairs","session_id":"82d4e992-ed62-4418-8c2c-4ba79eedb568"}
2472025-05-27T21:20:39.979Z{"msg":"Transition from WaitQuorum to Active","v":0,"name":"crucible","level":30,"time":"2025-05-27T21:20:39.100493407Z","hostname":"bmat-EVT22200007-00006f6c","pid":1244,"client":"1","":"downstairs","session_id":"82d4e992-ed62-4418-8c2c-4ba79eedb568"}
2482025-05-27T21:20:39.979Z{"msg":"Transition from WaitQuorum to Active","v":0,"name":"crucible","level":30,"time":"2025-05-27T21:20:39.100511262Z","hostname":"bmat-EVT22200007-00006f6c","pid":1244,"client":"2","":"downstairs","session_id":"82d4e992-ed62-4418-8c2c-4ba79eedb568"}
2492025-05-27T21:20:39.979Z{"msg":"All required reconciliation work is completed","v":0,"name":"crucible","level":30,"time":"2025-05-27T21:20:39.100542494Z","hostname":"bmat-EVT22200007-00006f6c","pid":1244,"session_id":"82d4e992-ed62-4418-8c2c-4ba79eedb568"}
2502025-05-27T21:20:39.979Z{"msg":"Set Downstairs and Upstairs active after reconciliation","v":0,"name":"crucible","level":30Wait for a query_work_queue command to finish before sending IO
2512025-05-27T21:20:39.979Z,"time":"2025-05-27T21:20:39.100559338Z","hostname":"bmat-EVT22200007-00006f6c","pid":1244,"session_id":"82d4e992-ed62-4418-8c2c-4ba79eedb568"}
2522025-05-27T21:20:39.979Z{"msg":"4fe115b2-d77c-4848-8c6e-0f45a40c9acf is now active with session: 82d4e992-ed62-4418-8c2c-4ba79eedb568","v":0,"name":"crucible","level":30,"time":"2025-05-27T21:20:39.100611973Z","hostname":"bmat-EVT22200007-00006f6c","pid":1244,"session_id":"82d4e992-ed62-4418-8c2c-4ba79eedb568"}
2532025-05-27T21:20:39.979Z{"msg":"Set Active after no reconciliation","v":0,"name":"crucible","level":30,"time":"2025-05-27T21:20:39.100643726Z","hostname":"bmat-EVT22200007-00006f6c","pid":1244,"session_id":"82d4e992-ed62-4418-8c2c-4ba79eedb568"}
2542025-05-27T21:20:39.979Z{"msg":"The guest has finished waiting for activation with:31","v":0,"name":"crucible","level":30,"time":"2025-05-27T21:20:39.100660519Z","hostname":"bmat-EVT22200007-00006f6c","pid":1244}
2552025-05-27T21:20:39.979Z{"msg":"Activated sub_volume 4fe115b2-d77c-4848-8c6e-0f45a40c9acf","v":0,"name":"crucible","level":30,"time":"2025-05-27T21:20:39.100676Z","hostname":"bmat-EVT22200007-00006f6c","pid":1244}
2562025-05-27T21:20:39.979ZDisk: sv:2 bs:4096 ts:409600 tb:100 max_io:100 or 409600
2572025-05-27T21:20:39.979ZFill test
2582025-05-27T21:20:39.979ZRead and Verify all blocks (0..100 range:false)
2592025-05-27T21:20:40.039ZWrote out file "/var/tmp/test_up-build/verify_file"
2602025-05-27T21:20:40.040ZCLIENT: Tests done. All submitted work has been ACK'd
2612025-05-27T21:20:40.040Z----------------------------------------------------------------
2622025-05-27T21:20:40.040Z Crucible gen:31 GIO:true work queues: Upstairs:0 downstairs:1
2632025-05-27T21:20:40.040ZStates: Active Active Active
2642025-05-27T21:20:40.040ZJOBID ACK TYPE BKS/EXT DS:0 DS:1 DS:2 REPLAY
2652025-05-27T21:20:40.040Z 1002 Acked Read 50 Done Done Done false
2662025-05-27T21:20:40.040Z STATES DS:0 DS:1 DS:2 TOTAL
2672025-05-27T21:20:40.040Z Sent 0 0 0 0
2682025-05-27T21:20:40.040Z Done 1 1 1 3
2692025-05-27T21:20:40.040Z Skipped 0 0 0 0
2702025-05-27T21:20:40.040Z Error 0 0 0 0
2712025-05-27T21:20:40.066ZLast Flush: Some(JobId(1001)) Some(JobId(1001)) Some(JobId(1001))
2722025-05-27T21:20:40.066ZDownstairs last five completed: 1001 1000
2732025-05-27T21:20:40.066ZUpstairs last five completed: 1002 1001 1000
2742025-05-27T21:20:40.066Z----------------------------------------------------------------
2752025-05-27T21:20:40.066Z Crucible gen:31 GIO:true work queues: Upstairs:0 downstairs:1
2762025-05-27T21:20:40.066ZStates: Active Active Active
2772025-05-27T21:20:40.066ZJOBID ACK TYPE BKS/EXT DS:0 DS:1 DS:2 REPLAY
2782025-05-27T21:20:40.066Z 1002 Acked Read 50 Done Done Done false
2792025-05-27T21:20:40.066Z STATES DS:0 DS:1 DS:2 TOTAL
2802025-05-27T21:20:40.066Z Sent 0 0 0 0
2812025-05-27T21:20:40.067Z Done 1 1 1 3
2822025-05-27T21:20:40.067Z Skipped 0 0 0 0
2832025-05-27T21:20:40.067Z Error 0 0 0 0
2842025-05-27T21:20:40.067ZLast Flush: Some(JobId(1001)) Some(JobId(1001)) Some(JobId(1001))
2852025-05-27T21:20:40.067ZDownstairs last five completed: 1001 1000
2862025-05-27T21:20:40.067ZUpstairs last five completed: 1002 1001 1000
2872025-05-27T21:20:40.067ZCLIENT: Up:0 ds:2 act:6
2882025-05-27T21:20:44.041Z----------------------------------------------------------------
2892025-05-27T21:20:44.041Z Crucible gen:31 GIO:true work queues: Upstairs:0 downstairs:0
2902025-05-27T21:20:44.041ZDownstairs last five completed: 1003 1002 1001 1000
2912025-05-27T21:20:44.041ZUpstairs last five completed: 1003 1002 1001 1000
2922025-05-27T21:20:44.067Z----------------------------------------------------------------
2932025-05-27T21:20:44.067Z Crucible gen:31 GIO:true work queues: Upstairs:0 downstairs:0
2942025-05-27T21:20:44.067ZDownstairs last five completed: 1003 1002 1001 1000
2952025-05-27T21:20:44.067ZUpstairs last five completed: 1003 1002 1001 1000
2962025-05-27T21:20:44.067ZCLIENT: Up:0 ds:0 act:6
2972025-05-27T21:20:44.067ZCLIENT: All crucible jobs finished, exiting program
2982025-05-27T21:20:44.067Z{"msg":"Guest handle has been dropped","v":0,"name":"crucible","level":40,"time":"2025-05-27T21:20:43.245803788Z","hostname":"bmat-EVT22200007-00006f6c","pid":1244}
2992025-05-27T21:20:44.067ZRepair setup passed
3002025-05-27T21:20:44.067ZCopy the region for /var/tmp/test_up-build/8830
3012025-05-27T21:20:44.067Zcp -r /var/tmp/test_up-build/8830 /var/tmp/test_up-build/previous
3022025-05-27T21:20:44.067Z/var/tmp/bins/crutest fill -g 32 -q --key CnZvPnPOKbrPY355yyOGXSwV1w0yrZFYdM2pVQH9kSE= --dsc 127.0.0.1:9998 --verify-out /var/tmp/test_up-build/verify_file --verify-in /var/tmp/test_up-build/verify_file
3032025-05-27T21:20:44.136Z{"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-05-27T21:20:43.33948529Z","hostname":"bmat-EVT22200007-00006f6c","pid":1250,"task":"crutest"}
3042025-05-27T21:20:44.207Z{"msg":"dsc has 6 regions. This means 2 sub_volumes","v":0,"name":"crucible","level":30,"time":"2025-05-27T21:20:43.340420822Z","hostname":"bmat-EVT22200007-00006f6c","pid":1250,"task":"crutest"}
3052025-05-27T21:20:44.207Z{"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-05-27T21:20:43.343049084Z","hostname":"bmat-EVT22200007-00006f6c","pid":1250,"task":"crutest"}
3062025-05-27T21:20:44.207Z{"msg":"Upstairs starts","v":0,"name":"crucible","level":30,"time":"2025-05-27T21:20:43.343298661Z","hostname":"bmat-EVT22200007-00006f6c","pid":1250}
3072025-05-27T21:20:44.207Z{"msg":"Crucible Version: BuildInfo {\n version: \"0.0.1\",\n git_sha: \"dd892d47062b1dcb23800b8bbb5d2946e1dd1cb7\",\n git_commit_timestamp: \"2025-05-27T20:18:55.000000000Z\",\n git_branch: \"alan/agent-needs-workers\",\n rustc_semver: \"1.86.0\",\n rustc_channel: \"stable\",\n rustc_host_triple: \"x86_64-unknown-illumos\",\n rustc_commit_sha: \"05f9846f893b09a1be1fc8560e33fc3c815cfecb\",\n cargo_triple: \"x86_64-unknown-illumos\",\n debug: true,\n opt_level: 0,\n}","v":0,"name":"crucible","level":30,"time":"2025-05-27T21:20:43.343370023Z","hostname":"bmat-EVT22200007-00006f6c","pid":1250}
3082025-05-27T21:20:44.207Z{"msg":"Upstairs <-> Downstairs Message Version: 13","v":0,"name":"crucible","level":30,"time":"2025-05-27T21:20:43.343414301Z","hostname":"bmat-EVT22200007-00006f6c","pid":1250}
3092025-05-27T21:20:44.207Z{"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-05-27T21:20:43.343541354Z","hostname":"bmat-EVT22200007-00006f6c","pid":1250}
3102025-05-27T21:20:44.207Z{"msg":"Crucible c07ca1c4-6e9e-4bae-92c9-f557c29b4de7 has session id: 735a0b3d-ce76-4dbb-b112-9dc4b660f790","v":0,"name":"crucible","level":30,"time":"2025-05-27T21:20:43.344730261Z","hostname":"bmat-EVT22200007-00006f6c","pid":1250,"session_id":"735a0b3d-ce76-4dbb-b112-9dc4b660f790"}
3112025-05-27T21:20:44.207Z{"msg":"Upstairs opts: Upstairs UUID: c07ca1c4-6e9e-4bae-92c9-f557c29b4de7, 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-05-27T21:20:43.344805501Z","hostname":"bmat-EVT22200007-00006f6c","pid":1250,"session_id":"735a0b3d-ce76-4dbb-b112-9dc4b660f790"}
3122025-05-27T21:20:44.207Z{"msg":"Crucible stats registered with UUID: c07ca1c4-6e9e-4bae-92c9-f557c29b4de7","v":0,"name":"crucible","level":30,"time":"2025-05-27T21:20:43.344829859Z","hostname":"bmat-EVT22200007-00006f6c","pid":1250,"session_id":"735a0b3d-ce76-4dbb-b112-9dc4b660f790"}
3132025-05-27T21:20:44.207Z{"msg":"could not find Downstairs address for Nexus","v":0,"name":"crucible","level":40,"time":"2025-05-27T21:20:43.344848476Z","hostname":"bmat-EVT22200007-00006f6c","pid":1250,"session_id":"735a0b3d-ce76-4dbb-b112-9dc4b660f790"}
3142025-05-27T21:20:44.207Z{"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-05-27T21:20:43.34797489Z","hostname":"bmat-EVT22200007-00006f6c","pid":1250,"task":"crutest"}
3152025-05-27T21:20:44.207Z{"msg":"Upstairs starts","v":0,"name":"crucible","level":30,"time":"2025-05-27T21:20:43.348263294Z","hostname":"bmat-EVT22200007-00006f6c","pid":1250}
3162025-05-27T21:20:44.207Z{"msg":"Crucible Version: BuildInfo {\n version: \"0.0.1\",\n git_sha: \"dd892d47062b1dcb23800b8bbb5d2946e1dd1cb7\",\n git_commit_timestamp: \"2025-05-27T20:18:55.000000000Z\",\n git_branch: \"alan/agent-needs-workers\",\n rustc_semver: \"1.86.0\",\n rustc_channel: \"stable\",\n rustc_host_triple: \"x86_64-unknown-illumos\",\n rustc_commit_sha: \"05f9846f893b09a1be1fc8560e33fc3c815cfecb\",\n cargo_triple: \"x86_64-unknown-illumos\",\n debug: true,\n opt_level: 0,\n}","v":0,"name":"crucible","level":30,"time":"2025-05-27T21:20:43.34842178Z","hostname":"bmat-EVT22200007-00006f6c","pid":1250}
3172025-05-27T21:20:44.207Z{"msg":"Upstairs <-> Downstairs Message Version: 13","v":0,"name":"crucible","level":30,"time":"2025-05-27T21:20:43.348493242Z","hostname":"bmat-EVT22200007-00006f6c","pid":1250}
3182025-05-27T21:20:44.208Z{"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-05-27T21:20:43.348533172Z","hostname":"bmat-EVT22200007-00006f6c","pid":1250}
3192025-05-27T21:20:44.208Z{"msg":"Crucible c07ca1c4-6e9e-4bae-92c9-f557c29b4de7 has session id: 77d7e9cd-9e62-45ef-9e34-872de061dba4","v":0,"name":"crucible","level":30,"time":"2025-05-27T21:20:43.349097495Z","hostname":"bmat-EVT22200007-00006f6c","pid":1250,"session_id":"77d7e9cd-9e62-45ef-9e34-872de061dba4"}
3202025-05-27T21:20:44.208Z{"msg":"Upstairs opts: Upstairs UUID: c07ca1c4-6e9e-4bae-92c9-f557c29b4de7, 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-05-27T21:20:43.349159278Z","hostname":"bmat-EVT22200007-00006f6c","pid":1250,"session_id":"77d7e9cd-9e62-45ef-9e34-872de061dba4"}
3212025-05-27T21:20:44.208Z{"msg":"Crucible stats registered with UUID: c07ca1c4-6e9e-4bae-92c9-f557c29b4de7","v":0,"name":"crucible","level":30,"time":"2025-05-27T21:20:43.349192805Z","hostname":"bmat-EVT22200007-00006f6c","pid":1250,"session_id":"77d7e9cd-9e62-45ef-9e34-872de061dba4"}
3222025-05-27T21:20:44.208Z{"msg":"could not find Downstairs address for Nexus","v":0,"name":"crucible","level":40,"time":"2025-05-27T21:20:43.34927583Z","hostname":"bmat-EVT22200007-00006f6c","pid":1250,"session_id":"77d7e9cd-9e62-45ef-9e34-872de061dba4"}
3232025-05-27T21:20:44.208Z{"msg":"Downstairs in volume = 6","v":0,"name":"crucible","level":30,"time":"2025-05-27T21:20:43.350251192Z","hostname":"bmat-EVT22200007-00006f6c","pid":1250,"task":"crutest"}
3242025-05-27T21:20:44.208Z{"msg":"The guest has requested activation with gen:32","v":0,"name":"crucible","level":30,"time":"2025-05-27T21:20:43.350292073Z","hostname":"bmat-EVT22200007-00006f6c","pid":1250}
3252025-05-27T21:20:44.208Z{"msg":"c07ca1c4-6e9e-4bae-92c9-f557c29b4de7 active request set","v":0,"name":"crucible","level":30,"time":"2025-05-27T21:20:43.350381441Z","hostname":"bmat-EVT22200007-00006f6c","pid":1250,"session_id":"735a0b3d-ce76-4dbb-b112-9dc4b660f790"}
3262025-05-27T21:20:44.208Z{"msg":"sending connect oneshot to client","v":0,"name":"crucible","level":30,"time":"2025-05-27T21:20:43.350419086Z","hostname":"bmat-EVT22200007-00006f6c","pid":1250,"client":"0","":"downstairs","session_id":"735a0b3d-ce76-4dbb-b112-9dc4b660f790"}
3272025-05-27T21:20:44.208Z{"msg":"client set_active_request while in Connecting { state: Start { auto_promote: true }, mode: New }; waiting...","v":0,"name":"crucible","level":30,"time":"2025-05-27T21:20:43.350461089Z","hostname":"bmat-EVT22200007-00006f6c","pid":1250,"client":"0","":"downstairs","session_id":"735a0b3d-ce76-4dbb-b112-9dc4b660f790"}
3282025-05-27T21:20:44.208Z{"msg":"sending connect oneshot to client","v":0,"name":"crucible","level":30,"time":"2025-05-27T21:20:43.350480308Z","hostname":"bmat-EVT22200007-00006f6c","pid":1250,"client":"1","":"downstairs","session_id":"735a0b3d-ce76-4dbb-b112-9dc4b660f790"}
3292025-05-27T21:20:44.208Z{"msg":"client set_active_request while in Connecting { state: Start { auto_promote: true }, mode: New }; waiting...","v":0,"name":"crucible","level":30,"time":"2025-05-27T21:20:43.350498965Z","hostname":"bmat-EVT22200007-00006f6c","pid":1250,"client":"1","":"downstairs","session_id":"735a0b3d-ce76-4dbb-b112-9dc4b660f790"}
3302025-05-27T21:20:44.208Z{"msg":"sending connect oneshot to client","v":0,"name":"crucible","level":30,"time":"2025-05-27T21:20:43.35053191Z","hostname":"bmat-EVT22200007-00006f6c","pid":1250,"client":"2","":"downstairs","session_id":"735a0b3d-ce76-4dbb-b112-9dc4b660f790"}
3312025-05-27T21:20:44.208Z{"msg":"client set_active_request while in Connecting { state: Start { auto_promote: true }, mode: New }; waiting...","v":0,"name":"crucible","level":30,"time":"2025-05-27T21:20:43.350551048Z","hostname":"bmat-EVT22200007-00006f6c","pid":1250,"client":"2","":"downstairs","session_id":"735a0b3d-ce76-4dbb-b112-9dc4b660f790"}
3322025-05-27T21:20:44.208Z{"msg":"connecting to 127.0.0.1:8830","v":0,"name":"crucible","level":30,"time":"2025-05-27T21:20:43.350568694Z","hostname":"bmat-EVT22200007-00006f6c","pid":1250,"":"io task","client":"2","":"downstairs","session_id":"735a0b3d-ce76-4dbb-b112-9dc4b660f790"}
3332025-05-27T21:20:44.208Z{"msg":"connecting to 127.0.0.1:8810","v":0,"name":"crucible","level":30,"time":"2025-05-27T21:20:43.350588353Z","hostname":"bmat-EVT22200007-00006f6c","pid":1250,"":"io task","client":"0","":"downstairs","session_id":"735a0b3d-ce76-4dbb-b112-9dc4b660f790"}
3342025-05-27T21:20:44.208Z{"msg":"connecting to 127.0.0.1:8820","v":0,"name":"crucible","level":30,"time":"2025-05-27T21:20:43.350607341Z","hostname":"bmat-EVT22200007-00006f6c","pid":1250,"":"io task","client":"1","":"downstairs","session_id":"735a0b3d-ce76-4dbb-b112-9dc4b660f790"}
3352025-05-27T21:20:44.208Z{"msg":"ds_connection connected from Ok(127.0.0.1:45995)","v":0,"name":"crucible","level":30,"time":"2025-05-27T21:20:43.351185762Z","hostname":"bmat-EVT22200007-00006f6c","pid":1250,"":"io task","client":"1","":"downstairs","session_id":"735a0b3d-ce76-4dbb-b112-9dc4b660f790"}
3362025-05-27T21:20:44.208Z{"msg":"ds_connection connected from Ok(127.0.0.1:39317)","v":0,"name":"crucible","level":30,"time":"2025-05-27T21:20:43.351235281Z","hostname":"bmat-EVT22200007-00006f6c","pid":1250,"":"io task","client":"0","":"downstairs","session_id":"735a0b3d-ce76-4dbb-b112-9dc4b660f790"}
3372025-05-27T21:20:44.208Z{"msg":"ds_connection connected from Ok(127.0.0.1:37677)","v":0,"name":"crucible","level":30,"time":"2025-05-27T21:20:43.35125523Z","hostname":"bmat-EVT22200007-00006f6c","pid":1250,"":"io task","client":"2","":"downstairs","session_id":"735a0b3d-ce76-4dbb-b112-9dc4b660f790"}
3382025-05-27T21:20:44.209Z{"msg":"version negotiation from state Connecting { state: WaitForPromote, mode: New }","v":0,"name":"crucible","level":30,"time":"2025-05-27T21:20:43.352382484Z","hostname":"bmat-EVT22200007-00006f6c","pid":1250,"client":"0","":"downstairs","session_id":"735a0b3d-ce76-4dbb-b112-9dc4b660f790"}
3392025-05-27T21:20:44.209Z{"msg":"version negotiation from state Connecting { state: WaitForPromote, mode: New }","v":0,"name":"crucible","level":30,"time":"2025-05-27T21:20:43.352539697Z","hostname":"bmat-EVT22200007-00006f6c","pid":1250,"client":"2","":"downstairs","session_id":"735a0b3d-ce76-4dbb-b112-9dc4b660f790"}
3402025-05-27T21:20:44.209Z{"msg":"version negotiation from state Connecting { state: WaitForPromote, mode: New }","v":0,"name":"crucible","level":30,"time":"2025-05-27T21:20:43.352744535Z","hostname":"bmat-EVT22200007-00006f6c","pid":1250,"client":"1","":"downstairs","session_id":"735a0b3d-ce76-4dbb-b112-9dc4b660f790"}
3412025-05-27T21:20:44.209Z{"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-05-27T21:20:43.353409359Z","hostname":"bmat-EVT22200007-00006f6c","pid":1250,"client":"2","":"downstairs","session_id":"735a0b3d-ce76-4dbb-b112-9dc4b660f790"}
3422025-05-27T21:20:44.209Z{"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-05-27T21:20:43.353451753Z","hostname":"bmat-EVT22200007-00006f6c","pid":1250,"client":"1","":"downstairs","session_id":"735a0b3d-ce76-4dbb-b112-9dc4b660f790"}
3432025-05-27T21:20:44.209Z{"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-05-27T21:20:43.35359591Z","hostname":"bmat-EVT22200007-00006f6c","pid":1250,"client":"0","":"downstairs","session_id":"735a0b3d-ce76-4dbb-b112-9dc4b660f790"}
3442025-05-27T21:20:44.209Z{"msg":"Waiting for more clients to be ready","v":0,"name":"crucible","level":30,"time":"2025-05-27T21:20:43.353911348Z","hostname":"bmat-EVT22200007-00006f6c","pid":1250,"session_id":"735a0b3d-ce76-4dbb-b112-9dc4b660f790"}
3452025-05-27T21:20:44.209Z{"msg":"Waiting for more clients to be ready","v":0,"name":"crucible","level":30,"time":"2025-05-27T21:20:43.354014423Z","hostname":"bmat-EVT22200007-00006f6c","pid":1250,"session_id":"735a0b3d-ce76-4dbb-b112-9dc4b660f790"}
3462025-05-27T21:20:44.209Z{"msg":"[0]R flush_numbers: [4000, 4000, 4000, 4000, 4000]","v":0,"name":"crucible","level":30,"time":"2025-05-27T21:20:43.354243168Z","hostname":"bmat-EVT22200007-00006f6c","pid":1250,"":"downstairs","":"downstairs","session_id":"735a0b3d-ce76-4dbb-b112-9dc4b660f790"}
3472025-05-27T21:20:44.209Z{"msg":"[0]R generation: [31, 31, 31, 31, 31]","v":0,"name":"crucible","level":30,"time":"2025-05-27T21:20:43.354280503Z","hostname":"bmat-EVT22200007-00006f6c","pid":1250,"":"downstairs","":"downstairs","session_id":"735a0b3d-ce76-4dbb-b112-9dc4b660f790"}
3482025-05-27T21:20:44.209Z{"msg":"[0]R dirty: [false, false, false, false, false]","v":0,"name":"crucible","level":30,"time":"2025-05-27T21:20:43.354299941Z","hostname":"bmat-EVT22200007-00006f6c","pid":1250,"":"downstairs","":"downstairs","session_id":"735a0b3d-ce76-4dbb-b112-9dc4b660f790"}
3492025-05-27T21:20:44.209Z{"msg":"[1]R flush_numbers: [4000, 4000, 4000, 4000, 4000]","v":0,"name":"crucible","level":30,"time":"2025-05-27T21:20:43.354318709Z","hostname":"bmat-EVT22200007-00006f6c","pid":1250,"":"downstairs","":"downstairs","session_id":"735a0b3d-ce76-4dbb-b112-9dc4b660f790"}
3502025-05-27T21:20:44.209Z{"msg":"[1]R generation: [31, 31, 31, 31, 31]","v":0,"name":"crucible","level":30,"time":"2025-05-27T21:20:43.354349831Z","hostname":"bmat-EVT22200007-00006f6c","pid":1250,"":"downstairs","":"downstairs","session_id":"735a0b3d-ce76-4dbb-b112-9dc4b660f790"}
3512025-05-27T21:20:44.209Z{"msg":"[1]R dirty: [false, false, false, false, false]","v":0,"name":"crucible","level":30,"time":"2025-05-27T21:20:43.354367175Z","hostname":"bmat-EVT22200007-00006f6c","pid":1250,"":"downstairs","":"downstairs","session_id":"735a0b3d-ce76-4dbb-b112-9dc4b660f790"}
3522025-05-27T21:20:44.209Z{"msg":"[2]R flush_numbers: [4000, 4000, 4000, 4000, 4000]","v":0,"name":"crucible","level":30,"time":"2025-05-27T21:20:43.354384931Z","hostname":"bmat-EVT22200007-00006f6c","pid":1250,"":"downstairs","":"downstairs","session_id":"735a0b3d-ce76-4dbb-b112-9dc4b660f790"}
3532025-05-27T21:20:44.209Z{"msg":"[2]R generation: [31, 31, 31, 31, 31]","v":0,"name":"crucible","level":30,"time":"2025-05-27T21:20:43.354415692Z","hostname":"bmat-EVT22200007-00006f6c","pid":1250,"":"downstairs","":"downstairs","session_id":"735a0b3d-ce76-4dbb-b112-9dc4b660f790"}
3542025-05-27T21:20:44.209Z{"msg":"[2]R dirty: [false, false, false, false, false]","v":0,"name":"crucible","level":30,"time":"2025-05-27T21:20:43.354432936Z","hostname":"bmat-EVT22200007-00006f6c","pid":1250,"":"downstairs","":"downstairs","session_id":"735a0b3d-ce76-4dbb-b112-9dc4b660f790"}
3552025-05-27T21:20:44.209Z{"msg":"Max found gen is 32","v":0,"name":"crucible","level":30,"time":"2025-05-27T21:20:43.354449569Z","hostname":"bmat-EVT22200007-00006f6c","pid":1250,"":"downstairs","":"downstairs","session_id":"735a0b3d-ce76-4dbb-b112-9dc4b660f790"}
3562025-05-27T21:20:44.209Z{"msg":"Generation requested: 32 >= found:32","v":0,"name":"crucible","level":30,"time":"2025-05-27T21:20:43.354480641Z","hostname":"bmat-EVT22200007-00006f6c","pid":1250,"":"downstairs","":"downstairs","session_id":"735a0b3d-ce76-4dbb-b112-9dc4b660f790"}
3572025-05-27T21:20:44.209Z{"msg":"Next flush: 4001","v":0,"name":"crucible","level":30,"time":"2025-05-27T21:20:43.354497916Z","hostname":"bmat-EVT22200007-00006f6c","pid":1250,"":"downstairs","":"downstairs","session_id":"735a0b3d-ce76-4dbb-b112-9dc4b660f790"}
3582025-05-27T21:20:44.209Z{"msg":"All extents match","v":0,"name":"crucible","level":30,"time":"2025-05-27T21:20:43.354514779Z","hostname":"bmat-EVT22200007-00006f6c","pid":1250,"":"downstairs","":"downstairs","session_id":"735a0b3d-ce76-4dbb-b112-9dc4b660f790"}
3592025-05-27T21:20:44.209Z{"msg":"No downstairs reconciliation required","v":0,"name":"crucible","level":30,"time":"2025-05-27T21:20:43.354544568Z","hostname":"bmat-EVT22200007-00006f6c","pid":1250,"session_id":"735a0b3d-ce76-4dbb-b112-9dc4b660f790"}
3602025-05-27T21:20:44.209Z{"msg":"Transition from WaitQuorum to Active","v":0,"name":"crucible","level":30,"time":"2025-05-27T21:20:43.354560861Z","hostname":"bmat-EVT22200007-00006f6c","pid":1250,"client":"0","":"downstairs","session_id":"735a0b3d-ce76-4dbb-b112-9dc4b660f790"}
3612025-05-27T21:20:44.209Z{"msg":"Transition from WaitQuorum to Active","v":0,"name":"crucible","level":30,"time":"2025-05-27T21:20:43.354577334Z","hostname":"bmat-EVT22200007-00006f6c","pid":1250,"client":"1","":"downstairs","session_id":"735a0b3d-ce76-4dbb-b112-9dc4b660f790"}
3622025-05-27T21:20:44.209Z{"msg":"Transition from WaitQuorum to Active","v":0,"name":"crucible","level":30,"time":"2025-05-27T21:20:43.354594378Z","hostname":"bmat-EVT22200007-00006f6c","pid":1250,"client":"2","":"downstairs","session_id":"735a0b3d-ce76-4dbb-b112-9dc4b660f790"}
3632025-05-27T21:20:44.209Z{"msg":"All required reconciliation work is completed","v":0,"name":"crucible","level":30,"time":"2025-05-27T21:20:43.354612444Z","hostname":"bmat-EVT22200007-00006f6c","pid":1250,"session_id":"735a0b3d-ce76-4dbb-b112-9dc4b660f790"}
3642025-05-27T21:20:44.209Z{"msg":"Set Downstairs and Upstairs active after reconciliation","v":0,"name":"crucible","level":30,"time":"2025-05-27T21:20:43.354642894Z","hostname":"bmat-EVT22200007-00006f6c","pid":1250,"session_id":"735a0b3d-ce76-4dbb-b112-9dc4b660f790"}
3652025-05-27T21:20:44.210Z{"msg":"c07ca1c4-6e9e-4bae-92c9-f557c29b4de7 is now active with session: 735a0b3d-ce76-4dbb-b112-9dc4b660f790","v":0,"name":"crucible","level":30,"time":"2025-05-27T21:20:43.354660509Z","hostname":"bmat-EVT22200007-00006f6c","pid":1250,"session_id":"735a0b3d-ce76-4dbb-b112-9dc4b660f790"}
3662025-05-27T21:20:44.210Z{"msg":"Set Active after no reconciliation","v":0,"name":"crucible","level":30,"time":"2025-05-27T21:20:43.354675719Z","hostname":"bmat-EVT22200007-00006f6c","pid":1250,"session_id":"735a0b3d-ce76-4dbb-b112-9dc4b660f790"}
3672025-05-27T21:20:44.210Z{"msg":"The guest has finished waiting for activation with:32","v":0,"name":"crucible","level":30,"time":"2025-05-27T21:20:43.354691832Z","hostname":"bmat-EVT22200007-00006f6c","pid":1250}
3682025-05-27T21:20:44.210Z{"msg":"Activated sub_volume c07ca1c4-6e9e-4bae-92c9-f557c29b4de7","v":0,"name":"crucible","level":30,"time":"2025-05-27T21:20:43.354708004Z","hostname":"bmat-EVT22200007-00006f6c","pid":1250}
3692025-05-27T21:20:44.210Z{"msg":"The guest has requested activation with gen:32","v":0,"name":"crucible","level":30,"time":"2025-05-27T21:20:43.354736541Z","hostname":"bmat-EVT22200007-00006f6c","pid":1250}
3702025-05-27T21:20:44.210Z{"msg":"c07ca1c4-6e9e-4bae-92c9-f557c29b4de7 active request set","v":0,"name":"crucible","level":30,"time":"2025-05-27T21:20:43.354916429Z","hostname":"bmat-EVT22200007-00006f6c","pid":1250,"session_id":"77d7e9cd-9e62-45ef-9e34-872de061dba4"}
3712025-05-27T21:20:44.210Z{"msg":"sending connect oneshot to client","v":0,"name":"crucible","level":30,"time":"2025-05-27T21:20:43.354951699Z","hostname":"bmat-EVT22200007-00006f6c","pid":1250,"client":"0","":"downstairs","session_id":"77d7e9cd-9e62-45ef-9e34-872de061dba4"}
3722025-05-27T21:20:44.210Z{"msg":"client set_active_request while in Connecting { state: Start { auto_promote: true }, mode: New }; waiting...","v":0,"name":"crucible","level":30,"time":"2025-05-27T21:20:43.354971448Z","hostname":"bmat-EVT22200007-00006f6c","pid":1250,"client":"0","":"downstairs","session_id":"77d7e9cd-9e62-45ef-9e34-872de061dba4"}
3732025-05-27T21:20:44.210Z{"msg":"sending connect oneshot to client","v":0,"name":"crucible","level":30,"time":"2025-05-27T21:20:43.354988442Z","hostname":"bmat-EVT22200007-00006f6c","pid":1250,"client":"1","":"downstairs","session_id":"77d7e9cd-9e62-45ef-9e34-872de061dba4"}
3742025-05-27T21:20:44.210Z{"msg":"client set_active_request while in Connecting { state: Start { auto_promote: true }, mode: New }; waiting...","v":0,"name":"crucible","level":30,"time":"2025-05-27T21:20:43.355021027Z","hostname":"bmat-EVT22200007-00006f6c","pid":1250,"client":"1","":"downstairs","session_id":"77d7e9cd-9e62-45ef-9e34-872de061dba4"}
3752025-05-27T21:20:44.210Z{"msg":"sending connect oneshot to client","v":0,"name":"crucible","level":30,"time":"2025-05-27T21:20:43.355038502Z","hostname":"bmat-EVT22200007-00006f6c","pid":1250,"client":"2","":"downstairs","session_id":"77d7e9cd-9e62-45ef-9e34-872de061dba4"}
3762025-05-27T21:20:44.210Z{"msg":"client set_active_request while in Connecting { state: Start { auto_promote: true }, mode: New }; waiting...","v":0,"name":"crucible","level":30,"time":"2025-05-27T21:20:43.355058702Z","hostname":"bmat-EVT22200007-00006f6c","pid":1250,"client":"2","":"downstairs","session_id":"77d7e9cd-9e62-45ef-9e34-872de061dba4"}
3772025-05-27T21:20:44.210Z{"msg":"connecting to 127.0.0.1:8840","v":0,"name":"crucible","level":30,"time":"2025-05-27T21:20:43.355076137Z","hostname":"bmat-EVT22200007-00006f6c","pid":1250,"":"io task","client":"0","":"downstairs","session_id":"77d7e9cd-9e62-45ef-9e34-872de061dba4"}
3782025-05-27T21:20:44.210Z{"msg":"connecting to 127.0.0.1:8860","v":0,"name":"crucible","level":30,"time":"2025-05-27T21:20:43.355095074Z","hostname":"bmat-EVT22200007-00006f6c","pid":1250,"":"io task","client":"2","":"downstairs","session_id":"77d7e9cd-9e62-45ef-9e34-872de061dba4"}
3792025-05-27T21:20:44.210Z{"msg":"connecting to 127.0.0.1:8850","v":0,"name":"crucible","level":30,"time":"2025-05-27T21:20:43.355219953Z","hostname":"bmat-EVT22200007-00006f6c","pid":1250,"":"io task","client":"1","":"downstairs","session_id":"77d7e9cd-9e62-45ef-9e34-872de061dba4"}
3802025-05-27T21:20:44.210Z{"msg":"ds_connection connected from Ok(127.0.0.1:55353)","v":0,"name":"crucible","level":30,"time":"2025-05-27T21:20:43.355356625Z","hostname":"bmat-EVT22200007-00006f6c","pid":1250,"":"io task","client":"1","":"downstairs","session_id":"77d7e9cd-9e62-45ef-9e34-872de061dba4"}
3812025-05-27T21:20:44.210Z{"msg":"ds_connection connected from Ok(127.0.0.1:63641)","v":0,"name":"crucible","level":30,"time":"2025-05-27T21:20:43.35537447Z","hostname":"bmat-EVT22200007-00006f6c","pid":1250,"":"io task","client":"0","":"downstairs","session_id":"77d7e9cd-9e62-45ef-9e34-872de061dba4"}
3822025-05-27T21:20:44.210Z{"msg":"ds_connection connected from Ok(127.0.0.1:35681)","v":0,"name":"crucible","level":30,"time":"2025-05-27T21:20:43.355540671Z","hostname":"bmat-EVT22200007-00006f6c","pid":1250,"":"io task","client":"2","":"downstairs","session_id":"77d7e9cd-9e62-45ef-9e34-872de061dba4"}
3832025-05-27T21:20:44.210Z{"msg":"version negotiation from state Connecting { state: WaitForPromote, mode: New }","v":0,"name":"crucible","level":30,"time":"2025-05-27T21:20:43.355574208Z","hostname":"bmat-EVT22200007-00006f6c","pid":1250,"client":"0","":"downstairs","session_id":"77d7e9cd-9e62-45ef-9e34-872de061dba4"}
3842025-05-27T21:20:44.210Z{"msg":"version negotiation from state Connecting { state: WaitForPromote, mode: New }","v":0,"name":"crucible","level":30,"time":"2025-05-27T21:20:43.35605754Z","hostname":"bmat-EVT22200007-00006f6c","pid":1250,"client":"1","":"downstairs","session_id":"77d7e9cd-9e62-45ef-9e34-872de061dba4"}
3852025-05-27T21:20:44.210Z{"msg":"version negotiation from state Connecting { state: WaitForPromote, mode: New }","v":0,"name":"crucible","level":30,"time":"2025-05-27T21:20:43.356126017Z","hostname":"bmat-EVT22200007-00006f6c","pid":1250,"client":"2","":"downstairs","session_id":"77d7e9cd-9e62-45ef-9e34-872de061dba4"}
3862025-05-27T21:20:44.210Z{"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-05-27T21:20:43.356515893Z","hostname":"bmat-EVT22200007-00006f6c","pid":1250,"client":"1","":"downstairs","session_id":"77d7e9cd-9e62-45ef-9e34-872de061dba4"}
3872025-05-27T21:20:44.210Z{"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-05-27T21:20:43.356674899Z","hostname":"bmat-EVT22200007-00006f6c","pid":1250,"client":"2","":"downstairs","session_id":"77d7e9cd-9e62-45ef-9e34-872de061dba4"}
3882025-05-27T21:20:44.210Z{"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-05-27T21:20:43.356833184Z","hostname":"bmat-EVT22200007-00006f6c","pid":1250,"client":"0","":"downstairs","session_id":"77d7e9cd-9e62-45ef-9e34-872de061dba4"}
3892025-05-27T21:20:44.210Z{"msg":"Waiting for more clients to be ready","v":0,"name":"crucible","level":30,"time":"2025-05-27T21:20:43.357030808Z","hostname":"bmat-EVT22200007-00006f6c","pid":1250,"session_id":"77d7e9cd-9e62-45ef-9e34-872de061dba4"}
3902025-05-27T21:20:44.210Z{"msg":"Waiting for more clients to be ready","v":0,"name":"crucible","level":30,"time":"2025-05-27T21:20:43.357070988Z","hostname":"bmat-EVT22200007-00006f6c","pid":1250,"session_id":"77d7e9cd-9e62-45ef-9e34-872de061dba4"}
3912025-05-27T21:20:44.210Z{"msg":"[0]R flush_numbers: [5321, 5321, 5321, 5321, 5321]","v":0,"name":"crucible","level":30,"time":"2025-05-27T21:20:43.357292609Z","hostname":"bmat-EVT22200007-00006f6c","pid":1250,"":"downstairs","":"downstairs","session_id":"77d7e9cd-9e62-45ef-9e34-872de061dba4"}
3922025-05-27T21:20:44.210Z{"msg":"[0]R generation: [31, 31, 31, 31, 31]","v":0,"name":"crucible","level":30,"time":"2025-05-27T21:20:43.357329132Z","hostname":"bmat-EVT22200007-00006f6c","pid":1250,"":"downstairs","":"downstairs","session_id":"77d7e9cd-9e62-45ef-9e34-872de061dba4"}
3932025-05-27T21:20:44.211Z{"msg":"[0]R dirty: [false, false, false, false, false]","v":0,"name":"crucible","level":30,"time":"2025-05-27T21:20:43.357346436Z","hostname":"bmat-EVT22200007-00006f6c","pid":1250,"":"downstairs","":"downstairs","session_id":"77d7e9cd-9e62-45ef-9e34-872de061dba4"}
3942025-05-27T21:20:44.211Z{"msg":"[1]R flush_numbers: [5321, 5321, 5321, 5321, 5321]","v":0,"name":"crucible","level":30,"time":"2025-05-27T21:20:43.357438489Z","hostname":"bmat-EVT22200007-00006f6c","pid":1250,"":"downstairs","":"downstairs","session_id":"77d7e9cd-9e62-45ef-9e34-872de061dba4"}
3952025-05-27T21:20:44.211Z{"msg":"[1]R generation: [31, 31, 31, 31, 31]","v":0,"name":"crucible","level":30,"time":"2025-05-27T21:20:43.357455593Z","hostname":"bmat-EVT22200007-00006f6c","pid":1250,"":"downstairs","":"downstairs","session_id":"77d7e9cd-9e62-45ef-9e34-872de061dba4"}
3962025-05-27T21:20:44.211Z{"msg":"[1]R dirty: [false, false, false, false, false]","v":0,"name":"crucible","level":30,"time":"2025-05-27T21:20:43.357522697Z","hostname":"bmat-EVT22200007-00006f6c","pid":1250,"":"downstairs","":"downstairs","session_id":"77d7e9cd-9e62-45ef-9e34-872de061dba4"}
3972025-05-27T21:20:44.211Z{"msg":"[2]R flush_numbers: [5321, 5321, 5321, 5321, 5321]","v":0,"name":"crucible","level":30,"time":"2025-05-27T21:20:43.357560933Z","hostname":"bmat-EVT22200007-00006f6c","pid":1250,"":"downstairs","":"downstairs","session_id":"77d7e9cd-9e62-45ef-9e34-872de061dba4"}
3982025-05-27T21:20:44.211Z{"msg":"[2]R generation: [31, 31, 31, 31, 31]","v":0,"name":"crucible","level":30Wait for a query_work_queue command to finish before sending IO
3992025-05-27T21:20:44.211Z,"time":"2025-05-27T21:20:43.357577366Z","hostname":"bmat-EVT22200007-00006f6c","pid":1250,"":"downstairs","":"downstairs","session_id":"77d7e9cd-9e62-45ef-9e34-872de061dba4"}
4002025-05-27T21:20:44.211Z{"msg":"[2]R dirty: [false, false, false, false, false]","v":0,"name":"crucible","level":30,"time":"2025-05-27T21:20:43.357677906Z","hostname":"bmat-EVT22200007-00006f6c","pid":1250,"":"downstairs","":"downstairs","session_id":"77d7e9cd-9e62-45ef-9e34-872de061dba4"}
4012025-05-27T21:20:44.211Z{"msg":"Max found gen is 32","v":0,"name":"crucible","level":30,"time":"2025-05-27T21:20:43.357785079Z","hostname":"bmat-EVT22200007-00006f6c","pid":1250,"":"downstairs","":"downstairs","session_id":"77d7e9cd-9e62-45ef-9e34-872de061dba4"}
4022025-05-27T21:20:44.211Z{"msg":"Generation requested: 32 >= found:32","v":0,"name":"crucible","level":30,"time":"2025-05-27T21:20:43.357803326Z","hostname":"bmat-EVT22200007-00006f6c","pid":1250,"":"downstairs","":"downstairs","session_id":"77d7e9cd-9e62-45ef-9e34-872de061dba4"}
4032025-05-27T21:20:44.211Z{"msg":"Next flush: 5322","v":0,"name":"crucible","level":30,"time":"2025-05-27T21:20:43.357863175Z","hostname":"bmat-EVT22200007-00006f6c","pid":1250,"":"downstairs","":"downstairs","session_id":"77d7e9cd-9e62-45ef-9e34-872de061dba4"}
4042025-05-27T21:20:44.237Z{"msg":"All extents match","v":0,"name":"crucible","level":30,"time":"2025-05-27T21:20:43.357898525Z","hostname":"bmat-EVT22200007-00006f6c","pid":1250,"":"downstairs","":"downstairs","session_id":"77d7e9cd-9e62-45ef-9e34-872de061dba4"}
4052025-05-27T21:20:44.237Z{"msg":"No downstairs reconciliation required","v":0,"name":"crucible","level":30,"time":"2025-05-27T21:20:43.357914998Z","hostname":"bmat-EVT22200007-00006f6c","pid":1250,"session_id":"77d7e9cd-9e62-45ef-9e34-872de061dba4"}
4062025-05-27T21:20:44.237Z{"msg":"Transition from WaitQuorum to Active","v":0,"name":"crucible","level":30,"time":"2025-05-27T21:20:43.358027692Z","hostname":"bmat-EVT22200007-00006f6c","pid":1250,"client":"0","":"downstairs","session_id":"77d7e9cd-9e62-45ef-9e34-872de061dba4"}
4072025-05-27T21:20:44.237Z{"msg":"Transition from WaitQuorum to Active","v":0,"name":"crucible","level":30,"time":"2025-05-27T21:20:43.358119826Z","hostname":"bmat-EVT22200007-00006f6c","pid":1250,"client":"1","":"downstairs","session_id":"77d7e9cd-9e62-45ef-9e34-872de061dba4"}
4082025-05-27T21:20:44.237Z{"msg":"Transition from WaitQuorum to Active","v":0,"name":"crucible","level":30,"time":"2025-05-27T21:20:43.358139124Z","hostname":"bmat-EVT22200007-00006f6c","pid":1250,"client":"2","":"downstairs","session_id":"77d7e9cd-9e62-45ef-9e34-872de061dba4"}
4092025-05-27T21:20:44.237Z{"msg":"All required reconciliation work is completed","v":0,"name":"crucible","level":30,"time":"2025-05-27T21:20:43.358203322Z","hostname":"bmat-EVT22200007-00006f6c","pid":1250,"session_id":"77d7e9cd-9e62-45ef-9e34-872de061dba4"}
4102025-05-27T21:20:44.237Z{"msg":"Set Downstairs and Upstairs active after reconciliation","v":0,"name":"crucible","level":30,"time":"2025-05-27T21:20:43.358238081Z","hostname":"bmat-EVT22200007-00006f6c","pid":1250,"session_id":"77d7e9cd-9e62-45ef-9e34-872de061dba4"}
4112025-05-27T21:20:44.237Z{"msg":"c07ca1c4-6e9e-4bae-92c9-f557c29b4de7 is now active with session: 77d7e9cd-9e62-45ef-9e34-872de061dba4","v":0,"name":"crucible","level":30,"time":"2025-05-27T21:20:43.358255406Z","hostname":"bmat-EVT22200007-00006f6c","pid":1250,"session_id":"77d7e9cd-9e62-45ef-9e34-872de061dba4"}
4122025-05-27T21:20:44.237Z{"msg":"Set Active after no reconciliation","v":0,"name":"crucible","level":30,"time":"2025-05-27T21:20:43.358329092Z","hostname":"bmat-EVT22200007-00006f6c","pid":1250,"session_id":"77d7e9cd-9e62-45ef-9e34-872de061dba4"}
4132025-05-27T21:20:44.237Z{"msg":"The guest has finished waiting for activation with:32","v":0,"name":"crucible","level":30,"time":"2025-05-27T21:20:43.358362168Z","hostname":"bmat-EVT22200007-00006f6c","pid":1250}
4142025-05-27T21:20:44.237Z{"msg":"Activated sub_volume c07ca1c4-6e9e-4bae-92c9-f557c29b4de7","v":0,"name":"crucible","level":30,"time":"2025-05-27T21:20:43.358377539Z","hostname":"bmat-EVT22200007-00006f6c","pid":1250}
4152025-05-27T21:20:44.238ZDisk: sv:2 bs:4096 ts:409600 tb:100 max_io:100 or 409600
4162025-05-27T21:20:44.238ZLoading write count information from file "/var/tmp/test_up-build/verify_file"
4172025-05-27T21:20:44.238ZFill test
4182025-05-27T21:20:44.238ZRead and Verify all blocks (0..100 range:false)
4192025-05-27T21:20:44.302ZWrote out file "/var/tmp/test_up-build/verify_file"
4202025-05-27T21:20:44.302ZCLIENT: Tests done. All submitted work has been ACK'd
4212025-05-27T21:20:44.302Z----------------------------------------------------------------
4222025-05-27T21:20:44.302Z Crucible gen:32 GIO:true work queues: Upstairs:0 downstairs:1
4232025-05-27T21:20:44.302ZStates: Active Active Active
4242025-05-27T21:20:44.302ZJOBID ACK TYPE BKS/EXT DS:0 DS:1 DS:2 REPLAY
4252025-05-27T21:20:44.302Z 1002 Acked Read 50 Done Done Done false
4262025-05-27T21:20:44.302Z STATES DS:0 DS:1 DS:2 TOTAL
4272025-05-27T21:20:44.302Z Sent 0 0 0 0
4282025-05-27T21:20:44.302Z Done 1 1 1 3
4292025-05-27T21:20:44.302Z Skipped 0 0 0 0
4302025-05-27T21:20:44.302Z Error 0 0 0 0
4312025-05-27T21:20:44.302ZLast Flush: Some(JobId(1001)) Some(JobId(1001)) Some(JobId(1001))
4322025-05-27T21:20:44.302ZDownstairs last five completed: 1001 1000
4332025-05-27T21:20:44.302ZUpstairs last five completed: 1002 1001 1000
4342025-05-27T21:20:44.327Z----------------------------------------------------------------
4352025-05-27T21:20:44.327Z Crucible gen:32 GIO:true work queues: Upstairs:0 downstairs:1
4362025-05-27T21:20:44.327ZStates: Active Active Active
4372025-05-27T21:20:44.327ZJOBID ACK TYPE BKS/EXT DS:0 DS:1 DS:2 REPLAY
4382025-05-27T21:20:44.327Z 1002 Acked Read 50 Done Done Done false
4392025-05-27T21:20:44.327Z STATES DS:0 DS:1 DS:2 TOTAL
4402025-05-27T21:20:44.328Z Sent 0 0 0 0
4412025-05-27T21:20:44.328Z Done 1 1 1 3
4422025-05-27T21:20:44.328Z Skipped 0 0 0 0
4432025-05-27T21:20:44.328Z Error 0 0 0 0
4442025-05-27T21:20:44.328ZLast Flush: Some(JobId(1001)) Some(JobId(1001)) Some(JobId(1001))
4452025-05-27T21:20:44.328ZDownstairs last five completed: 1001 1000
4462025-05-27T21:20:44.328ZUpstairs last five completed: 1002 1001 1000
4472025-05-27T21:20:44.328ZCLIENT: Up:0 ds:2 act:6
4482025-05-27T21:20:48.303Z----------------------------------------------------------------
4492025-05-27T21:20:48.303Z Crucible gen:32 GIO:true work queues: Upstairs:0 downstairs:0
4502025-05-27T21:20:48.303ZDownstairs last five completed: 1003 1002 1001 1000
4512025-05-27T21:20:48.303ZUpstairs last five completed: 1003 1002 1001 1000
4522025-05-27T21:20:48.303Z----------------------------------------------------------------
4532025-05-27T21:20:48.303Z Crucible gen:32 GIO:true work queues: Upstairs:0 downstairs:0
4542025-05-27T21:20:48.303ZDownstairs last five completed: 1003 1002 1001 1000
4552025-05-27T21:20:48.303ZUpstairs last five completed: 1003 1002 1001 1000
4562025-05-27T21:20:48.303ZCLIENT: Up:0 ds:0 act:6
4572025-05-27T21:20:48.303ZCLIENT: All crucible jobs finished, exiting program
4582025-05-27T21:20:48.328Z{"msg":"Guest handle has been dropped","v":0,"name":"crucible","level":40,"time":"2025-05-27T21:20:47.507472133Z","hostname":"bmat-EVT22200007-00006f6c","pid":1250}
4592025-05-27T21:20:48.328ZRepair part 1 passed
4602025-05-27T21:20:48.328Z
4612025-05-27T21:20:48.328ZKill the current downstairs
4622025-05-27T21:20:48.528ZDownstairs 2 stopped
4632025-05-27T21:20:48.528Zmv /var/tmp/test_up-build/8830 /var/tmp/test_up-build/new
4642025-05-27T21:20:48.553ZNow put back the original so we have a mismatch
4652025-05-27T21:20:48.553Zmv /var/tmp/test_up-build/previous /var/tmp/test_up-build/8830
4662025-05-27T21:20:48.553ZRestart downstairs with old directory
4672025-05-27T21:20:48.604Z/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
4682025-05-27T21:20:48.629ZEXT BLOCKS GEN0 GEN1 GEN2 FL0 FL1 FL2 D0 D1 D2 DIFF
4692025-05-27T21:20:48.629Z 0 000-009 32 32 31 4001 4001 4000 F F F <---
4702025-05-27T21:20:48.629Z 1 010-019 32 32 31 4001 4001 4000 F F F <---
4712025-05-27T21:20:48.629Z 2 020-029 32 32 31 4001 4001 4000 F F F <---
4722025-05-27T21:20:48.629Z 3 030-039 32 32 31 4001 4001 4000 F F F <---
4732025-05-27T21:20:48.630Z 4 040-049 32 32 31 4001 4001 4000 F F F <---
4742025-05-27T21:20:48.630ZMax gen: 32, Max flush: 4001
4752025-05-27T21:20:48.655ZError: Difference in extent metadata found!
4762025-05-27T21:20:48.655Zdump test found error as expected
4772025-05-27T21:20:48.655Z
4782025-05-27T21:20:48.655Z
4792025-05-27T21:20:48.655Z/var/tmp/bins/crutest verify --range -g 33 -q --key CnZvPnPOKbrPY355yyOGXSwV1w0yrZFYdM2pVQH9kSE= --dsc 127.0.0.1:9998 --verify-out /var/tmp/test_up-build/verify_file --verify-in /var/tmp/test_up-build/verify_file
4802025-05-27T21:20:48.703Z{"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-05-27T21:20:47.906949232Z","hostname":"bmat-EVT22200007-00006f6c","pid":1258,"task":"crutest"}
4812025-05-27T21:20:48.750Z{"msg":"dsc has 6 regions. This means 2 sub_volumes","v":0,"name":"crucible","level":30,"time":"2025-05-27T21:20:47.908027879Z","hostname":"bmat-EVT22200007-00006f6c","pid":1258,"task":"crutest"}
4822025-05-27T21:20:48.751Z{"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-05-27T21:20:47.910495762Z","hostname":"bmat-EVT22200007-00006f6c","pid":1258,"task":"crutest"}
4832025-05-27T21:20:48.751Z{"msg":"Upstairs starts","v":0,"name":"crucible","level":30,"time":"2025-05-27T21:20:47.910714086Z","hostname":"bmat-EVT22200007-00006f6c","pid":1258}
4842025-05-27T21:20:48.751Z{"msg":"Crucible Version: BuildInfo {\n version: \"0.0.1\",\n git_sha: \"dd892d47062b1dcb23800b8bbb5d2946e1dd1cb7\",\n git_commit_timestamp: \"2025-05-27T20:18:55.000000000Z\",\n git_branch: \"alan/agent-needs-workers\",\n rustc_semver: \"1.86.0\",\n rustc_channel: \"stable\",\n rustc_host_triple: \"x86_64-unknown-illumos\",\n rustc_commit_sha: \"05f9846f893b09a1be1fc8560e33fc3c815cfecb\",\n cargo_triple: \"x86_64-unknown-illumos\",\n debug: true,\n opt_level: 0,\n}","v":0,"name":"crucible","level":30,"time":"2025-05-27T21:20:47.91080646Z","hostname":"bmat-EVT22200007-00006f6c","pid":1258}
4852025-05-27T21:20:48.751Z{"msg":"Upstairs <-> Downstairs Message Version: 13","v":0,"name":"crucible","level":30,"time":"2025-05-27T21:20:47.910860257Z","hostname":"bmat-EVT22200007-00006f6c","pid":1258}
4862025-05-27T21:20:48.751Z{"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-05-27T21:20:47.910896109Z","hostname":"bmat-EVT22200007-00006f6c","pid":1258}
4872025-05-27T21:20:48.751Z{"msg":"Crucible 40b123ad-686b-4fb0-bc14-130e449dda3d has session id: 15e5d320-3986-447d-96d9-dcb23b8b1d33","v":0,"name":"crucible","level":30,"time":"2025-05-27T21:20:47.911648797Z","hostname":"bmat-EVT22200007-00006f6c","pid":1258,"session_id":"15e5d320-3986-447d-96d9-dcb23b8b1d33"}
4882025-05-27T21:20:48.751Z{"msg":"Upstairs opts: Upstairs UUID: 40b123ad-686b-4fb0-bc14-130e449dda3d, 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-05-27T21:20:47.911756752Z","hostname":"bmat-EVT22200007-00006f6c","pid":1258,"session_id":"15e5d320-3986-447d-96d9-dcb23b8b1d33"}
4892025-05-27T21:20:48.751Z{"msg":"Crucible stats registered with UUID: 40b123ad-686b-4fb0-bc14-130e449dda3d","v":0,"name":"crucible","level":30,"time":"2025-05-27T21:20:47.911778335Z","hostname":"bmat-EVT22200007-00006f6c","pid":1258,"session_id":"15e5d320-3986-447d-96d9-dcb23b8b1d33"}
4902025-05-27T21:20:48.751Z{"msg":"could not find Downstairs address for Nexus","v":0,"name":"crucible","level":40,"time":"2025-05-27T21:20:47.911795208Z","hostname":"bmat-EVT22200007-00006f6c","pid":1258,"session_id":"15e5d320-3986-447d-96d9-dcb23b8b1d33"}
4912025-05-27T21:20:48.751Z{"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-05-27T21:20:47.91526191Z","hostname":"bmat-EVT22200007-00006f6c","pid":1258,"task":"crutest"}
4922025-05-27T21:20:48.751Z{"msg":"Upstairs starts","v":0,"name":"crucible","level":30,"time":"2025-05-27T21:20:47.915370596Z","hostname":"bmat-EVT22200007-00006f6c","pid":1258}
4932025-05-27T21:20:48.751Z{"msg":"Crucible Version: BuildInfo {\n version: \"0.0.1\",\n git_sha: \"dd892d47062b1dcb23800b8bbb5d2946e1dd1cb7\",\n git_commit_timestamp: \"2025-05-27T20:18:55.000000000Z\",\n git_branch: \"alan/agent-needs-workers\",\n rustc_semver: \"1.86.0\",\n rustc_channel: \"stable\",\n rustc_host_triple: \"x86_64-unknown-illumos\",\n rustc_commit_sha: \"05f9846f893b09a1be1fc8560e33fc3c815cfecb\",\n cargo_triple: \"x86_64-unknown-illumos\",\n debug: true,\n opt_level: 0,\n}","v":0,"name":"crucible","level":30,"time":"2025-05-27T21:20:47.915422309Z","hostname":"bmat-EVT22200007-00006f6c","pid":1258}
4942025-05-27T21:20:48.751Z{"msg":"Upstairs <-> Downstairs Message Version: 13","v":0,"name":"crucible","level":30,"time":"2025-05-27T21:20:47.915439182Z","hostname":"bmat-EVT22200007-00006f6c","pid":1258}
4952025-05-27T21:20:48.751Z{"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-05-27T21:20:47.91545778Z","hostname":"bmat-EVT22200007-00006f6c","pid":1258}
4962025-05-27T21:20:48.751Z{"msg":"Crucible 40b123ad-686b-4fb0-bc14-130e449dda3d has session id: 67adfc74-d0c1-48bf-8681-fd972579c24e","v":0,"name":"crucible","level":30,"time":"2025-05-27T21:20:47.916067443Z","hostname":"bmat-EVT22200007-00006f6c","pid":1258,"session_id":"67adfc74-d0c1-48bf-8681-fd972579c24e"}
4972025-05-27T21:20:48.751Z{"msg":"Upstairs opts: Upstairs UUID: 40b123ad-686b-4fb0-bc14-130e449dda3d, 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-05-27T21:20:47.916114196Z","hostname":"bmat-EVT22200007-00006f6c","pid":1258,"session_id":"67adfc74-d0c1-48bf-8681-fd972579c24e"}
4982025-05-27T21:20:48.751Z{"msg":"Crucible stats registered with UUID: 40b123ad-686b-4fb0-bc14-130e449dda3d","v":0,"name":"crucible","level":30,"time":"2025-05-27T21:20:47.916132924Z","hostname":"bmat-EVT22200007-00006f6c","pid":1258,"session_id":"67adfc74-d0c1-48bf-8681-fd972579c24e"}
4992025-05-27T21:20:48.751Z{"msg":"could not find Downstairs address for Nexus","v":0,"name":"crucible","level":40,"time":"2025-05-27T21:20:47.916148414Z","hostname":"bmat-EVT22200007-00006f6c","pid":1258,"session_id":"67adfc74-d0c1-48bf-8681-fd972579c24e"}
5002025-05-27T21:20:48.751Z{"msg":"Downstairs in volume = 6","v":0,"name":"crucible","level":30,"time":"2025-05-27T21:20:47.916999869Z","hostname":"bmat-EVT22200007-00006f6c","pid":1258,"task":"crutest"}
5012025-05-27T21:20:48.751Z{"msg":"The guest has requested activation with gen:33","v":0,"name":"crucible","level":30,"time":"2025-05-27T21:20:47.917211801Z","hostname":"bmat-EVT22200007-00006f6c","pid":1258}
5022025-05-27T21:20:48.751Z{"msg":"40b123ad-686b-4fb0-bc14-130e449dda3d active request set","v":0,"name":"crucible","level":30,"time":"2025-05-27T21:20:47.917265438Z","hostname":"bmat-EVT22200007-00006f6c","pid":1258,"session_id":"15e5d320-3986-447d-96d9-dcb23b8b1d33"}
5032025-05-27T21:20:48.751Z{"msg":"sending connect oneshot to client","v":0,"name":"crucible","level":30,"time":"2025-05-27T21:20:47.917283754Z","hostname":"bmat-EVT22200007-00006f6c","pid":1258,"client":"0","":"downstairs","session_id":"15e5d320-3986-447d-96d9-dcb23b8b1d33"}
5042025-05-27T21:20:48.751Z{"msg":"client set_active_request while in Connecting { state: Start { auto_promote: true }, mode: New }; waiting...","v":0,"name":"crucible","level":30,"time":"2025-05-27T21:20:47.917333223Z","hostname":"bmat-EVT22200007-00006f6c","pid":1258,"client":"0","":"downstairs","session_id":"15e5d320-3986-447d-96d9-dcb23b8b1d33"}
5052025-05-27T21:20:48.751Z{"msg":"sending connect oneshot to client","v":0,"name":"crucible","level":30,"time":"2025-05-27T21:20:47.917352101Z","hostname":"bmat-EVT22200007-00006f6c","pid":1258,"client":"1","":"downstairs","session_id":"15e5d320-3986-447d-96d9-dcb23b8b1d33"}
5062025-05-27T21:20:48.751Z{"msg":"client set_active_request while in Connecting { state: Start { auto_promote: true }, mode: New }; waiting...","v":0,"name":"crucible","level":30,"time":"2025-05-27T21:20:47.917373754Z","hostname":"bmat-EVT22200007-00006f6c","pid":1258,"client":"1","":"downstairs","session_id":"15e5d320-3986-447d-96d9-dcb23b8b1d33"}
5072025-05-27T21:20:48.751Z{"msg":"sending connect oneshot to client","v":0,"name":"crucible","level":30,"time":"2025-05-27T21:20:47.917391048Z","hostname":"bmat-EVT22200007-00006f6c","pid":1258,"client":"2","":"downstairs","session_id":"15e5d320-3986-447d-96d9-dcb23b8b1d33"}
5082025-05-27T21:20:48.751Z{"msg":"client set_active_request while in Connecting { state: Start { auto_promote: true }, mode: New }; waiting...","v":0,"name":"crucible","level":30,"time":"2025-05-27T21:20:47.91741219Z","hostname":"bmat-EVT22200007-00006f6c","pid":1258,"client":"2","":"downstairs","session_id":"15e5d320-3986-447d-96d9-dcb23b8b1d33"}
5092025-05-27T21:20:48.751Z{"msg":"connecting to 127.0.0.1:8830","v":0,"name":"crucible","level":30,"time":"2025-05-27T21:20:47.917430106Z","hostname":"bmat-EVT22200007-00006f6c","pid":1258,"":"io task","client":"2","":"downstairs","session_id":"15e5d320-3986-447d-96d9-dcb23b8b1d33"}
5102025-05-27T21:20:48.751Z{"msg":"connecting to 127.0.0.1:8810","v":0,"name":"crucible","level":30,"time":"2025-05-27T21:20:47.917464494Z","hostname":"bmat-EVT22200007-00006f6c","pid":1258,"":"io task","client":"0","":"downstairs","session_id":"15e5d320-3986-447d-96d9-dcb23b8b1d33"}
5112025-05-27T21:20:48.751Z{"msg":"connecting to 127.0.0.1:8820","v":0,"name":"crucible","level":30,"time":"2025-05-27T21:20:47.917546668Z","hostname":"bmat-EVT22200007-00006f6c","pid":1258,"":"io task","client":"1","":"downstairs","session_id":"15e5d320-3986-447d-96d9-dcb23b8b1d33"}
5122025-05-27T21:20:48.751Z{"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-05-27T21:20:47.917650795Z","hostname":"bmat-EVT22200007-00006f6c","pid":1258,"":"io task","client":"2","":"downstairs","session_id":"15e5d320-3986-447d-96d9-dcb23b8b1d33"}
5132025-05-27T21:20:48.751Z{"msg":"client task is sending Done(ConnectionFailed(Os { code: 146, kind: ConnectionRefused, message: \"Connection refused\" }))","v":0,"name":"crucible","level":40,"time":"2025-05-27T21:20:47.917691847Z","hostname":"bmat-EVT22200007-00006f6c","pid":1258,"":"io task","client":"2","":"downstairs","session_id":"15e5d320-3986-447d-96d9-dcb23b8b1d33"}
5142025-05-27T21:20:48.751Z{"msg":"ds_connection connected from Ok(127.0.0.1:46097)","v":0,"name":"crucible","level":30,"time":"2025-05-27T21:20:47.917711286Z","hostname":"bmat-EVT22200007-00006f6c","pid":1258,"":"io task","client":"1","":"downstairs","session_id":"15e5d320-3986-447d-96d9-dcb23b8b1d33"}
5152025-05-27T21:20:48.751Z{"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-05-27T21:20:47.9177336Z","hostname":"bmat-EVT22200007-00006f6c","pid":1258,"session_id":"15e5d320-3986-447d-96d9-dcb23b8b1d33"}
5162025-05-27T21:20:48.751Z{"msg":"ds_connection connected from Ok(127.0.0.1:34692)","v":0,"name":"crucible","level":30,"time":"2025-05-27T21:20:47.917910803Z","hostname":"bmat-EVT22200007-00006f6c","pid":1258,"":"io task","client":"0","":"downstairs","session_id":"15e5d320-3986-447d-96d9-dcb23b8b1d33"}
5172025-05-27T21:20:48.751Z{"msg":"client task is exiting","v":0,"name":"crucible","level":30,"time":"2025-05-27T21:20:47.917966393Z","hostname":"bmat-EVT22200007-00006f6c","pid":1258,"":"io task","client":"2","":"downstairs","session_id":"15e5d320-3986-447d-96d9-dcb23b8b1d33"}
5182025-05-27T21:20:48.752Z{"msg":"version negotiation from state Connecting { state: WaitForPromote, mode: New }","v":0,"name":"crucible","level":30,"time":"2025-05-27T21:20:47.91863302Z","hostname":"bmat-EVT22200007-00006f6c","pid":1258,"client":"1","":"downstairs","session_id":"15e5d320-3986-447d-96d9-dcb23b8b1d33"}
5192025-05-27T21:20:48.752Z{"msg":"version negotiation from state Connecting { state: WaitForPromote, mode: New }","v":0,"name":"crucible","level":30,"time":"2025-05-27T21:20:47.918672509Z","hostname":"bmat-EVT22200007-00006f6c","pid":1258,"client":"0","":"downstairs","session_id":"15e5d320-3986-447d-96d9-dcb23b8b1d33"}
5202025-05-27T21:20:48.752Z{"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-05-27T21:20:47.919673832Z","hostname":"bmat-EVT22200007-00006f6c","pid":1258,"client":"0","":"downstairs","session_id":"15e5d320-3986-447d-96d9-dcb23b8b1d33"}
5212025-05-27T21:20:48.752Z{"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-05-27T21:20:47.919940263Z","hostname":"bmat-EVT22200007-00006f6c","pid":1258,"client":"1","":"downstairs","session_id":"15e5d320-3986-447d-96d9-dcb23b8b1d33"}
5222025-05-27T21:20:48.752Z{"msg":"Waiting for more clients to be ready","v":0,"name":"crucible","level":30,"time":"2025-05-27T21:20:47.920286061Z","hostname":"bmat-EVT22200007-00006f6c","pid":1258,"session_id":"15e5d320-3986-447d-96d9-dcb23b8b1d33"}
5232025-05-27T21:20:48.752Z{"msg":"Waiting for more clients to be ready","v":0,"name":"crucible","level":30,"time":"2025-05-27T21:20:47.920669354Z","hostname":"bmat-EVT22200007-00006f6c","pid":1258,"session_id":"15e5d320-3986-447d-96d9-dcb23b8b1d33"}
5242025-05-27T21:20:58.715Z{"msg":"connecting to 127.0.0.1:8830","v":0,"name":"crucible","level":30,"time":"2025-05-27T21:20:57.919752551Z","hostname":"bmat-EVT22200007-00006f6c","pid":1258,"":"io task","client":"2","":"downstairs","session_id":"15e5d320-3986-447d-96d9-dcb23b8b1d33"}
5252025-05-27T21:20:58.715Z{"msg":"ds_connection connected from Ok(127.0.0.1:34854)","v":0,"name":"crucible","level":30,"time":"2025-05-27T21:20:57.91988278Z","hostname":"bmat-EVT22200007-00006f6c","pid":1258,"":"io task","client":"2","":"downstairs","session_id":"15e5d320-3986-447d-96d9-dcb23b8b1d33"}
5262025-05-27T21:20:58.789Z{"msg":"version negotiation from state Connecting { state: WaitForPromote, mode: New }","v":0,"name":"crucible","level":30,"time":"2025-05-27T21:20:57.921057508Z","hostname":"bmat-EVT22200007-00006f6c","pid":1258,"client":"2","":"downstairs","session_id":"15e5d320-3986-447d-96d9-dcb23b8b1d33"}
5272025-05-27T21:20:58.789Z{"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-05-27T21:20:57.922100595Z","hostname":"bmat-EVT22200007-00006f6c","pid":1258,"client":"2","":"downstairs","session_id":"15e5d320-3986-447d-96d9-dcb23b8b1d33"}
5282025-05-27T21:20:58.789Z{"msg":"[0]R flush_numbers: [4001, 4001, 4001, 4001, 4001]","v":0,"name":"crucible","level":30,"time":"2025-05-27T21:20:57.922679497Z","hostname":"bmat-EVT22200007-00006f6c","pid":1258,"":"downstairs","":"downstairs","session_id":"15e5d320-3986-447d-96d9-dcb23b8b1d33"}
5292025-05-27T21:20:58.789Z{"msg":"[0]R generation: [32, 32, 32, 32, 32]","v":0,"name":"crucible","level":30,"time":"2025-05-27T21:20:57.922719567Z","hostname":"bmat-EVT22200007-00006f6c","pid":1258,"":"downstairs","":"downstairs","session_id":"15e5d320-3986-447d-96d9-dcb23b8b1d33"}
5302025-05-27T21:20:58.789Z{"msg":"[0]R dirty: [false, false, false, false, false]","v":0,"name":"crucible","level":30,"time":"2025-05-27T21:20:57.922738164Z","hostname":"bmat-EVT22200007-00006f6c","pid":1258,"":"downstairs","":"downstairs","session_id":"15e5d320-3986-447d-96d9-dcb23b8b1d33"}
5312025-05-27T21:20:58.789Z{"msg":"[1]R flush_numbers: [4001, 4001, 4001, 4001, 4001]","v":0,"name":"crucible","level":30,"time":"2025-05-27T21:20:57.922769767Z","hostname":"bmat-EVT22200007-00006f6c","pid":1258,"":"downstairs","":"downstairs","session_id":"15e5d320-3986-447d-96d9-dcb23b8b1d33"}
5322025-05-27T21:20:58.789Z{"msg":"[1]R generation: [32, 32, 32, 32, 32]","v":0,"name":"crucible","level":30,"time":"2025-05-27T21:20:57.922787142Z","hostname":"bmat-EVT22200007-00006f6c","pid":1258,"":"downstairs","":"downstairs","session_id":"15e5d320-3986-447d-96d9-dcb23b8b1d33"}
5332025-05-27T21:20:58.789Z{"msg":"[1]R dirty: [false, false, false, false, false]","v":0,"name":"crucible","level":30,"time":"2025-05-27T21:20:57.922878473Z","hostname":"bmat-EVT22200007-00006f6c","pid":1258,"":"downstairs","":"downstairs","session_id":"15e5d320-3986-447d-96d9-dcb23b8b1d33"}
5342025-05-27T21:20:58.789Z{"msg":"[2]R flush_numbers: [4000, 4000, 4000, 4000, 4000]","v":0,"name":"crucible","level":30,"time":"2025-05-27T21:20:57.922916118Z","hostname":"bmat-EVT22200007-00006f6c","pid":1258,"":"downstairs","":"downstairs","session_id":"15e5d320-3986-447d-96d9-dcb23b8b1d33"}
5352025-05-27T21:20:58.789Z{"msg":"[2]R generation: [31, 31, 31, 31, 31]","v":0,"name":"crucible","level":30,"time":"2025-05-27T21:20:57.922933894Z","hostname":"bmat-EVT22200007-00006f6c","pid":1258,"":"downstairs","":"downstairs","session_id":"15e5d320-3986-447d-96d9-dcb23b8b1d33"}
5362025-05-27T21:20:58.789Z{"msg":"[2]R dirty: [false, false, false, false, false]","v":0,"name":"crucible","level":30,"time":"2025-05-27T21:20:57.922968322Z","hostname":"bmat-EVT22200007-00006f6c","pid":1258,"":"downstairs","":"downstairs","session_id":"15e5d320-3986-447d-96d9-dcb23b8b1d33"}
5372025-05-27T21:20:58.789Z{"msg":"Max found gen is 33","v":0,"name":"crucible","level":30,"time":"2025-05-27T21:20:57.922985827Z","hostname":"bmat-EVT22200007-00006f6c","pid":1258,"":"downstairs","":"downstairs","session_id":"15e5d320-3986-447d-96d9-dcb23b8b1d33"}
5382025-05-27T21:20:58.789Z{"msg":"Generation requested: 33 >= found:33","v":0,"name":"crucible","level":30,"time":"2025-05-27T21:20:57.923004444Z","hostname":"bmat-EVT22200007-00006f6c","pid":1258,"":"downstairs","":"downstairs","session_id":"15e5d320-3986-447d-96d9-dcb23b8b1d33"}
5392025-05-27T21:20:58.790Z{"msg":"Next flush: 4002","v":0,"name":"crucible","level":30,"time":"2025-05-27T21:20:57.923021298Z","hostname":"bmat-EVT22200007-00006f6c","pid":1258,"":"downstairs","":"downstairs","session_id":"15e5d320-3986-447d-96d9-dcb23b8b1d33"}
5402025-05-27T21:20:58.790Z{"msg":"extent 0 needs reconciliation: ExtentMetadata { gen: 32, flush: 4001, dirty: false } ExtentMetadata { gen: 32, flush: 4001, dirty: false } ExtentMetadata { gen: 31, flush: 4000, dirty: false }","v":0,"name":"crucible","level":30,"time":"2025-05-27T21:20:57.92306267Z","hostname":"bmat-EVT22200007-00006f6c","pid":1258,"":"mend","":"downstairs","":"downstairs","session_id":"15e5d320-3986-447d-96d9-dcb23b8b1d33"}
5412025-05-27T21:20:58.790Z{"msg":"extent:0 [ExtentMetadata { gen: 32, flush: 4001, dirty: false }, ExtentMetadata { gen: 32, flush: 4001, dirty: false }, ExtentMetadata { gen: 31, flush: 4000, dirty: false }] => 0","v":0,"name":"crucible","level":30,"time":"2025-05-27T21:20:57.923100435Z","hostname":"bmat-EVT22200007-00006f6c","pid":1258,"":"mend","":"downstairs","":"downstairs","session_id":"15e5d320-3986-447d-96d9-dcb23b8b1d33"}
5422025-05-27T21:20:58.790Z{"msg":"found dest for source 0 for extent at index 0 => [ClientId(2)]","v":0,"name":"crucible","level":30,"time":"2025-05-27T21:20:57.923120716Z","hostname":"bmat-EVT22200007-00006f6c","pid":1258,"":"mend","":"downstairs","":"downstairs","session_id":"15e5d320-3986-447d-96d9-dcb23b8b1d33"}
5432025-05-27T21:20:58.790Z{"msg":"extent 1 needs reconciliation: ExtentMetadata { gen: 32, flush: 4001, dirty: false } ExtentMetadata { gen: 32, flush: 4001, dirty: false } ExtentMetadata { gen: 31, flush: 4000, dirty: false }","v":0,"name":"crucible","level":30,"time":"2025-05-27T21:20:57.923156337Z","hostname":"bmat-EVT22200007-00006f6c","pid":1258,"":"mend","":"downstairs","":"downstairs","session_id":"15e5d320-3986-447d-96d9-dcb23b8b1d33"}
5442025-05-27T21:20:58.790Z{"msg":"extent:0 [ExtentMetadata { gen: 32, flush: 4001, dirty: false }, ExtentMetadata { gen: 32, flush: 4001, dirty: false }, ExtentMetadata { gen: 31, flush: 4000, dirty: false }] => 0","v":0,"name":"crucible","level":30,"time":"2025-05-27T21:20:57.92319297Z","hostname":"bmat-EVT22200007-00006f6c","pid":1258,"":"mend","":"downstairs","":"downstairs","session_id":"15e5d320-3986-447d-96d9-dcb23b8b1d33"}
5452025-05-27T21:20:58.790Z{"msg":"found dest for source 0 for extent at index 1 => [ClientId(2)]","v":0,"name":"crucible","level":30,"time":"2025-05-27T21:20:57.923212909Z","hostname":"bmat-EVT22200007-00006f6c","pid":1258,"":"mend","":"downstairs","":"downstairs","session_id":"15e5d320-3986-447d-96d9-dcb23b8b1d33"}
5462025-05-27T21:20:58.790Z{"msg":"extent 2 needs reconciliation: ExtentMetadata { gen: 32, flush: 4001, dirty: false } ExtentMetadata { gen: 32, flush: 4001, dirty: false } ExtentMetadata { gen: 31, flush: 4000, dirty: false }","v":0,"name":"crucible","level":30,"time":"2025-05-27T21:20:57.923248841Z","hostname":"bmat-EVT22200007-00006f6c","pid":1258,"":"mend","":"downstairs","":"downstairs","session_id":"15e5d320-3986-447d-96d9-dcb23b8b1d33"}
5472025-05-27T21:20:58.790Z{"msg":"extent:0 [ExtentMetadata { gen: 32, flush: 4001, dirty: false }, ExtentMetadata { gen: 32, flush: 4001, dirty: false }, ExtentMetadata { gen: 31, flush: 4000, dirty: false }] => 0","v":0,"name":"crucible","level":30,"time":"2025-05-27T21:20:57.923269081Z","hostname":"bmat-EVT22200007-00006f6c","pid":1258,"":"mend","":"downstairs","":"downstairs","session_id":"15e5d320-3986-447d-96d9-dcb23b8b1d33"}
5482025-05-27T21:20:58.790Z{"msg":"found dest for source 0 for extent at index 2 => [ClientId(2)]","v":0,"name":"crucible","level":30,"time":"2025-05-27T21:20:57.923301345Z","hostname":"bmat-EVT22200007-00006f6c","pid":1258,"":"mend","":"downstairs","":"downstairs","session_id":"15e5d320-3986-447d-96d9-dcb23b8b1d33"}
5492025-05-27T21:20:58.790Z{"msg":"extent 3 needs reconciliation: ExtentMetadata { gen: 32, flush: 4001, dirty: false } ExtentMetadata { gen: 32, flush: 4001, dirty: false } ExtentMetadata { gen: 31, flush: 4000, dirty: false }","v":0,"name":"crucible","level":30,"time":"2025-05-27T21:20:57.923322117Z","hostname":"bmat-EVT22200007-00006f6c","pid":1258,"":"mend","":"downstairs","":"downstairs","session_id":"15e5d320-3986-447d-96d9-dcb23b8b1d33"}
5502025-05-27T21:20:58.790Z{"msg":"extent:0 [ExtentMetadata { gen: 32, flush: 4001, dirty: false }, ExtentMetadata { gen: 32, flush: 4001, dirty: false }, ExtentMetadata { gen: 31, flush: 4000, dirty: false }] => 0","v":0,"name":"crucible","level":30,"time":"2025-05-27T21:20:57.92334382Z","hostname":"bmat-EVT22200007-00006f6c","pid":1258,"":"mend","":"downstairs","":"downstairs","session_id":"15e5d320-3986-447d-96d9-dcb23b8b1d33"}
5512025-05-27T21:20:58.790Z{"msg":"found dest for source 0 for extent at index 3 => [ClientId(2)]","v":0,"name":"crucible","level":30,"time":"2025-05-27T21:20:57.923361886Z","hostname":"bmat-EVT22200007-00006f6c","pid":1258,"":"mend","":"downstairs","":"downstairs","session_id":"15e5d320-3986-447d-96d9-dcb23b8b1d33"}
5522025-05-27T21:20:58.790Z{"msg":"extent 4 needs reconciliation: ExtentMetadata { gen: 32, flush: 4001, dirty: false } ExtentMetadata { gen: 32, flush: 4001, dirty: false } ExtentMetadata { gen: 31, flush: 4000, dirty: false }","v":0,"name":"crucible","level":30,"time":"2025-05-27T21:20:57.923395262Z","hostname":"bmat-EVT22200007-00006f6c","pid":1258,"":"mend","":"downstairs","":"downstairs","session_id":"15e5d320-3986-447d-96d9-dcb23b8b1d33"}
5532025-05-27T21:20:58.790Z{"msg":"extent:0 [ExtentMetadata { gen: 32, flush: 4001, dirty: false }, ExtentMetadata { gen: 32, flush: 4001, dirty: false }, ExtentMetadata { gen: 31, flush: 4000, dirty: false }] => 0","v":0,"name":"crucible","level":30,"time":"2025-05-27T21:20:57.923415583Z","hostname":"bmat-EVT22200007-00006f6c","pid":1258,"":"mend","":"downstairs","":"downstairs","session_id":"15e5d320-3986-447d-96d9-dcb23b8b1d33"}
5542025-05-27T21:20:58.790Z{"msg":"found dest for source 0 for extent at index 4 => [ClientId(2)]","v":0,"name":"crucible","level":30,"time":"2025-05-27T21:20:57.923447256Z","hostname":"bmat-EVT22200007-00006f6c","pid":1258,"":"mend","":"downstairs","":"downstairs","session_id":"15e5d320-3986-447d-96d9-dcb23b8b1d33"}
5552025-05-27T21:20:58.790Z{"msg":"Transition from Connecting { state: WaitQuorum, mode: New } to Reconcile","v":0,"name":"crucible","level":30,"time":"2025-05-27T21:20:57.923490472Z","hostname":"bmat-EVT22200007-00006f6c","pid":1258,"client":"0","":"downstairs","session_id":"15e5d320-3986-447d-96d9-dcb23b8b1d33"}
5562025-05-27T21:20:58.790Z{"msg":"Transition from Connecting { state: WaitQuorum, mode: New } to Reconcile","v":0,"name":"crucible","level":30,"time":"2025-05-27T21:20:57.923523648Z","hostname":"bmat-EVT22200007-00006f6c","pid":1258,"client":"1","":"downstairs","session_id":"15e5d320-3986-447d-96d9-dcb23b8b1d33"}
5572025-05-27T21:20:58.790Z{"msg":"Transition from Connecting { state: WaitQuorum, mode: New } to Reconcile","v":0,"name":"crucible","level":30,"time":"2025-05-27T21:20:57.923542616Z","hostname":"bmat-EVT22200007-00006f6c","pid":1258,"client":"2","":"downstairs","session_id":"15e5d320-3986-447d-96d9-dcb23b8b1d33"}
5582025-05-27T21:20:58.790Z{"msg":"Full repair list: {ExtentId(1): ExtentFix { source: ClientId(0), dest: [ClientId(2)] }, ExtentId(0): ExtentFix { source: ClientId(0), dest: [ClientId(2)] }, ExtentId(3): ExtentFix { source: ClientId(0), dest: [ClientId(2)] }, ExtentId(4): ExtentFix { source: ClientId(0), dest: [ClientId(2)] }, ExtentId(2): ExtentFix { source: ClientId(0), dest: [ClientId(2)] }}","v":0,"name":"crucible","level":30,"time":"2025-05-27T21:20:57.92358009Z","hostname":"bmat-EVT22200007-00006f6c","pid":1258,"":"downstairs","":"downstairs","session_id":"15e5d320-3986-447d-96d9-dcb23b8b1d33"}
5592025-05-27T21:20:58.790Z{"msg":"Task list: [ReconcileIO { id: ReconciliationId(0), op: ExtentFlush { repair_id: ReconciliationId(0), extent_id: ExtentId(1), client_id: ClientId(0), flush_number: 4002, gen_number: 33 }, state: ClientData([New, New, New]) }, ReconcileIO { id: ReconciliationId(1), op: ExtentClose { repair_id: ReconciliationId(1), extent_id: ExtentId(1) }, state: ClientData([New, New, New]) }, ReconcileIO { id: ReconciliationId(2), op: ExtentRepair { repair_id: ReconciliationId(2), extent_id: ExtentId(1), source_client_id: ClientId(0), source_repair_address: 0.0.0.0:12810, dest_clients: [ClientId(2)] }, state: ClientData([New, New, New]) }, ReconcileIO { id: ReconciliationId(3), op: ExtentReopen { repair_id: ReconciliationId(3), extent_id: ExtentId(1) }, state: ClientData([New, New, New]) }, ReconcileIO { id: ReconciliationId(4), op: ExtentFlush { repair_id: ReconciliationId(4), extent_id: ExtentId(0), client_id: ClientId(0), flush_number: 4002, gen_number: 33 }, state: ClientData([New, New, New]) }, ReconcileIO { id: ReconciliationId(5), op: ExtentClose { repair_id: ReconciliationId(5), extent_id: ExtentId(0) }, state: ClientData([New, New, New]) }, ReconcileIO { id: ReconciliationId(6), op: ExtentRepair { repair_id: ReconciliationId(6), extent_id: ExtentId(0), source_client_id: ClientId(0), source_repair_address: 0.0.0.0:12810, dest_clients: [ClientId(2)] }, state: ClientData([New, New, New]) }, ReconcileIO { id: ReconciliationId(7), op: ExtentReopen { repair_id: ReconciliationId(7), extent_id: ExtentId(0) }, state: ClientData([New, New, New]) }, ReconcileIO { id: ReconciliationId(8), op: ExtentFlush { repair_id: ReconciliationId(8), extent_id: ExtentId(3), client_id: ClientId(0), flush_number: 4002, gen_number: 33 }, state: ClientData([New, New, New]) }, ReconcileIO { id: ReconciliationId(9), op: ExtentClose { repair_id: ReconciliationId(9), extent_id: ExtentId(3) }, state: ClientData([New, New, New]) }, ReconcileIO { id: ReconciliationId(10), op: ExtentRepair { repair_id: ReconciliationId(10), extent_id: ExtentId(3), source_client_id: ClientId(0), source_repair_address: 0.0.0.0:12810, dest_clients: [ClientId(2)] }, state: ClientData([New, New, New]) }, ReconcileIO { id: ReconciliationId(11), op: ExtentReopen { repair_id: ReconciliationId(11), extent_id: ExtentId(3) }, state: ClientData([New, New, New]) }, ReconcileIO { id: ReconciliationId(12), op: ExtentFlush { repair_id: ReconciliationId(12), extent_id: ExtentId(4), client_id: ClientId(0), flush_number: 4002, gen_number: 33 }, state: ClientData([New, New, New]) }, ReconcileIO { id: ReconciliationId(13), op: ExtentClose { repair_id: ReconciliationId(13), extent_id: ExtentId(4) }, state: ClientData([New, New, New]) }, ReconcileIO { id: ReconciliationId(14), op: ExtentRepair { repair_id: ReconciliationId(14), extent_id: ExtentId(4), source_client_id: ClientId(0), source_repair_address: 0.0.0.0:12810, dest_clients: [ClientId(2)] }, state: ClientData([New, New, New]) }, ReconcileIO { id: ReconciliationId(15), op: ExtentReopen { repair_id: ReconciliationId(15), extent_id: ExtentId(4) }, state: ClientData([New, New, New]) }, ReconcileIO { id: ReconciliationId(16), op: ExtentFlush { repair_id: ReconciliationId(16), extent_id: ExtentId(2), client_id: ClientId(0), flush_number: 4002, gen_number: 33 }, state: ClientData([New, New, New]) }, ReconcileIO { id: ReconciliationId(17), op: ExtentClose { repair_id: ReconciliationId(17), extent_id: ExtentId(2) }, state: ClientData([New, New, New]) }, ReconcileIO { id: ReconciliationId(18), op: ExtentRepair { repair_id: ReconciliationId(18), 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(19), op: ExtentReopen { repair_id: ReconciliationId(19), extent_id: ExtentId(2) }, state: ClientData([New, New, New]) }]","v":0,"name":"crucible","level":30,"time":"2025-05-27T21:20:57.923916851Z","hostname":"bmat-EVT22200007-00006f6c","pid":1258,"":"downstairs","":"downstairs","session_id":"15e5d320-3986-447d-96d9-dcb23b8b1d33"}
5602025-05-27T21:20:58.790Z{"msg":"starting reconciliation 48fd6614-a669-488f-9b10-cd27b878f4af: found 20 extents that need repair","v":0,"name":"crucible","level":30,"time":"2025-05-27T21:20:57.923944866Z","hostname":"bmat-EVT22200007-00006f6c","pid":1258,"":"downstairs","":"downstairs","session_id":"15e5d320-3986-447d-96d9-dcb23b8b1d33"}
5612025-05-27T21:20:58.790Z{"msg":"sending reconcile request ReconciliationId(2)","v":0,"name":"crucible","level":30,"time":"2025-05-27T21:20:57.924905318Z","hostname":"bmat-EVT22200007-00006f6c","pid":1258,"client":"2","":"downstairs","session_id":"15e5d320-3986-447d-96d9-dcb23b8b1d33"}
5622025-05-27T21:20:58.790Z{"msg":"sending reconcile request ReconciliationId(6)","v":0,"name":"crucible","level":30,"time":"2025-05-27T21:20:57.937714728Z","hostname":"bmat-EVT22200007-00006f6c","pid":1258,"client":"2","":"downstairs","session_id":"15e5d320-3986-447d-96d9-dcb23b8b1d33"}
5632025-05-27T21:20:58.790Z{"msg":"sending reconcile request ReconciliationId(10)","v":0,"name":"crucible","level":30,"time":"2025-05-27T21:20:57.942911954Z","hostname":"bmat-EVT22200007-00006f6c","pid":1258,"client":"2","":"downstairs","session_id":"15e5d320-3986-447d-96d9-dcb23b8b1d33"}
5642025-05-27T21:20:58.790Z{"msg":"sending reconcile request ReconciliationId(14)","v":0,"name":"crucible","level":30,"time":"2025-05-27T21:20:57.94815427Z","hostname":"bmat-EVT22200007-00006f6c","pid":1258,"client":"2","":"downstairs","session_id":"15e5d320-3986-447d-96d9-dcb23b8b1d33"}
5652025-05-27T21:20:58.816Z{"msg":"sending reconcile request ReconciliationId(18)","v":0,"name":"crucible","level":30,"time":"2025-05-27T21:20:57.954441015Z","hostname":"bmat-EVT22200007-00006f6c","pid":1258,"client":"2","":"downstairs","session_id":"15e5d320-3986-447d-96d9-dcb23b8b1d33"}
5662025-05-27T21:20:58.816Z{"msg":"done with reconciliation","v":0,"name":"crucible","level":30,"time":"2025-05-27T21:20:57.959261732Z","hostname":"bmat-EVT22200007-00006f6c","pid":1258,"":"downstairs","":"downstairs","session_id":"15e5d320-3986-447d-96d9-dcb23b8b1d33"}
5672025-05-27T21:20:58.816Z{"msg":"Transition from Reconcile to Active","v":0,"name":"crucible","level":30,"time":"2025-05-27T21:20:57.959366741Z","hostname":"bmat-EVT22200007-00006f6c","pid":1258,"client":"0","":"downstairs","session_id":"15e5d320-3986-447d-96d9-dcb23b8b1d33"}
5682025-05-27T21:20:58.816Z{"msg":"Transition from Reconcile to Active","v":0,"name":"crucible","level":30,"time":"2025-05-27T21:20:57.959398123Z","hostname":"bmat-EVT22200007-00006f6c","pid":1258,"client":"1","":"downstairs","session_id":"15e5d320-3986-447d-96d9-dcb23b8b1d33"}
5692025-05-27T21:20:58.816Z{"msg":"Transition from Reconcile to Active","v":0,"name":"crucible","level":30,"time":"2025-05-27T21:20:57.959425337Z","hostname":"bmat-EVT22200007-00006f6c","pid":1258,"client":"2","":"downstairs","session_id":"15e5d320-3986-447d-96d9-dcb23b8b1d33"}
5702025-05-27T21:20:58.816Z{"msg":"All required reconciliation work is completed","v":0,"name":"crucible","level":30,"time":"2025-05-27T21:20:57.959473393Z","hostname":"bmat-EVT22200007-00006f6c","pid":1258,"session_id":"15e5d320-3986-447d-96d9-dcb23b8b1d33"}
5712025-05-27T21:20:58.816Z{"msg":"Set Downstairs and Upstairs active after reconciliation","v":0,"name":"crucible","level":30,"time":"2025-05-27T21:20:57.959498172Z","hostname":"bmat-EVT22200007-00006f6c","pid":1258,"session_id":"15e5d320-3986-447d-96d9-dcb23b8b1d33"}
5722025-05-27T21:20:58.816Z{"msg":"40b123ad-686b-4fb0-bc14-130e449dda3d is now active with session: 15e5d320-3986-447d-96d9-dcb23b8b1d33","v":0,"name":"crucible","level":30,"time":"2025-05-27T21:20:57.959544194Z","hostname":"bmat-EVT22200007-00006f6c","pid":1258,"session_id":"15e5d320-3986-447d-96d9-dcb23b8b1d33"}
5732025-05-27T21:20:58.816Z{"msg":"The guest has finished waiting for activation with:33","v":0,"name":"crucible","level":30,"time":"2025-05-27T21:20:57.959568843Z","hostname":"bmat-EVT22200007-00006f6c","pid":1258}
5742025-05-27T21:20:58.816Z{"msg":"Activated sub_volume 40b123ad-686b-4fb0-bc14-130e449dda3d","v":0,"name":"crucible","level":30,"time":"2025-05-27T21:20:57.959610686Z","hostname":"bmat-EVT22200007-00006f6c","pid":1258}
5752025-05-27T21:20:58.816Z{"msg":"The guest has requested activation with gen:33","v":0,"name":"crucible","level":30,"time":"2025-05-27T21:20:57.959664944Z","hostname":"bmat-EVT22200007-00006f6c","pid":1258}
5762025-05-27T21:20:58.816Z{"msg":"40b123ad-686b-4fb0-bc14-130e449dda3d active request set","v":0,"name":"crucible","level":30,"time":"2025-05-27T21:20:57.959711797Z","hostname":"bmat-EVT22200007-00006f6c","pid":1258,"session_id":"67adfc74-d0c1-48bf-8681-fd972579c24e"}
5772025-05-27T21:20:58.816Z{"msg":"sending connect oneshot to client","v":0,"name":"crucible","level":30,"time":"2025-05-27T21:20:57.959736156Z","hostname":"bmat-EVT22200007-00006f6c","pid":1258,"client":"0","":"downstairs","session_id":"67adfc74-d0c1-48bf-8681-fd972579c24e"}
5782025-05-27T21:20:58.816Z{"msg":"client set_active_request while in Connecting { state: Start { auto_promote: true }, mode: New }; waiting...","v":0,"name":"crucible","level":30,"time":"2025-05-27T21:20:57.959784111Z","hostname":"bmat-EVT22200007-00006f6c","pid":1258,"client":"0","":"downstairs","session_id":"67adfc74-d0c1-48bf-8681-fd972579c24e"}
5792025-05-27T21:20:58.817Z{"msg":"sending connect oneshot to client","v":0,"name":"crucible","level":30,"time":"2025-05-27T21:20:57.959811195Z","hostname":"bmat-EVT22200007-00006f6c","pid":1258,"client":"1","":"downstairs","session_id":"67adfc74-d0c1-48bf-8681-fd972579c24e"}
5802025-05-27T21:20:58.817Z{"msg":"client set_active_request while in Connecting { state: Start { auto_promote: true }, mode: New }; waiting...","v":0,"name":"crucible","level":30,"time":"2025-05-27T21:20:57.95985896Z","hostname":"bmat-EVT22200007-00006f6c","pid":1258,"client":"1","":"downstairs","session_id":"67adfc74-d0c1-48bf-8681-fd972579c24e"}
5812025-05-27T21:20:58.817Z{"msg":"sending connect oneshot to client","v":0,"name":"crucible","level":30,"time":"2025-05-27T21:20:57.959884612Z","hostname":"bmat-EVT22200007-00006f6c","pid":1258,"client":"2","":"downstairs","session_id":"67adfc74-d0c1-48bf-8681-fd972579c24e"}
5822025-05-27T21:20:58.817Z{"msg":"client set_active_request while in Connecting { state: Start { auto_promote: true }, mode: New }; waiting...","v":0,"name":"crucible","level":30,"time":"2025-05-27T21:20:57.95991374Z","hostname":"bmat-EVT22200007-00006f6c","pid":1258,"client":"2","":"downstairs","session_id":"67adfc74-d0c1-48bf-8681-fd972579c24e"}
5832025-05-27T21:20:58.817Z{"msg":"connecting to 127.0.0.1:8860","v":0,"name":"crucible","level":30,"time":"2025-05-27T21:20:57.959938849Z","hostname":"bmat-EVT22200007-00006f6c","pid":1258,"":"io task","client":"2","":"downstairs","session_id":"67adfc74-d0c1-48bf-8681-fd972579c24e"}
5842025-05-27T21:20:58.817Z{"msg":"connecting to 127.0.0.1:8840","v":0,"name":"crucible","level":30,"time":"2025-05-27T21:20:57.959985432Z","hostname":"bmat-EVT22200007-00006f6c","pid":1258,"":"io task","client":"0","":"downstairs","session_id":"67adfc74-d0c1-48bf-8681-fd972579c24e"}
5852025-05-27T21:20:58.817Z{"msg":"ds_connection connected from Ok(127.0.0.1:35426)","v":0,"name":"crucible","level":30,"time":"2025-05-27T21:20:57.960012476Z","hostname":"bmat-EVT22200007-00006f6c","pid":1258,"":"io task","client":"2","":"downstairs","session_id":"67adfc74-d0c1-48bf-8681-fd972579c24e"}
5862025-05-27T21:20:58.817Z{"msg":"connecting to 127.0.0.1:8850","v":0,"name":"crucible","level":30,"time":"2025-05-27T21:20:57.960038658Z","hostname":"bmat-EVT22200007-00006f6c","pid":1258,"":"io task","client":"1","":"downstairs","session_id":"67adfc74-d0c1-48bf-8681-fd972579c24e"}
5872025-05-27T21:20:58.817Z{"msg":"ds_connection connected from Ok(127.0.0.1:49623)","v":0,"name":"crucible","level":30,"time":"2025-05-27T21:20:57.960065041Z","hostname":"bmat-EVT22200007-00006f6c","pid":1258,"":"io task","client":"0","":"downstairs","session_id":"67adfc74-d0c1-48bf-8681-fd972579c24e"}
5882025-05-27T21:20:58.817Z{"msg":"ds_connection connected from Ok(127.0.0.1:48357)","v":0,"name":"crucible","level":30,"time":"2025-05-27T21:20:57.960150811Z","hostname":"bmat-EVT22200007-00006f6c","pid":1258,"":"io task","client":"1","":"downstairs","session_id":"67adfc74-d0c1-48bf-8681-fd972579c24e"}
5892025-05-27T21:20:58.817Z{"msg":"version negotiation from state Connecting { state: WaitForPromote, mode: New }","v":0,"name":"crucible","level":30,"time":"2025-05-27T21:20:57.960514055Z","hostname":"bmat-EVT22200007-00006f6c","pid":1258,"client":"2","":"downstairs","session_id":"67adfc74-d0c1-48bf-8681-fd972579c24e"}
5902025-05-27T21:20:58.817Z{"msg":"version negotiation from state Connecting { state: WaitForPromote, mode: New }","v":0,"name":"crucible","level":30,"time":"2025-05-27T21:20:57.960858641Z","hostname":"bmat-EVT22200007-00006f6c","pid":1258,"client":"0","":"downstairs","session_id":"67adfc74-d0c1-48bf-8681-fd972579c24e"}
5912025-05-27T21:20:58.817Z{"msg":"version negotiation from state Connecting { state: WaitForPromote, mode: New }","v":0,"name":"crucible","level":30,"time":"2025-05-27T21:20:57.961242865Z","hostname":"bmat-EVT22200007-00006f6c","pid":1258,"client":"1","":"downstairs","session_id":"67adfc74-d0c1-48bf-8681-fd972579c24e"}
5922025-05-27T21:20:58.817Z{"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-05-27T21:20:57.96128524Z","hostname":"bmat-EVT22200007-00006f6c","pid":1258,"client":"2","":"downstairs","session_id":"67adfc74-d0c1-48bf-8681-fd972579c24e"}
5932025-05-27T21:20:58.817Z{"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-05-27T21:20:57.961482853Z","hostname":"bmat-EVT22200007-00006f6c","pid":1258,"client":"0","":"downstairs","session_id":"67adfc74-d0c1-48bf-8681-fd972579c24e"}
5942025-05-27T21:20:58.817Z{"msg":"Waiting for more clients to be ready","v":0,"name":"crucible","level":30,"time":"2025-05-27T21:20:57.96174764Z","hostname":"bmat-EVT22200007-00006f6c","pid":1258,"session_id":"67adfc74-d0c1-48bf-8681-fd972579c24e"}
5952025-05-27T21:20:58.817Z{"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-05-27T21:20:57.961811026Z","hostname":"bmat-EVT22200007-00006f6c","pid":1258,"client":"1","":"downstairs","session_id":"67adfc74-d0c1-48bf-8681-fd972579c24e"}
5962025-05-27T21:20:58.817Z{"msg":"Waiting for more clients to be ready","v":0,"name":"crucible","level":30,"time":"2025-05-27T21:20:57.961960805Z","hostname":"bmat-EVT22200007-00006f6c","pid":1258,"session_id":"67adfc74-d0c1-48bf-8681-fd972579c24e"}
5972025-05-27T21:20:58.817Z{"msg":"[0]R flush_numbers: [5322, 5322, 5322, 5322, 5322]","v":0,"name":"crucible","level":30,"time":"2025-05-27T21:20:57.962246002Z","hostname":"bmat-EVT22200007-00006f6c","pid":1258,"":"downstairs","":"downstairs","session_id":"67adfc74-d0c1-48bf-8681-fd972579c24e"}
5982025-05-27T21:20:58.817Z{"msg":"[0]R generation: [32, 32, 32, 32, 32]","v":0,"name":"crucible","level":30,"time":"2025-05-27T21:20:57.962281884Z","hostname":"bmat-EVT22200007-00006f6c","pid":1258,"":"downstairs","":"downstairs","session_id":"67adfc74-d0c1-48bf-8681-fd972579c24e"}
5992025-05-27T21:20:58.817Z{"msg":"[0]R dirty: [false, false, false, false, false]","v":0,"name":"crucible","level":30,"time":"2025-05-27T21:20:57.962299709Z","hostname":"bmat-EVT22200007-00006f6c","pid":1258,"":"downstairs","":"downstairs","session_id":"67adfc74-d0c1-48bf-8681-fd972579c24e"}
6002025-05-27T21:20:58.817Z{"msg":"[1]R flush_numbers: [5322, 5322, 5322, 5322, 5322]","v":0,"name":"crucible","level":30,"time":"2025-05-27T21:20:57.962317204Z","hostname":"bmat-EVT22200007-00006f6c","pid":1258,"":"downstairs","":"downstairs","session_id":"67adfc74-d0c1-48bf-8681-fd972579c24e"}
6012025-05-27T21:20:58.817Z{"msg":"[1]R generation: [32, 32, 32, 32, 32]","v":0,"name":"crucible","level":30,"time":"2025-05-27T21:20:57.962333797Z","hostname":"bmat-EVT22200007-00006f6c","pid":1258,"":"downstairs","":"downstairs","session_id":"67adfc74-d0c1-48bf-8681-fd972579c24e"}
6022025-05-27T21:20:58.817Z{"msg":"[1]R dirty: [false, false, false, false, false]","v":0,"name":"crucible","level":30,"time":"2025-05-27T21:20:57.962478776Z","hostname":"bmat-EVT22200007-00006f6c","pid":1258,"":"downstairs","":"downstairs","session_id":"67adfc74-d0c1-48bf-8681-fd972579c24e"}
6032025-05-27T21:20:58.817Z{"msg":"[2]R flush_numbers: [5322, 5322, 5322, 5322, 5322]","v":0,"name":"crucible","level":30,"time":"2025-05-27T21:20:57.962534266Z","hostname":"bmat-EVT22200007-00006f6c","pid":1258,"":"downstairs","":"downstairs","session_id":"67adfc74-d0c1-48bf-8681-fd972579c24e"}
6042025-05-27T21:20:58.817Z{"msg":"[2]R generation: [32, 32, 32, 32, 32]","v":0,"name":"crucible","level":30,"time":"2025-05-27T21:20:57.962553725Z","hostname":"bmat-EVT22200007-00006f6c","pid":1258,"":"downstairs","":"downstairs","session_id":"67adfc74-d0c1-48bf-8681-fd972579c24e"}
6052025-05-27T21:20:58.817Z{"msg":"[2]R dirty: [false, false, false, false, false]","v":0,"name":"crucible","level":30,"time":"2025-05-27T21:20:57.962587432Z","hostname":"bmat-EVT22200007-00006f6c","pid":1258,"":"downstairs","":"downstairs","session_id":"67adfc74-d0c1-48bf-8681-fd972579c24e"}
6062025-05-27T21:20:58.817Z{"msg":"Max found gen is 33","v":0,"name":"crucible","level":30,"time":"2025-05-27T21:20:57.96260648Z","hostname":"bmat-EVT22200007-00006f6c","pid":1258,"":"downstairs","":"downstairs","session_id":"67adfc74-d0c1-48bf-8681-fd972579c24e"}
6072025-05-27T21:20:58.817Z{"msg":"Generation requested: 33 >= found:33","v":0,"name":"crucible","level":30,"time":"2025-05-27T21:20:57.962624746Z","hostname":"bmat-EVT22200007-00006f6c","pid":1258,"":"downstairs","":"downstairs","session_id":"67adfc74-d0c1-48bf-8681-fd972579c24e"}
6082025-05-27T21:20:58.817Z{"msg":"Next flush: 5323","v":0,"name":"crucible","level":30,"time":"2025-05-27T21:20:57.9626418Z","hostname":"bmat-EVT22200007-00006f6c","pid":1258,"":"downstairs","":"downstairs","session_id":"67adfc74-d0c1-48bf-8681-fd972579c24e"}
6092025-05-27T21:20:58.817Z{"msg":"All extents match","v":0,"name":"crucible","level":30,"time":"2025-05-27T21:20:57.962659055Z","hostname":"bmat-EVT22200007-00006f6c","pid":1258,"":"downstairs","":"downstairs","session_id":"67adfc74-d0c1-48bf-8681-fd972579c24e"}
6102025-05-27T21:20:58.817Z{"msg":"No downstairs reconciliation required","v":0,"name":"crucible","level":30,"time":"2025-05-27T21:20:57.962691008Z","hostname":"bmat-EVT22200007-00006f6c","pid":1258,"session_id":"67adfc74-d0c1-48bf-8681-fd972579c24e"}
6112025-05-27T21:20:58.817ZWait for a query_work_queue command to finish before sending IO
6122025-05-27T21:20:58.817Z{"msg":"Transition from WaitQuorum to Active","v":0,"name":"crucible","level":30,"time":"2025-05-27T21:20:57.962723603Z","hostname":"bmat-EVT22200007-00006f6c","pid":1258,"client":"0","":"downstairs","session_id":"67adfc74-d0c1-48bf-8681-fd972579c24e"}
6132025-05-27T21:20:58.817Z{"msg":"Transition from WaitQuorum to Active","v":0,"name":"crucible","level":30,"time":"2025-05-27T21:20:57.962743873Z","hostname":"bmat-EVT22200007-00006f6c","pid":1258,"client":"1","":"downstairs","session_id":"67adfc74-d0c1-48bf-8681-fd972579c24e"}
6142025-05-27T21:20:58.817Z{"msg":"Transition from WaitQuorum to Active","v":0,"name":"crucible","level":30,"time":"2025-05-27T21:20:57.962761679Z","hostname":"bmat-EVT22200007-00006f6c","pid":1258,"client":"2","":"downstairs","session_id":"67adfc74-d0c1-48bf-8681-fd972579c24e"}
6152025-05-27T21:20:58.817Z{"msg":"All required reconciliation work is completed","v":0,"name":"crucible","level":30,"time":"2025-05-27T21:20:57.962794264Z","hostname":"bmat-EVT22200007-00006f6c","pid":1258,"session_id":"67adfc74-d0c1-48bf-8681-fd972579c24e"}
6162025-05-27T21:20:58.817Z{"msg":"Set Downstairs and Upstairs active after reconciliation","v":0,"name":"crucible","level":30,"time":"2025-05-27T21:20:57.962813071Z","hostname":"bmat-EVT22200007-00006f6c","pid":1258,"session_id":"67adfc74-d0c1-48bf-8681-fd972579c24e"}
6172025-05-27T21:20:58.817Z{"msg":"40b123ad-686b-4fb0-bc14-130e449dda3d is now active with session: 67adfc74-d0c1-48bf-8681-fd972579c24e","v":0,"name":"crucible","level":30,"time":"2025-05-27T21:20:57.962831538Z","hostname":"bmat-EVT22200007-00006f6c","pid":1258,"session_id":"67adfc74-d0c1-48bf-8681-fd972579c24e"}
6182025-05-27T21:20:58.818Z{"msg":"Set Active after no reconciliation","v":0,"name":"crucible","level":30,"time":"2025-05-27T21:20:57.96286291Z","hostname":"bmat-EVT22200007-00006f6c","pid":1258,"session_id":"67adfc74-d0c1-48bf-8681-fd972579c24e"}
6192025-05-27T21:20:58.818Z{"msg":"The guest has finished waiting for activation with:33","v":0,"name":"crucible","level":30,"time":"2025-05-27T21:20:57.962879894Z","hostname":"bmat-EVT22200007-00006f6c","pid":1258}
6202025-05-27T21:20:58.818Z{"msg":"Activated sub_volume 40b123ad-686b-4fb0-bc14-130e449dda3d","v":0,"name":"crucible","level":30,"time":"2025-05-27T21:20:57.962895605Z","hostname":"bmat-EVT22200007-00006f6c","pid":1258}
6212025-05-27T21:20:58.818ZDisk: sv:2 bs:4096 ts:409600 tb:100 max_io:100 or 409600
6222025-05-27T21:20:58.818ZLoading write count information from file "/var/tmp/test_up-build/verify_file"
6232025-05-27T21:20:58.818ZRead and Verify all blocks (0..100 range:true)
6242025-05-27T21:20:58.852ZWrote out file "/var/tmp/test_up-build/verify_file"
6252025-05-27T21:20:58.852ZVerify test completed
6262025-05-27T21:20:58.877ZWrote out file "/var/tmp/test_up-build/verify_file"
6272025-05-27T21:20:58.877ZCLIENT: Tests done. All submitted work has been ACK'd
6282025-05-27T21:20:58.877Z----------------------------------------------------------------
6292025-05-27T21:20:58.877Z Crucible gen:33 GIO:true work queues: Upstairs:0 downstairs:1
6302025-05-27T21:20:58.877ZStates: Active Active Active
6312025-05-27T21:20:58.877ZJOBID ACK TYPE BKS/EXT DS:0 DS:1 DS:2 REPLAY
6322025-05-27T21:20:58.877Z 1000 Acked Read 50 Done Done Done false
6332025-05-27T21:20:58.877Z STATES DS:0 DS:1 DS:2 TOTAL
6342025-05-27T21:20:58.877Z Sent 0 0 0 0
6352025-05-27T21:20:58.877Z Done 1 1 1 3
6362025-05-27T21:20:58.877Z Skipped 0 0 0 0
6372025-05-27T21:20:58.877Z Error 0 0 0 0
6382025-05-27T21:20:58.877ZLast Flush: None None None
6392025-05-27T21:20:58.877ZDownstairs last five completed:
6402025-05-27T21:20:58.877ZUpstairs last five completed: 1000
6412025-05-27T21:20:58.877Z----------------------------------------------------------------
6422025-05-27T21:20:58.877Z Crucible gen:33 GIO:true work queues: Upstairs:0 downstairs:1
6432025-05-27T21:20:58.877ZStates: Active Active Active
6442025-05-27T21:20:58.877ZJOBID ACK TYPE BKS/EXT DS:0 DS:1 DS:2 REPLAY
6452025-05-27T21:20:58.877Z 1000 Acked Read 50 Done Done Done false
6462025-05-27T21:20:58.877Z STATES DS:0 DS:1 DS:2 TOTAL
6472025-05-27T21:20:58.877Z Sent 0 0 0 0
6482025-05-27T21:20:58.877Z Done 1 1 1 3
6492025-05-27T21:20:58.877Z Skipped 0 0 0 0
6502025-05-27T21:20:58.877Z Error 0 0 0 0
6512025-05-27T21:20:58.877ZLast Flush: None None None
6522025-05-27T21:20:58.877ZDownstairs last five completed:
6532025-05-27T21:20:58.877ZUpstairs last five completed: 1000
6542025-05-27T21:20:58.878ZCLIENT: Up:0 ds:2 act:6
6552025-05-27T21:21:02.854Z----------------------------------------------------------------
6562025-05-27T21:21:02.854Z Crucible gen:33 GIO:true work queues: Upstairs:0 downstairs:0
6572025-05-27T21:21:02.854ZDownstairs last five completed: 1001 1000
6582025-05-27T21:21:02.854ZUpstairs last five completed: 1001 1000
6592025-05-27T21:21:02.854Z----------------------------------------------------------------
6602025-05-27T21:21:02.854Z Crucible gen:33 GIO:true work queues: Upstairs:0 downstairs:0
6612025-05-27T21:21:02.854ZDownstairs last five completed: 1001 1000
6622025-05-27T21:21:02.854ZUpstairs last five completed: 1001 1000
6632025-05-27T21:21:02.855ZCLIENT: Up:0 ds:0 act:6
6642025-05-27T21:21:02.855ZCLIENT: All crucible jobs finished, exiting program
6652025-05-27T21:21:02.880Z{"msg":"Guest handle has been dropped","v":0,"name":"crucible","level":40,"time":"2025-05-27T21:21:02.059112667Z","hostname":"bmat-EVT22200007-00006f6c","pid":1258}
6662025-05-27T21:21:02.880ZRepair part 2 passed
6672025-05-27T21:21:02.880Z/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
6682025-05-27T21:21:02.905ZEXT BLOCKS GEN0 GEN1 GEN2 FL0 FL1 FL2 D0 D1 D2 DIFF
6692025-05-27T21:21:02.905Z 0 000-009 32 32 32 4001 4001 4001 F F F
6702025-05-27T21:21:02.905Z 1 010-019 32 32 32 4001 4001 4001 F F F
6712025-05-27T21:21:02.905Z 2 020-029 32 32 32 4001 4001 4001 F F F
6722025-05-27T21:21:02.905Z 3 030-039 32 32 32 4001 4001 4001 F F F
6732025-05-27T21:21:02.905Z 4 040-049 32 32 32 4001 4001 4001 F F F
6742025-05-27T21:21:02.905ZMax gen: 32, Max flush: 4001
6752025-05-27T21:21:02.905Zdump test passed
6762025-05-27T21:21:02.905Z/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
6772025-05-27T21:21:02.930Z Extent 1
6782025-05-27T21:21:02.930ZGEN 32 32 32
6792025-05-27T21:21:02.930ZFLUSH_ID 4001 4001 4001
6802025-05-27T21:21:02.930ZDIRTY
6812025-05-27T21:21:02.930Z
6822025-05-27T21:21:02.930ZBLOCK D0 D1 D2 C0 C1 C2 DIFF
6832025-05-27T21:21:02.930Z010 A A A A A A
6842025-05-27T21:21:02.930Z011 A A A A A A
6852025-05-27T21:21:02.930Z012 A A A A A A
6862025-05-27T21:21:02.930Z013 A A A A A A
6872025-05-27T21:21:02.930Z014 A A A A A A
6882025-05-27T21:21:02.930Z015 A A A A A A
6892025-05-27T21:21:02.955Z016 A A A A A A
6902025-05-27T21:21:02.955Z017 A A A A A A
6912025-05-27T21:21:02.955Z018 A A A A A A
6922025-05-27T21:21:02.955Z019 A A A A A A
6932025-05-27T21:21:02.955Zdump extent test passed
6942025-05-27T21:21:02.955Z/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
6952025-05-27T21:21:02.981ZExtent 2 Block in extent 0 Actual block 20
6962025-05-27T21:21:02.981Z
6972025-05-27T21:21:02.981Z DATA SHA256 VER
6982025-05-27T21:21:02.981Z------ ---------------------------------------------------------------- ---
6992025-05-27T21:21:02.981Z 0 d109a66aa383e053921a151c1ef049841efb6b74f9d5b2f3b25e4d657dad9d9c A
7002025-05-27T21:21:02.981Z 1 d109a66aa383e053921a151c1ef049841efb6b74f9d5b2f3b25e4d657dad9d9c A
7012025-05-27T21:21:02.981Z 2 d109a66aa383e053921a151c1ef049841efb6b74f9d5b2f3b25e4d657dad9d9c A
7022025-05-27T21:21:02.981Z
7032025-05-27T21:21:02.981ZNONCES 0 1 2 DIFF
7042025-05-27T21:21:02.981Z------ ------------------------ ------------------------ ------------------------ -----
7052025-05-27T21:21:02.981Z 0 a58590dce322dafbb6af5096 a58590dce322dafbb6af5096 a58590dce322dafbb6af5096
7062025-05-27T21:21:02.981Z
7072025-05-27T21:21:02.981Z TAGS 0 1 2 DIFF
7082025-05-27T21:21:02.981Z------ -------------------------------- -------------------------------- -------------------------------- -----
7092025-05-27T21:21:02.981Z 0 514f8c7aa6e9803462c57ebcb0f06ebd 514f8c7aa6e9803462c57ebcb0f06ebd 514f8c7aa6e9803462c57ebcb0f06ebd
7102025-05-27T21:21:02.981Z
7112025-05-27T21:21:02.981ZHASHES 0 1 2 DIFF
7122025-05-27T21:21:02.981Z------ ---------------- ---------------- ---------------- -----
7132025-05-27T21:21:02.981Z
7142025-05-27T21:21:02.981Zdump block test passed
7152025-05-27T21:21:02.981ZInitial upstairs tests have completed, stopping all downstairs
7162025-05-27T21:21:08.062ZCreating 7 larger downstairs regions
7172025-05-27T21:21:08.582ZStarting 7 downstairs
7182025-05-27T21:21:13.606Zdsc restarted at PID: 1274
7192025-05-27T21:21:14.120ZNow do the replace-reconcile test
7202025-05-27T21:21:14.194ZUsing 8870 for the replacement port
7212025-05-27T21:24:42.122ZCompleted test: replace-reconcile
7222025-05-27T21:24:42.122ZNow do the replace-before-active test
7232025-05-27T21:29:44.412ZCompleted test: replace-before-active
7242025-05-27T21:29:44.412ZAll tests have completed, stopping all downstairs
7252025-05-27T21:29:44.488Z
7262025-05-27T21:29:44.488ZAll Tests have passed
7272025-05-27T21:29:44.488Z16:44 Test duration
7282025-05-27T21:29:44.488Z
7292025-05-27T21:29:44.488Zreal 16:44.202602105
7302025-05-27T21:29:44.488Zuser 32:09.861596743
7312025-05-27T21:29:44.488Zsys 51.347663914
7322025-05-27T21:29:44.488Ztrap 1.095067448
7332025-05-27T21:29:44.488Ztflt 0.083191345
7342025-05-27T21:29:44.488Zdflt 0.119932962
7352025-05-27T21:29:44.488Zkflt 0.020596348
7362025-05-27T21:29:44.488Zlock 29:45:31.645387873
7372025-05-27T21:29:44.488Zslp 1:27:07.632009495
7382025-05-27T21:29:44.488Zlat 4:39.075094280
7392025-05-27T21:29:44.488Zstop 0.222749000
7402025-05-27T21:29:44.488Z+ echo 'test-up-2region-encrypted ends'
7412025-05-27T21:29:44.488Ztest-up-2region-encrypted ends
7422025-05-27T21:29:49.492Zprocess exited: duration 1014865 ms, exit code 0
7432025-05-27T21:29:49.492Zexec warning: : stdio descriptors remain open after task exit; waiting 60 seconds for them to close
7442025-05-27T21:30:49.507Zexec warning: : stdout descriptor may be held open by a background process; giving up!
7452025-05-27T21:30:49.507Zexec warning: : stderr descriptor may be held open by a background process; giving up!
 
7462025-05-27T21:30:49.587Zfound 17 output files
7472025-05-27T21:30:49.587Zuploading: /tmp/test_up-build/dsc-out.txt (52860 bytes)
7482025-05-27T21:30:50.753Zuploaded: /tmp/test_up-build/dsc-out.txt
7492025-05-27T21:30:50.753Zuploading: /tmp/test_up-build/test_up_out.txt (18445963 bytes)
7502025-05-27T21:30:58.260Zuploaded: /tmp/test_up-build/test_up_out.txt
7512025-05-27T21:30:58.260Zuploading: /tmp/test_up-build/dsc/downstairs-8810.txt (543458 bytes)
7522025-05-27T21:30:59.496Zuploaded: /tmp/test_up-build/dsc/downstairs-8810.txt
7532025-05-27T21:30:59.496Zuploading: /tmp/test_up-build/dsc/downstairs-8820.txt (540962 bytes)
7542025-05-27T21:31:00.730Zuploaded: /tmp/test_up-build/dsc/downstairs-8820.txt
7552025-05-27T21:31:00.730Zuploading: /tmp/test_up-build/dsc/downstairs-8830.txt (971321 bytes)
7562025-05-27T21:31:02.060Zuploaded: /tmp/test_up-build/dsc/downstairs-8830.txt
7572025-05-27T21:31:02.060Zuploading: /tmp/test_up-build/dsc/downstairs-8840.txt (535765 bytes)
7582025-05-27T21:31:03.281Zuploaded: /tmp/test_up-build/dsc/downstairs-8840.txt
7592025-05-27T21:31:03.281Zuploading: /tmp/test_up-build/dsc/downstairs-8850.txt (2464 bytes)
7602025-05-27T21:31:04.378Zuploaded: /tmp/test_up-build/dsc/downstairs-8850.txt
7612025-05-27T21:31:04.403Zuploading: /tmp/test_up-build/dsc/downstairs-8860.txt (33363 bytes)
7622025-05-27T21:31:05.476Zuploaded: /tmp/test_up-build/dsc/downstairs-8860.txt
7632025-05-27T21:31:05.476Zuploading: /tmp/test_up-build/dsc/downstairs-8870.txt (3530990 bytes)
7642025-05-27T21:31:07.459Zuploaded: /tmp/test_up-build/dsc/downstairs-8870.txt
7652025-05-27T21:31:07.459Zuploading: /tmp/debug/df.txt (1270 bytes)
7662025-05-27T21:31:08.561Zuploaded: /tmp/debug/df.txt
7672025-05-27T21:31:08.561Zuploading: /tmp/debug/dtrace.txt (1345364 bytes)
7682025-05-27T21:31:08.972Zupload warning: file "/tmp/debug/dtrace.txt" changed size mid upload: 1345364 -> 1482953
7692025-05-27T21:31:10.046Zuploaded: /tmp/debug/dtrace.txt
7702025-05-27T21:31:10.046Zuploading: /tmp/debug/iostat.txt (389608 bytes)
7712025-05-27T21:31:10.210Zupload warning: file "/tmp/debug/iostat.txt" changed size mid upload: 389608 -> 396888
7722025-05-27T21:31:11.283Zuploaded: /tmp/debug/iostat.txt
7732025-05-27T21:31:11.283Zuploading: /tmp/debug/mpstat.txt (775771 bytes)
7742025-05-27T21:31:11.532Zupload warning: file "/tmp/debug/mpstat.txt" changed size mid upload: 775771 -> 791721
7752025-05-27T21:31:12.606Zuploaded: /tmp/debug/mpstat.txt
7762025-05-27T21:31:12.631Zuploading: /tmp/debug/paging.txt (135676 bytes)
7772025-05-27T21:31:12.681Zupload warning: file "/tmp/debug/paging.txt" changed size mid upload: 135676 -> 138703
7782025-05-27T21:31:13.754Zuploaded: /tmp/debug/paging.txt
7792025-05-27T21:31:13.780Zuploading: /tmp/debug/prstat.txt (1536369 bytes)
7802025-05-27T21:31:14.199Zupload warning: file "/tmp/debug/prstat.txt" changed size mid upload: 1536369 -> 1567389
7812025-05-27T21:31:15.272Zuploaded: /tmp/debug/prstat.txt
7822025-05-27T21:31:15.272Zuploading: /tmp/debug/psrinfo.txt (1528 bytes)
7832025-05-27T21:31:16.369Zuploaded: /tmp/debug/psrinfo.txt
7842025-05-27T21:31:16.369Zuploading: /tmp/debug/upstairs-info.txt (226710 bytes)
7852025-05-27T21:31:17.534Zuploaded: /tmp/debug/upstairs-info.txt