01JEW0KXEFA5RD22T81YD3YPNW: test-up-unencrypted

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: 01JEW0M6DHEJZFGQ6HHRND371C

Tags:

Artefacts:

Output:

SEQ GLOBAL TIME DETAILS
12024-12-11T23:38:59.951Zjob dependencies complete; ready to run (waiting for 14 m 9 s)
22024-12-11T23:40:55.208Zjob assigned to worker 01JEW1EFDAGT0RY7YPFWJAPQ1M [factory aws, i-073a8c8a2410b63d2] (queued for 1 m 55 s)
32024-12-11T23:41:08.757Zdownloading input: /input/build/work/bins/crucible-downstairs.gz
42024-12-11T23:41:09.861Zdownloaded input: /input/build/work/bins/crucible-downstairs.gz
52024-12-11T23:41:09.861Zdownloading input: /input/build/work/bins/crucible-hammer.gz
62024-12-11T23:41:10.911Zdownloaded input: /input/build/work/bins/crucible-hammer.gz
72024-12-11T23:41:10.911Zdownloading input: /input/build/work/bins/crutest.gz
82024-12-11T23:41:12.009Zdownloaded input: /input/build/work/bins/crutest.gz
92024-12-11T23:41:12.009Zdownloading input: /input/build/work/bins/dsc.gz
102024-12-11T23:41:12.682Zdownloaded input: /input/build/work/bins/dsc.gz
112024-12-11T23:41:12.685Zdownloading input: /input/build/work/scripts/perf-downstairs-tick.d
122024-12-11T23:41:12.699Zdownloaded input: /input/build/work/scripts/perf-downstairs-tick.d
132024-12-11T23:41:12.699Zdownloading input: /input/build/work/scripts/test_ds.sh
142024-12-11T23:41:12.715Zdownloaded input: /input/build/work/scripts/test_ds.sh
152024-12-11T23:41:12.715Zdownloading input: /input/build/work/scripts/test_live_repair.sh
162024-12-11T23:41:12.731Zdownloaded input: /input/build/work/scripts/test_live_repair.sh
172024-12-11T23:41:12.731Zdownloading input: /input/build/work/scripts/test_repair.sh
182024-12-11T23:41:12.765Zdownloaded input: /input/build/work/scripts/test_repair.sh
192024-12-11T23:41:12.765Zdownloading input: /input/build/work/scripts/test_replay.sh
202024-12-11T23:41:12.782Zdownloaded input: /input/build/work/scripts/test_replay.sh
212024-12-11T23:41:12.782Zdownloading input: /input/build/work/scripts/test_up.sh
222024-12-11T23:41:12.804Zdownloaded input: /input/build/work/scripts/test_up.sh
232024-12-11T23:41:12.804Zdownloading input: /input/build/work/scripts/upstairs_info.d
242024-12-11T23:41:12.823Zdownloaded input: /input/build/work/scripts/upstairs_info.d
252024-12-11T23:41:12.826Zdownloading input: /input/build/tmp/cargo-test-out.log
262024-12-11T23:41:13.543Zdownloaded input: /input/build/tmp/cargo-test-out.log
 
272024-12-11T23:41:13.544Zstarting task 0: "setup"
282024-12-11T23:41:13.552Z++ uname -s
292024-12-11T23:41:13.554Z+ kern=SunOS
302024-12-11T23:41:13.554Z+ case "$kern" in
312024-12-11T23:41:13.554Z+ groupadd -g 12345 build
322024-12-11T23:41:13.557Z+ useradd -u 12345 -g build -d /home/build -s /bin/bash -c build -P 'Primary Administrator' build
332024-12-11T23:41:15.564Z+ zfs create -o mountpoint=/work rpool/work
342024-12-11T23:41:19.727Z++ awk '$2 == "/home" { print $3 }' /etc/mnttab
352024-12-11T23:41:19.730Z+ home_fs=zfs
362024-12-11T23:41:19.730Z+ [[ zfs == autofs ]]
372024-12-11T23:41:19.730Z+ mkdir -p /home/build
382024-12-11T23:41:19.732Z+ chown build:build /home/build /work
392024-12-11T23:41:19.735Z+ chmod 0700 /home/build /work
402024-12-11T23:41:19.737Zprocess exited: duration 6191 ms, exit code 0
 
412024-12-11T23:41:19.742Zstarting task 1: "authentication"
422024-12-11T23:41:19.758Zprocess exited: duration 16 ms, exit code 0
 
432024-12-11T23:41:19.763Zstarting task 2: "build"
442024-12-11T23:41:19.768Z+ banner cores
452024-12-11T23:41:19.856Z
462024-12-11T23:41:19.856Z #### #### ##### ###### ####
472024-12-11T23:41:19.856Z # # # # # # # #
482024-12-11T23:41:19.856Z # # # # # ##### ####
492024-12-11T23:41:19.856Z # # # ##### # #
502024-12-11T23:41:19.856Z # # # # # # # # #
512024-12-11T23:41:19.856Z #### #### # # ###### ####
522024-12-11T23:41:19.856Z
532024-12-11T23:41:19.858Z+ pfexec coreadm -i /tmp/core.%f.%p -g /tmp/core.%f.%p -e global -e log -e proc-setid -e global-setid
542024-12-11T23:41:19.863Z+ echo 'input bins dir contains:'
552024-12-11T23:41:19.863Zinput bins dir contains:
562024-12-11T23:41:19.866Z+ ls -ltr /input/build/work/bins
572024-12-11T23:41:19.866Ztotal 760636
582024-12-11T23:41:19.866Z-rw-r--r-- 1 root root 109276510 Dec 11 23:41 crucible-downstairs.gz
592024-12-11T23:41:19.866Z-rw-r--r-- 1 root root 104518811 Dec 11 23:41 crucible-hammer.gz
602024-12-11T23:41:19.866Z-rw-r--r-- 1 root root 108906373 Dec 11 23:41 crutest.gz
612024-12-11T23:41:19.866Z-rw-r--r-- 1 root root 66480704 Dec 11 23:41 dsc.gz
622024-12-11T23:41:19.866Z+ banner unpack
632024-12-11T23:41:19.868Z
642024-12-11T23:41:19.868Z # # # # ##### ## #### # #
652024-12-11T23:41:19.868Z # # ## # # # # # # # # #
662024-12-11T23:41:19.868Z # # # # # # # # # # ####
672024-12-11T23:41:19.868Z # # # # # ##### ###### # # #
682024-12-11T23:41:19.869Z # # # ## # # # # # # #
692024-12-11T23:41:19.869Z #### # # # # # #### # #
702024-12-11T23:41:19.869Z
712024-12-11T23:41:19.869Z+ mkdir -p /var/tmp/bins
722024-12-11T23:41:19.871Z+ for t in "$input/bins/"*.gz
732024-12-11T23:41:19.871Z++ basename /input/build/work/bins/crucible-downstairs.gz
742024-12-11T23:41:19.874Z+ b=crucible-downstairs.gz
752024-12-11T23:41:19.874Z+ b=crucible-downstairs
762024-12-11T23:41:19.874Z+ gunzip
772024-12-11T23:41:22.112Z+ chmod +x /var/tmp/bins/crucible-downstairs
782024-12-11T23:41:22.115Z+ for t in "$input/bins/"*.gz
792024-12-11T23:41:22.117Z++ basename /input/build/work/bins/crucible-hammer.gz
802024-12-11T23:41:22.117Z+ b=crucible-hammer.gz
812024-12-11T23:41:22.117Z+ b=crucible-hammer
822024-12-11T23:41:22.117Z+ gunzip
832024-12-11T23:41:24.297Z+ chmod +x /var/tmp/bins/crucible-hammer
842024-12-11T23:41:24.300Z+ for t in "$input/bins/"*.gz
852024-12-11T23:41:24.300Z++ basename /input/build/work/bins/crutest.gz
862024-12-11T23:41:24.302Z+ b=crutest.gz
872024-12-11T23:41:24.302Z+ b=crutest
882024-12-11T23:41:24.302Z+ gunzip
892024-12-11T23:41:26.498Z+ chmod +x /var/tmp/bins/crutest
902024-12-11T23:41:26.501Z+ for t in "$input/bins/"*.gz
912024-12-11T23:41:26.503Z++ basename /input/build/work/bins/dsc.gz
922024-12-11T23:41:26.503Z+ b=dsc.gz
932024-12-11T23:41:26.503Z+ b=dsc
942024-12-11T23:41:26.503Z+ gunzip
952024-12-11T23:41:27.910Z+ chmod +x /var/tmp/bins/dsc
962024-12-11T23:41:27.912Z+ export BINDIR=/var/tmp/bins
972024-12-11T23:41:27.912Z+ BINDIR=/var/tmp/bins
982024-12-11T23:41:27.912Z+ jobpid=1146
992024-12-11T23:41:27.912Z+ echo 'Setup debug logging'
1002024-12-11T23:41:27.912ZSetup debug logging
1012024-12-11T23:41:27.912Z+ mkdir /tmp/debug
1022024-12-11T23:41:27.915Z+ sleep 7200
1032024-12-11T23:41:27.915Z+ psrinfo -v
1042024-12-11T23:41:27.918Z+ df -h
1052024-12-11T23:41:28.092Z+ prstat -d d -mLc 1
1062024-12-11T23:41:28.094Z+ iostat -T d -xn 1
1072024-12-11T23:41:28.094Z+ mpstat -T d 1
1082024-12-11T23:41:28.095Z+ vmstat -T d -p 1
1092024-12-11T23:41:28.095Z+ pfexec dtrace -Z -s /input/build/work/scripts/perf-downstairs-tick.d
1102024-12-11T23:41:28.097Z+ banner test_up_unencrypted
1112024-12-11T23:41:28.097Z+ pfexec dtrace -Z -s /input/build/work/scripts/upstairs_info.d
1122024-12-11T23:41:28.097Z
1132024-12-11T23:41:28.097Z ##### ###### #### ##### # # ##### # # # #
1142024-12-11T23:41:28.097Z # # # # # # # # # # ## #
1152024-12-11T23:41:28.097Z # ##### #### # # # # # # # # # #
1162024-12-11T23:41:28.097Z # # # # # # ##### # # # # #
1172024-12-11T23:41:28.097Z # # # # # # # # # # # ##
1182024-12-11T23:41:28.097Z # ###### #### # ####### #### # ####### #### # #
1192024-12-11T23:41:28.098Z
1202024-12-11T23:41:28.098Z+ ptime -m bash /input/build/work/scripts/test_up.sh -N unencrypted
1212024-12-11T23:41:28.108Z/input/build/work
1222024-12-11T23:41:28.268ZTurn off color for downstairs dump
1232024-12-11T23:41:28.270Zdsc output goes to /tmp/test_up-build/dsc-out.txt
1242024-12-11T23:41:28.271ZCreating 3 downstairs regions
1252024-12-11T23:41:28.706ZStarting 3 downstairs
1262024-12-11T23:41:28.710Zdsc started at PID: 1191
1272024-12-11T23:41:33.891ZDisable automatic restart on all downstairs
1282024-12-11T23:41:33.942Z
1292024-12-11T23:41:33.942ZBegin tests, output goes to /tmp/test_up-build/test_up_out.txt
1302024-12-11T23:41:33.946ZRunning test: span
1312024-12-11T23:41:38.052ZCompleted test: span
1322024-12-11T23:41:43.061ZRunning test: big
1332024-12-11T23:41:47.204ZCompleted test: big
1342024-12-11T23:41:52.213ZRunning test: dep
1352024-12-11T23:42:04.831ZCompleted test: dep
1362024-12-11T23:42:09.840ZRunning test: balloon
1372024-12-11T23:42:19.450ZCompleted test: balloon
1382024-12-11T23:42:24.459ZRunning test: deactivate
1392024-12-11T23:43:18.682ZCompleted test: deactivate
1402024-12-11T23:43:23.690ZRunning hammer
1412024-12-11T23:43:26.578ZRun repair tests
1422024-12-11T23:43:26.582Z/var/tmp/bins/crutest fill -g 31 -q --dsc 127.0.0.1:9998 --verify-out /var/tmp/test_up-build/verify_file
1432024-12-11T23:43:26.640Z{"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":"2024-12-11T23:43:26.467392658Z","hostname":"w-01JEW1EFDAGT0RY7YPFWJAPQ1M","pid":1228,"task":"crutest"}
1442024-12-11T23:43:26.642Z{"msg":"dsc has 3 regions. This means 1 sub_volumes","v":0,"name":"crucible","level":30,"time":"2024-12-11T23:43:26.467946869Z","hostname":"w-01JEW1EFDAGT0RY7YPFWJAPQ1M","pid":1228,"task":"crutest"}
1452024-12-11T23:43:26.642Z{"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":"2024-12-11T23:43:26.46961033Z","hostname":"w-01JEW1EFDAGT0RY7YPFWJAPQ1M","pid":1228,"task":"crutest"}
1462024-12-11T23:43:26.642Z{"msg":"Upstairs starts","v":0,"name":"crucible","level":30,"time":"2024-12-11T23:43:26.469833619Z","hostname":"w-01JEW1EFDAGT0RY7YPFWJAPQ1M","pid":1228}
1472024-12-11T23:43:26.643Z{"msg":"Crucible Version: BuildInfo {\n version: \"0.0.1\",\n git_sha: \"d81f7fe7d3a87a2a3c58f4f5d619f7f37b0a05d0\",\n git_commit_timestamp: \"2024-12-11T23:24:14.000000000Z\",\n git_branch: \"mkeeter/separate-notify-task\",\n rustc_semver: \"1.82.0\",\n rustc_channel: \"stable\",\n rustc_host_triple: \"x86_64-unknown-illumos\",\n rustc_commit_sha: \"f6e511eec7342f59a25f7c0534f1dbea00d01b14\",\n cargo_triple: \"x86_64-unknown-illumos\",\n debug: true,\n opt_level: 0,\n}","v":0,"name":"crucible","level":30,"time":"2024-12-11T23:43:26.469873445Z","hostname":"w-01JEW1EFDAGT0RY7YPFWJAPQ1M","pid":1228}
1482024-12-11T23:43:26.643Z{"msg":"Upstairs <-> Downstairs Message Version: 12","v":0,"name":"crucible","level":30,"time":"2024-12-11T23:43:26.469888829Z","hostname":"w-01JEW1EFDAGT0RY7YPFWJAPQ1M","pid":1228}
1492024-12-11T23:43:26.643Z{"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: false, database_read_version: 1, database_write_version: 1 }","v":0,"name":"crucible","level":30,"time":"2024-12-11T23:43:26.469904994Z","hostname":"w-01JEW1EFDAGT0RY7YPFWJAPQ1M","pid":1228}
1502024-12-11T23:43:26.646Z{"msg":"Crucible b70ba46c-a95f-4243-81c2-346fe9fc0477 has session id: 1e9b7b3e-9d26-4d96-b2b3-5f52ff256857","v":0,"name":"crucible","level":30,"time":"2024-12-11T23:43:26.470337438Z","hostname":"w-01JEW1EFDAGT0RY7YPFWJAPQ1M","pid":1228,"session_id":"1e9b7b3e-9d26-4d96-b2b3-5f52ff256857"}
1512024-12-11T23:43:26.646Z{"msg":"Upstairs opts: Upstairs UUID: b70ba46c-a95f-4243-81c2-346fe9fc0477, Targets: [127.0.0.1:8810, 127.0.0.1:8820, 127.0.0.1:8830], lossy: false, flush_timeout: None, key populated: false, 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":"2024-12-11T23:43:26.470387Z","hostname":"w-01JEW1EFDAGT0RY7YPFWJAPQ1M","pid":1228,"session_id":"1e9b7b3e-9d26-4d96-b2b3-5f52ff256857"}
1522024-12-11T23:43:26.646Z{"msg":"Crucible stats registered with UUID: b70ba46c-a95f-4243-81c2-346fe9fc0477","v":0,"name":"crucible","level":30,"time":"2024-12-11T23:43:26.470404794Z","hostname":"w-01JEW1EFDAGT0RY7YPFWJAPQ1M","pid":1228,"session_id":"1e9b7b3e-9d26-4d96-b2b3-5f52ff256857"}
1532024-12-11T23:43:26.646Z{"msg":"could not find Downstairs address for Nexus","v":0,"name":"crucible","level":40,"time":"2024-12-11T23:43:26.470418518Z","hostname":"w-01JEW1EFDAGT0RY7YPFWJAPQ1M","pid":1228,"session_id":"1e9b7b3e-9d26-4d96-b2b3-5f52ff256857"}
1542024-12-11T23:43:26.646Z{"msg":"Downstairs in volume = 3","v":0,"name":"crucible","level":30,"time":"2024-12-11T23:43:26.471378133Z","hostname":"w-01JEW1EFDAGT0RY7YPFWJAPQ1M","pid":1228,"task":"crutest"}
1552024-12-11T23:43:26.646Z{"msg":"The guest has requested activation with gen:31","v":0,"name":"crucible","level":30,"time":"2024-12-11T23:43:26.471422847Z","hostname":"w-01JEW1EFDAGT0RY7YPFWJAPQ1M","pid":1228}
1562024-12-11T23:43:26.646Z{"msg":"b70ba46c-a95f-4243-81c2-346fe9fc0477 active request set","v":0,"name":"crucible","level":30,"time":"2024-12-11T23:43:26.471444849Z","hostname":"w-01JEW1EFDAGT0RY7YPFWJAPQ1M","pid":1228,"session_id":"1e9b7b3e-9d26-4d96-b2b3-5f52ff256857"}
1572024-12-11T23:43:26.646Z{"msg":"sending connect oneshot to client","v":0,"name":"crucible","level":30,"time":"2024-12-11T23:43:26.471472899Z","hostname":"w-01JEW1EFDAGT0RY7YPFWJAPQ1M","pid":1228,"client":"0","":"downstairs","session_id":"1e9b7b3e-9d26-4d96-b2b3-5f52ff256857"}
1582024-12-11T23:43:26.646Z{"msg":"client set_active_request while in New; waiting...","v":0,"name":"crucible","level":30,"time":"2024-12-11T23:43:26.471534257Z","hostname":"w-01JEW1EFDAGT0RY7YPFWJAPQ1M","pid":1228,"client":"0","":"downstairs","session_id":"1e9b7b3e-9d26-4d96-b2b3-5f52ff256857"}
1592024-12-11T23:43:26.646Z{"msg":"sending connect oneshot to client","v":0,"name":"crucible","level":30,"time":"2024-12-11T23:43:26.471576612Z","hostname":"w-01JEW1EFDAGT0RY7YPFWJAPQ1M","pid":1228,"client":"1","":"downstairs","session_id":"1e9b7b3e-9d26-4d96-b2b3-5f52ff256857"}
1602024-12-11T23:43:26.646Z{"msg":"client set_active_request while in New; waiting...","v":0,"name":"crucible","level":30,"time":"2024-12-11T23:43:26.471615817Z","hostname":"w-01JEW1EFDAGT0RY7YPFWJAPQ1M","pid":1228,"client":"1","":"downstairs","session_id":"1e9b7b3e-9d26-4d96-b2b3-5f52ff256857"}
1612024-12-11T23:43:26.647Z{"msg":"sending connect oneshot to client","v":0,"name":"crucible","level":30,"time":"2024-12-11T23:43:26.471655553Z","hostname":"w-01JEW1EFDAGT0RY7YPFWJAPQ1M","pid":1228,"client":"2","":"downstairs","session_id":"1e9b7b3e-9d26-4d96-b2b3-5f52ff256857"}
1622024-12-11T23:43:26.647Z{"msg":"client set_active_request while in New; waiting...","v":0,"name":"crucible","level":30,"time":"2024-12-11T23:43:26.471684183Z","hostname":"w-01JEW1EFDAGT0RY7YPFWJAPQ1M","pid":1228,"client":"2","":"downstairs","session_id":"1e9b7b3e-9d26-4d96-b2b3-5f52ff256857"}
1632024-12-11T23:43:26.647Z{"msg":"connecting to 127.0.0.1:8830","v":0,"name":"crucible","level":30,"time":"2024-12-11T23:43:26.471710283Z","hostname":"w-01JEW1EFDAGT0RY7YPFWJAPQ1M","pid":1228,"":"io task","client":"2","":"downstairs","session_id":"1e9b7b3e-9d26-4d96-b2b3-5f52ff256857"}
1642024-12-11T23:43:26.647Z{"msg":"connecting to 127.0.0.1:8820","v":0,"name":"crucible","level":30,"time":"2024-12-11T23:43:26.47174667Z","hostname":"w-01JEW1EFDAGT0RY7YPFWJAPQ1M","pid":1228,"":"io task","client":"1","":"downstairs","session_id":"1e9b7b3e-9d26-4d96-b2b3-5f52ff256857"}
1652024-12-11T23:43:26.647Z{"msg":"connecting to 127.0.0.1:8810","v":0,"name":"crucible","level":30,"time":"2024-12-11T23:43:26.471770502Z","hostname":"w-01JEW1EFDAGT0RY7YPFWJAPQ1M","pid":1228,"":"io task","client":"0","":"downstairs","session_id":"1e9b7b3e-9d26-4d96-b2b3-5f52ff256857"}
1662024-12-11T23:43:26.647Z{"msg":"ds_connection connected from Ok(127.0.0.1:57400)","v":0,"name":"crucible","level":30,"time":"2024-12-11T23:43:26.471800411Z","hostname":"w-01JEW1EFDAGT0RY7YPFWJAPQ1M","pid":1228,"":"io task","client":"2","":"downstairs","session_id":"1e9b7b3e-9d26-4d96-b2b3-5f52ff256857"}
1672024-12-11T23:43:26.647Z{"msg":"ds_connection connected from Ok(127.0.0.1:40814)","v":0,"name":"crucible","level":30,"time":"2024-12-11T23:43:26.471825982Z","hostname":"w-01JEW1EFDAGT0RY7YPFWJAPQ1M","pid":1228,"":"io task","client":"0","":"downstairs","session_id":"1e9b7b3e-9d26-4d96-b2b3-5f52ff256857"}
1682024-12-11T23:43:26.647Z{"msg":"ds_connection connected from Ok(127.0.0.1:49312)","v":0,"name":"crucible","level":30,"time":"2024-12-11T23:43:26.471889579Z","hostname":"w-01JEW1EFDAGT0RY7YPFWJAPQ1M","pid":1228,"":"io task","client":"1","":"downstairs","session_id":"1e9b7b3e-9d26-4d96-b2b3-5f52ff256857"}
1692024-12-11T23:43:26.647Z{"msg":"ds_transition from New to WaitActive","v":0,"name":"crucible","level":30,"time":"2024-12-11T23:43:26.472439671Z","hostname":"w-01JEW1EFDAGT0RY7YPFWJAPQ1M","pid":1228,"client":"0","":"downstairs","session_id":"1e9b7b3e-9d26-4d96-b2b3-5f52ff256857"}
1702024-12-11T23:43:26.647Z{"msg":"[0] Transition from New to WaitActive","v":0,"name":"crucible","level":30,"time":"2024-12-11T23:43:26.472477747Z","hostname":"w-01JEW1EFDAGT0RY7YPFWJAPQ1M","pid":1228,"client":"0","":"downstairs","session_id":"1e9b7b3e-9d26-4d96-b2b3-5f52ff256857"}
1712024-12-11T23:43:26.647Z{"msg":"ds_transition from New to WaitActive","v":0,"name":"crucible","level":30,"time":"2024-12-11T23:43:26.472494721Z","hostname":"w-01JEW1EFDAGT0RY7YPFWJAPQ1M","pid":1228,"client":"1","":"downstairs","session_id":"1e9b7b3e-9d26-4d96-b2b3-5f52ff256857"}
1722024-12-11T23:43:26.647Z{"msg":"[1] Transition from New to WaitActive","v":0,"name":"crucible","level":30,"time":"2024-12-11T23:43:26.472509585Z","hostname":"w-01JEW1EFDAGT0RY7YPFWJAPQ1M","pid":1228,"client":"1","":"downstairs","session_id":"1e9b7b3e-9d26-4d96-b2b3-5f52ff256857"}
1732024-12-11T23:43:26.647Z{"msg":"ds_transition from New to WaitActive","v":0,"name":"crucible","level":30,"time":"2024-12-11T23:43:26.472545263Z","hostname":"w-01JEW1EFDAGT0RY7YPFWJAPQ1M","pid":1228,"client":"2","":"downstairs","session_id":"1e9b7b3e-9d26-4d96-b2b3-5f52ff256857"}
1742024-12-11T23:43:26.647Z{"msg":"[2] Transition from New to WaitActive","v":0,"name":"crucible","level":30,"time":"2024-12-11T23:43:26.472576591Z","hostname":"w-01JEW1EFDAGT0RY7YPFWJAPQ1M","pid":1228,"client":"2","":"downstairs","session_id":"1e9b7b3e-9d26-4d96-b2b3-5f52ff256857"}
1752024-12-11T23:43:26.650Z{"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":"2024-12-11T23:43:26.473110889Z","hostname":"w-01JEW1EFDAGT0RY7YPFWJAPQ1M","pid":1228,"client":"0","":"downstairs","session_id":"1e9b7b3e-9d26-4d96-b2b3-5f52ff256857"}
1762024-12-11T23:43:26.650Z{"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":"2024-12-11T23:43:26.47316258Z","hostname":"w-01JEW1EFDAGT0RY7YPFWJAPQ1M","pid":1228,"client":"1","":"downstairs","session_id":"1e9b7b3e-9d26-4d96-b2b3-5f52ff256857"}
1772024-12-11T23:43:26.650Z{"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":"2024-12-11T23:43:26.473194099Z","hostname":"w-01JEW1EFDAGT0RY7YPFWJAPQ1M","pid":1228,"client":"2","":"downstairs","session_id":"1e9b7b3e-9d26-4d96-b2b3-5f52ff256857"}
1782024-12-11T23:43:26.650Z{"msg":"ds_transition from WaitActive to WaitQuorum","v":0,"name":"crucible","level":30,"time":"2024-12-11T23:43:26.473494801Z","hostname":"w-01JEW1EFDAGT0RY7YPFWJAPQ1M","pid":1228,"client":"0","":"downstairs","session_id":"1e9b7b3e-9d26-4d96-b2b3-5f52ff256857"}
1792024-12-11T23:43:26.650Z{"msg":"[0] Transition from WaitActive to WaitQuorum","v":0,"name":"crucible","level":30,"time":"2024-12-11T23:43:26.473535056Z","hostname":"w-01JEW1EFDAGT0RY7YPFWJAPQ1M","pid":1228,"client":"0","":"downstairs","session_id":"1e9b7b3e-9d26-4d96-b2b3-5f52ff256857"}
1802024-12-11T23:43:26.650Z{"msg":"Waiting for more clients to be ready","v":0,"name":"crucible","level":30,"time":"2024-12-11T23:43:26.473561937Z","hostname":"w-01JEW1EFDAGT0RY7YPFWJAPQ1M","pid":1228,"session_id":"1e9b7b3e-9d26-4d96-b2b3-5f52ff256857"}
1812024-12-11T23:43:26.650Z{"msg":"ds_transition from WaitActive to WaitQuorum","v":0,"name":"crucible","level":30,"time":"2024-12-11T23:43:26.473592136Z","hostname":"w-01JEW1EFDAGT0RY7YPFWJAPQ1M","pid":1228,"client":"1","":"downstairs","session_id":"1e9b7b3e-9d26-4d96-b2b3-5f52ff256857"}
1822024-12-11T23:43:26.650Z{"msg":"[1] Transition from WaitActive to WaitQuorum","v":0,"name":"crucible","level":30,"time":"2024-12-11T23:43:26.473614228Z","hostname":"w-01JEW1EFDAGT0RY7YPFWJAPQ1M","pid":1228,"client":"1","":"downstairs","session_id":"1e9b7b3e-9d26-4d96-b2b3-5f52ff256857"}
1832024-12-11T23:43:26.650Z{"msg":"Waiting for more clients to be ready","v":0,"name":"crucible","level":30,"time":"2024-12-11T23:43:26.473638279Z","hostname":"w-01JEW1EFDAGT0RY7YPFWJAPQ1M","pid":1228,"session_id":"1e9b7b3e-9d26-4d96-b2b3-5f52ff256857"}
1842024-12-11T23:43:26.650Z{"msg":"ds_transition from WaitActive to WaitQuorum","v":0,"name":"crucible","level":30,"time":"2024-12-11T23:43:26.473654323Z","hostname":"w-01JEW1EFDAGT0RY7YPFWJAPQ1M","pid":1228,"client":"2","":"downstairs","session_id":"1e9b7b3e-9d26-4d96-b2b3-5f52ff256857"}
1852024-12-11T23:43:26.650Z{"msg":"[2] Transition from WaitActive to WaitQuorum","v":0,"name":"crucible","level":30,"time":"2024-12-11T23:43:26.473687271Z","hostname":"w-01JEW1EFDAGT0RY7YPFWJAPQ1M","pid":1228,"client":"2","":"downstairs","session_id":"1e9b7b3e-9d26-4d96-b2b3-5f52ff256857"}
1862024-12-11T23:43:26.650Z{"msg":"[0]R flush_numbers: [1501, 1501, 1501, 1501, 1501]","v":0,"name":"crucible","level":30,"time":"2024-12-11T23:43:26.47371963Z","hostname":"w-01JEW1EFDAGT0RY7YPFWJAPQ1M","pid":1228,"":"downstairs","":"downstairs","session_id":"1e9b7b3e-9d26-4d96-b2b3-5f52ff256857"}
1872024-12-11T23:43:26.650Z{"msg":"[0]R generation: [25, 25, 25, 25, 25]","v":0,"name":"crucible","level":30,"time":"2024-12-11T23:43:26.473753298Z","hostname":"w-01JEW1EFDAGT0RY7YPFWJAPQ1M","pid":1228,"":"downstairs","":"downstairs","session_id":"1e9b7b3e-9d26-4d96-b2b3-5f52ff256857"}
1882024-12-11T23:43:26.650Z{"msg":"[0]R dirty: [false, false, false, false, false]","v":0,"name":"crucible","level":30,"time":"2024-12-11T23:43:26.473786326Z","hostname":"w-01JEW1EFDAGT0RY7YPFWJAPQ1M","pid":1228,"":"downstairs","":"downstairs","session_id":"1e9b7b3e-9d26-4d96-b2b3-5f52ff256857"}
1892024-12-11T23:43:26.650Z{"msg":"[1]R flush_numbers: [1501, 1501, 1501, 1501, 1501]","v":0,"name":"crucible","level":30,"time":"2024-12-11T23:43:26.473821423Z","hostname":"w-01JEW1EFDAGT0RY7YPFWJAPQ1M","pid":1228,"":"downstairs","":"downstairs","session_id":"1e9b7b3e-9d26-4d96-b2b3-5f52ff256857"}
1902024-12-11T23:43:26.650Z{"msg":"[1]R generation: [25, 25, 25, 25, 25]","v":0,"name":"crucible","level":30,"time":"2024-12-11T23:43:26.473853632Z","hostname":"w-01JEW1EFDAGT0RY7YPFWJAPQ1M","pid":1228,"":"downstairs","":"downstairs","session_id":"1e9b7b3e-9d26-4d96-b2b3-5f52ff256857"}
1912024-12-11T23:43:26.650Z{"msg":"[1]R dirty: [false, false, false, false, false]","v":0,"name":"crucible","level":30,"time":"2024-12-11T23:43:26.473869176Z","hostname":"w-01JEW1EFDAGT0RY7YPFWJAPQ1M","pid":1228,"":"downstairs","":"downstairs","session_id":"1e9b7b3e-9d26-4d96-b2b3-5f52ff256857"}
1922024-12-11T23:43:26.650Z{"msg":"[2]R flush_numbers: [1501, 1501, 1501, 1501, 1501]","v":0,"name":"crucible","level":30,"time":"2024-12-11T23:43:26.473882871Z","hostname":"w-01JEW1EFDAGT0RY7YPFWJAPQ1M","pid":1228,"":"downstairs","":"downstairs","session_id":"1e9b7b3e-9d26-4d96-b2b3-5f52ff256857"}
1932024-12-11T23:43:26.650Z{"msg":"[2]R generation: [25, 25, 25, 25, 25]","v":0,"name":"crucible","level":30,"time":"2024-12-11T23:43:26.473898315Z","hostname":"w-01JEW1EFDAGT0RY7YPFWJAPQ1M","pid":1228,"":"downstairs","":"downstairs","session_id":"1e9b7b3e-9d26-4d96-b2b3-5f52ff256857"}
1942024-12-11T23:43:26.650Z{"msg":"[2]R dirty: [false, false, false, false, false]","v":0,"name":"crucible","level":30,"time":"2024-12-11T23:43:26.473923736Z","hostname":"w-01JEW1EFDAGT0RY7YPFWJAPQ1M","pid":1228,"":"downstairs","":"downstairs","session_id":"1e9b7b3e-9d26-4d96-b2b3-5f52ff256857"}
1952024-12-11T23:43:26.650Z{"msg":"Max found gen is 26","v":0,"name":"crucible","level":30,"time":"2024-12-11T23:43:26.473937851Z","hostname":"w-01JEW1EFDAGT0RY7YPFWJAPQ1M","pid":1228,"":"downstairs","":"downstairs","session_id":"1e9b7b3e-9d26-4d96-b2b3-5f52ff256857"}
1962024-12-11T23:43:26.650Z{"msg":"Generation requested: 31 >= found:26","v":0,"name":"crucible","level":30,"time":"2024-12-11T23:43:26.473990792Z","hostname":"w-01JEW1EFDAGT0RY7YPFWJAPQ1M","pid"Wait for a query_work_queue command to finish before sending IO
1972024-12-11T23:43:26.650Z:1228,"":"downstairs","":"downstairs","session_id":"1e9b7b3e-9d26-4d96-b2b3-5f52ff256857"}
1982024-12-11T23:43:26.650Z{"msg":"Next flush: 1502","v":0,"name":"crucible","level":30,"time":"2024-12-11T23:43:26.474038595Z","hostname":"w-01JEW1EFDAGT0RY7YPFWJAPQ1M","pid":1228,"":"downstairs","":"downstairs","session_id":"1e9b7b3e-9d26-4d96-b2b3-5f52ff256857"}
1992024-12-11T23:43:26.650Z{"msg":"All extents match","v":0,"name":"crucible","level":30,"time":"2024-12-11T23:43:26.474072782Z","hostname":"w-01JEW1EFDAGT0RY7YPFWJAPQ1M","pid":1228,"":"downstairs","":"downstairs","session_id":"1e9b7b3e-9d26-4d96-b2b3-5f52ff256857"}
2002024-12-11T23:43:26.650Z{"msg":"No downstairs reconciliation required","v":0,"name":"crucible","level":30,"time":"2024-12-11T23:43:26.474113598Z","hostname":"w-01JEW1EFDAGT0RY7YPFWJAPQ1M","pid":1228,"session_id":"1e9b7b3e-9d26-4d96-b2b3-5f52ff256857"}
2012024-12-11T23:43:26.650Z{"msg":"Transition from WaitQuorum to Active","v":0,"name":"crucible","level":30,"time":"2024-12-11T23:43:26.474145496Z","hostname":"w-01JEW1EFDAGT0RY7YPFWJAPQ1M","pid":1228,"client":"0","":"downstairs","session_id":"1e9b7b3e-9d26-4d96-b2b3-5f52ff256857"}
2022024-12-11T23:43:26.650Z{"msg":"Transition from WaitQuorum to Active","v":0,"name":"crucible","level":30,"time":"2024-12-11T23:43:26.474168198Z","hostname":"w-01JEW1EFDAGT0RY7YPFWJAPQ1M","pid":1228,"client":"1","":"downstairs","session_id":"1e9b7b3e-9d26-4d96-b2b3-5f52ff256857"}
2032024-12-11T23:43:26.650Z{"msg":"Transition from WaitQuorum to Active","v":0,"name":"crucible","level":30,"time":"2024-12-11T23:43:26.474199517Z","hostname":"w-01JEW1EFDAGT0RY7YPFWJAPQ1M","pid":1228,"client":"2","":"downstairs","session_id":"1e9b7b3e-9d26-4d96-b2b3-5f52ff256857"}
2042024-12-11T23:43:26.651Z{"msg":"All required reconciliation work is completed","v":0,"name":"crucible","level":30,"time":"2024-12-11T23:43:26.47421944Z","hostname":"w-01JEW1EFDAGT0RY7YPFWJAPQ1M","pid":1228,"session_id":"1e9b7b3e-9d26-4d96-b2b3-5f52ff256857"}
2052024-12-11T23:43:26.651Z{"msg":"Set Downstairs and Upstairs active after reconciliation","v":0,"name":"crucible","level":30,"time":"2024-12-11T23:43:26.474248329Z","hostname":"w-01JEW1EFDAGT0RY7YPFWJAPQ1M","pid":1228,"session_id":"1e9b7b3e-9d26-4d96-b2b3-5f52ff256857"}
2062024-12-11T23:43:26.651Z{"msg":"b70ba46c-a95f-4243-81c2-346fe9fc0477 is now active with session: 1e9b7b3e-9d26-4d96-b2b3-5f52ff256857"Disk: sv:1 bs:4096 ts:204800 tb:50 max_io:50 or 204800
2072024-12-11T23:43:26.651Z,"v":0,"name":"crucible","level":30,"time":"2024-12-11T23:43:26.474278319Z","hostname":"w-01JEW1EFDAGT0RY7YPFWJAPQ1M","pid":1228,"session_id":"1e9b7b3e-9d26-4d96-b2b3-5f52ff256857"}
2082024-12-11T23:43:26.651Z{"msg":"Set Active after no reconciliation","v":0,"Fill test
2092024-12-11T23:43:26.651Zname":"crucible","level":30,"time":"2024-12-11T23:43:26.474303419Z","hostname":"w-01JEW1EFDAGT0RY7YPFWJAPQ1M","pid":1228,"session_id":"1e9b7b3e-9d26-4d96-b2b3-5f52ff256857"}
2102024-12-11T23:43:26.651Z{"msg":"The guest has finished waiting for activation with:31","v":0,"name":"crucible","level":30,"time":"2024-12-11T23:43:26.474333959Z","hostname":"w-01JEW1EFDAGT0RY7YPFWJAPQ1M","pid":1228}
2112024-12-11T23:43:26.653ZRead and Verify all blocks (0..50 range:false)
2122024-12-11T23:43:26.658ZWrote out file "/var/tmp/test_up-build/verify_file"
2132024-12-11T23:43:26.658ZCLIENT: Tests done. All submitted work has been ACK'd
2142024-12-11T23:43:26.661Z----------------------------------------------------------------
2152024-12-11T23:43:26.661Z Crucible gen:31 GIO:true work queues: Upstairs:0 downstairs:1
2162024-12-11T23:43:26.661ZStates: Active Active Active
2172024-12-11T23:43:26.661ZJOBID ACK TYPE BKS/EXT DS:0 DS:1 DS:2 REPLAY
2182024-12-11T23:43:26.661Z 1002 Acked Read 50 Done Done Done false
2192024-12-11T23:43:26.661Z STATES DS:0 DS:1 DS:2 TOTAL
2202024-12-11T23:43:26.661Z Sent 0 0 0 0
2212024-12-11T23:43:26.661Z Done 1 1 1 3
2222024-12-11T23:43:26.661Z Skipped 0 0 0 0
2232024-12-11T23:43:26.661Z Error 0 0 0 0
2242024-12-11T23:43:26.661ZLast Flush: 1001 1001 1001
2252024-12-11T23:43:26.661ZDownstairs last five completed: 1001 1000
2262024-12-11T23:43:26.661ZUpstairs last five completed: 1002 1001 1000
2272024-12-11T23:43:26.661ZCLIENT: Up:0 ds:1 act:3
2282024-12-11T23:43:30.663Z----------------------------------------------------------------
2292024-12-11T23:43:30.663Z Crucible gen:31 GIO:true work queues: Upstairs:0 downstairs:0
2302024-12-11T23:43:30.663ZDownstairs last five completed: 1003 1002 1001 1000
2312024-12-11T23:43:30.663ZUpstairs last five completed: 1003 1002 1001 1000
2322024-12-11T23:43:30.663ZCLIENT: Up:0 ds:0 act:3
2332024-12-11T23:43:30.663ZCLIENT: All crucible jobs finished, exiting program
2342024-12-11T23:43:30.667Z{"msg":"Guest handle has been dropped","v":0,"name":"crucible","level":40,"time":"2024-12-11T23:43:30.487880678Z","hostname":"w-01JEW1EFDAGT0RY7YPFWJAPQ1M","pid":1228}
2352024-12-11T23:43:30.671ZRepair setup passed
2362024-12-11T23:43:30.675ZCopy the region for /var/tmp/test_up-build/8830
2372024-12-11T23:43:30.677Zcp -r /var/tmp/test_up-build/8830 /var/tmp/test_up-build/previous
2382024-12-11T23:43:30.680Z/var/tmp/bins/crutest fill -g 32 -q --dsc 127.0.0.1:9998 --verify-out /var/tmp/test_up-build/verify_file --verify-in /var/tmp/test_up-build/verify_file
2392024-12-11T23:43:30.736Z{"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":"2024-12-11T23:43:30.561945755Z","hostname":"w-01JEW1EFDAGT0RY7YPFWJAPQ1M","pid":1234,"task":"crutest"}
2402024-12-11T23:43:30.739Z{"msg":"dsc has 3 regions. This means 1 sub_volumes","v":0,"name":"crucible","level":30,"time":"2024-12-11T23:43:30.562538971Z","hostname":"w-01JEW1EFDAGT0RY7YPFWJAPQ1M","pid":1234,"task":"crutest"}
2412024-12-11T23:43:30.739Z{"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":"2024-12-11T23:43:30.564118562Z","hostname":"w-01JEW1EFDAGT0RY7YPFWJAPQ1M","pid":1234,"task":"crutest"}
2422024-12-11T23:43:30.739Z{"msg":"Upstairs starts","v":0,"name":"crucible","level":30,"time":"2024-12-11T23:43:30.564298088Z","hostname":"w-01JEW1EFDAGT0RY7YPFWJAPQ1M","pid":1234}
2432024-12-11T23:43:30.739Z{"msg":"Crucible Version: BuildInfo {\n version: \"0.0.1\",\n git_sha: \"d81f7fe7d3a87a2a3c58f4f5d619f7f37b0a05d0\",\n git_commit_timestamp: \"2024-12-11T23:24:14.000000000Z\",\n git_branch: \"mkeeter/separate-notify-task\",\n rustc_semver: \"1.82.0\",\n rustc_channel: \"stable\",\n rustc_host_triple: \"x86_64-unknown-illumos\",\n rustc_commit_sha: \"f6e511eec7342f59a25f7c0534f1dbea00d01b14\",\n cargo_triple: \"x86_64-unknown-illumos\",\n debug: true,\n opt_level: 0,\n}","v":0,"name":"crucible","level":30,"time":"2024-12-11T23:43:30.564338133Z","hostname":"w-01JEW1EFDAGT0RY7YPFWJAPQ1M","pid":1234}
2442024-12-11T23:43:30.739Z{"msg":"Upstairs <-> Downstairs Message Version: 12","v":0,"name":"crucible","level":30,"time":"2024-12-11T23:43:30.564370911Z","hostname":"w-01JEW1EFDAGT0RY7YPFWJAPQ1M","pid":1234}
2452024-12-11T23:43:30.739Z{"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: false, database_read_version: 1, database_write_version: 1 }","v":0,"name":"crucible","level":30,"time":"2024-12-11T23:43:30.564405269Z","hostname":"w-01JEW1EFDAGT0RY7YPFWJAPQ1M","pid":1234}
2462024-12-11T23:43:30.739Z{"msg":"Crucible a3b030ef-94d3-493b-b065-770be87e0fc2 has session id: 8d0df198-239a-4ff2-9b83-83a1baec1a71","v":0,"name":"crucible","level":30,"time":"2024-12-11T23:43:30.564756443Z","hostname":"w-01JEW1EFDAGT0RY7YPFWJAPQ1M","pid":1234,"session_id":"8d0df198-239a-4ff2-9b83-83a1baec1a71"}
2472024-12-11T23:43:30.739Z{"msg":"Upstairs opts: Upstairs UUID: a3b030ef-94d3-493b-b065-770be87e0fc2, Targets: [127.0.0.1:8810, 127.0.0.1:8820, 127.0.0.1:8830], lossy: false, flush_timeout: None, key populated: false, 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":"2024-12-11T23:43:30.564817901Z","hostname":"w-01JEW1EFDAGT0RY7YPFWJAPQ1M","pid":1234,"session_id":"8d0df198-239a-4ff2-9b83-83a1baec1a71"}
2482024-12-11T23:43:30.739Z{"msg":"Crucible stats registered with UUID: a3b030ef-94d3-493b-b065-770be87e0fc2","v":0,"name":"crucible","level":30,"time":"2024-12-11T23:43:30.564845371Z","hostname":"w-01JEW1EFDAGT0RY7YPFWJAPQ1M","pid":1234,"session_id":"8d0df198-239a-4ff2-9b83-83a1baec1a71"}
2492024-12-11T23:43:30.739Z{"msg":"could not find Downstairs address for Nexus","v":0,"name":"crucible","level":40,"time":"2024-12-11T23:43:30.564877629Z","hostname":"w-01JEW1EFDAGT0RY7YPFWJAPQ1M","pid":1234,"session_id":"8d0df198-239a-4ff2-9b83-83a1baec1a71"}
2502024-12-11T23:43:30.742Z{"msg":"Downstairs in volume = 3","v":0,"name":"crucible","level":30,"time":"2024-12-11T23:43:30.565705051Z","hostname":"w-01JEW1EFDAGT0RY7YPFWJAPQ1M","pid":1234,"task":"crutest"}
2512024-12-11T23:43:30.742Z{"msg":"The guest has requested activation with gen:32","v":0,"name":"crucible","level":30,"time":"2024-12-11T23:43:30.565756233Z","hostname":"w-01JEW1EFDAGT0RY7YPFWJAPQ1M","pid":1234}
2522024-12-11T23:43:30.743Z{"msg":"a3b030ef-94d3-493b-b065-770be87e0fc2 active request set","v":0,"name":"crucible","level":30,"time":"2024-12-11T23:43:30.565793679Z","hostname":"w-01JEW1EFDAGT0RY7YPFWJAPQ1M","pid":1234,"session_id":"8d0df198-239a-4ff2-9b83-83a1baec1a71"}
2532024-12-11T23:43:30.743Z{"msg":"sending connect oneshot to client","v":0,"name":"crucible","level":30,"time":"2024-12-11T23:43:30.565827977Z","hostname":"w-01JEW1EFDAGT0RY7YPFWJAPQ1M","pid":1234,"client":"0","":"downstairs","session_id":"8d0df198-239a-4ff2-9b83-83a1baec1a71"}
2542024-12-11T23:43:30.743Z{"msg":"client set_active_request while in New; waiting...","v":0,"name":"crucible","level":30,"time":"2024-12-11T23:43:30.565863564Z","hostname":"w-01JEW1EFDAGT0RY7YPFWJAPQ1M","pid":1234,"client":"0","":"downstairs","session_id":"8d0df198-239a-4ff2-9b83-83a1baec1a71"}
2552024-12-11T23:43:30.743Z{"msg":"sending connect oneshot to client","v":0,"name":"crucible","level":30,"time":"2024-12-11T23:43:30.565880148Z","hostname":"w-01JEW1EFDAGT0RY7YPFWJAPQ1M","pid":1234,"client":"1","":"downstairs","session_id":"8d0df198-239a-4ff2-9b83-83a1baec1a71"}
2562024-12-11T23:43:30.743Z{"msg":"client set_active_request while in New; waiting...","v":0,"name":"crucible","level":30,"time":"2024-12-11T23:43:30.565911637Z","hostname":"w-01JEW1EFDAGT0RY7YPFWJAPQ1M","pid":1234,"client":"1","":"downstairs","session_id":"8d0df198-239a-4ff2-9b83-83a1baec1a71"}
2572024-12-11T23:43:30.743Z{"msg":"sending connect oneshot to client","v":0,"name":"crucible","level":30,"time":"2024-12-11T23:43:30.565942306Z","hostname":"w-01JEW1EFDAGT0RY7YPFWJAPQ1M","pid":1234,"client":"2","":"downstairs","session_id":"8d0df198-239a-4ff2-9b83-83a1baec1a71"}
2582024-12-11T23:43:30.743Z{"msg":"client set_active_request while in New; waiting...","v":0,"name":"crucible","level":30,"time":"2024-12-11T23:43:30.565964308Z","hostname":"w-01JEW1EFDAGT0RY7YPFWJAPQ1M","pid":1234,"client":"2","":"downstairs","session_id":"8d0df198-239a-4ff2-9b83-83a1baec1a71"}
2592024-12-11T23:43:30.743Z{"msg":"connecting to 127.0.0.1:8830","v":0,"name":"crucible","level":30,"time":"2024-12-11T23:43:30.56598618Z","hostname":"w-01JEW1EFDAGT0RY7YPFWJAPQ1M","pid":1234,"":"io task","client":"2","":"downstairs","session_id":"8d0df198-239a-4ff2-9b83-83a1baec1a71"}
2602024-12-11T23:43:30.743Z{"msg":"connecting to 127.0.0.1:8810","v":0,"name":"crucible","level":30,"time":"2024-12-11T23:43:30.566008902Z","hostname":"w-01JEW1EFDAGT0RY7YPFWJAPQ1M","pid":1234,"":"io task","client":"0","":"downstairs","session_id":"8d0df198-239a-4ff2-9b83-83a1baec1a71"}
2612024-12-11T23:43:30.743Z{"msg":"connecting to 127.0.0.1:8820","v":0,"name":"crucible","level":30,"time":"2024-12-11T23:43:30.566051217Z","hostname":"w-01JEW1EFDAGT0RY7YPFWJAPQ1M","pid":1234,"":"io task","client":"1","":"downstairs","session_id":"8d0df198-239a-4ff2-9b83-83a1baec1a71"}
2622024-12-11T23:43:30.743Z{"msg":"ds_connection connected from Ok(127.0.0.1:54725)","v":0,"name":"crucible","level":30,"time":"2024-12-11T23:43:30.566317841Z","hostname":"w-01JEW1EFDAGT0RY7YPFWJAPQ1M","pid":1234,"":"io task","client":"1","":"downstairs","session_id":"8d0df198-239a-4ff2-9b83-83a1baec1a71"}
2632024-12-11T23:43:30.743Z{"msg":"ds_connection connected from Ok(127.0.0.1:64699)","v":0,"name":"crucible","level":30,"time":"2024-12-11T23:43:30.566376Z","hostname":"w-01JEW1EFDAGT0RY7YPFWJAPQ1M","pid":1234,"":"io task","client":"0","":"downstairs","session_id":"8d0df198-239a-4ff2-9b83-83a1baec1a71"}
2642024-12-11T23:43:30.743Z{"msg":"ds_connection connected from Ok(127.0.0.1:35953)","v":0,"name":"crucible","level":30,"time":"2024-12-11T23:43:30.566410457Z","hostname":"w-01JEW1EFDAGT0RY7YPFWJAPQ1M","pid":1234,"":"io task","client":"2","":"downstairs","session_id":"8d0df198-239a-4ff2-9b83-83a1baec1a71"}
2652024-12-11T23:43:30.743Z{"msg":"ds_transition from New to WaitActive","v":0,"name":"crucible","level":30,"time":"2024-12-11T23:43:30.566996036Z","hostname":"w-01JEW1EFDAGT0RY7YPFWJAPQ1M","pid":1234,"client":"1","":"downstairs","session_id":"8d0df198-239a-4ff2-9b83-83a1baec1a71"}
2662024-12-11T23:43:30.743Z{"msg":"[1] Transition from New to WaitActive","v":0,"name":"crucible","level":30,"time":"2024-12-11T23:43:30.567047078Z","hostname":"w-01JEW1EFDAGT0RY7YPFWJAPQ1M","pid":1234,"client":"1","":"downstairs","session_id":"8d0df198-239a-4ff2-9b83-83a1baec1a71"}
2672024-12-11T23:43:30.743Z{"msg":"ds_transition from New to WaitActive","v":0,"name":"crucible","level":30,"time":"2024-12-11T23:43:30.567080296Z","hostname":"w-01JEW1EFDAGT0RY7YPFWJAPQ1M","pid":1234,"client":"2","":"downstairs","session_id":"8d0df198-239a-4ff2-9b83-83a1baec1a71"}
2682024-12-11T23:43:30.743Z{"msg":"[2] Transition from New to WaitActive","v":0,"name":"crucible","level":30,"time":"2024-12-11T23:43:30.567121391Z","hostname":"w-01JEW1EFDAGT0RY7YPFWJAPQ1M","pid":1234,"client":"2","":"downstairs","session_id":"8d0df198-239a-4ff2-9b83-83a1baec1a71"}
2692024-12-11T23:43:30.743Z{"msg":"ds_transition from New to WaitActive","v":0,"name":"crucible","level":30,"time":"2024-12-11T23:43:30.567158308Z","hostname":"w-01JEW1EFDAGT0RY7YPFWJAPQ1M","pid":1234,"client":"0","":"downstairs","session_id":"8d0df198-239a-4ff2-9b83-83a1baec1a71"}
2702024-12-11T23:43:30.743Z{"msg":"[0] Transition from New to WaitActive","v":0,"name":"crucible","level":30,"time":"2024-12-11T23:43:30.567185618Z","hostname":"w-01JEW1EFDAGT0RY7YPFWJAPQ1M","pid":1234,"client":"0","":"downstairs","session_id":"8d0df198-239a-4ff2-9b83-83a1baec1a71"}
2712024-12-11T23:43:30.743Z{"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":"2024-12-11T23:43:30.567606257Z","hostname":"w-01JEW1EFDAGT0RY7YPFWJAPQ1M","pid":1234,"client":"1","":"downstairs","session_id":"8d0df198-239a-4ff2-9b83-83a1baec1a71"}
2722024-12-11T23:43:30.743Z{"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":"2024-12-11T23:43:30.56768113Z","hostname":"w-01JEW1EFDAGT0RY7YPFWJAPQ1M","pid":1234,"client":"2","":"downstairs","session_id":"8d0df198-239a-4ff2-9b83-83a1baec1a71"}
2732024-12-11T23:43:30.743Z{"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":"2024-12-11T23:43:30.567788161Z","hostname":"w-01JEW1EFDAGT0RY7YPFWJAPQ1M","pid":1234,"client":"0","":"downstairs","session_id":"8d0df198-239a-4ff2-9b83-83a1baec1a71"}
2742024-12-11T23:43:30.746Z{"msg":"ds_transition from WaitActive to WaitQuorum","v":0,"name":"crucible","level":30,"time":"2024-12-11T23:43:30.567966527Z","hostname":"w-01JEW1EFDAGT0RY7YPFWJAPQ1M","pid":1234,"client":"1","":"downstairs","session_id":"8d0df198-239a-4ff2-9b83-83a1baec1a71"}
2752024-12-11T23:43:30.746Z{"msg":"[1] Transition from WaitActive to WaitQuorum","v":0,"name":"crucible","level":30,"time":"2024-12-11T23:43:30.56801334Z","hostname":"w-01JEW1EFDAGT0RY7YPFWJAPQ1M","pid":1234,"client":"1","":"downstairs","session_id":"8d0df198-239a-4ff2-9b83-83a1baec1a71"}
2762024-12-11T23:43:30.746Z{"msg":"Waiting for more clients to be ready","v":0,"name":"crucible","level":30,"time":"2024-12-11T23:43:30.568029174Z","hostname":"w-01JEW1EFDAGT0RY7YPFWJAPQ1M","pid":1234,"session_id":"8d0df198-239a-4ff2-9b83-83a1baec1a71"}
2772024-12-11T23:43:30.746Z{"msg":"ds_transition from WaitActive to WaitQuorum","v":0,"name":"crucible","level":30,"time":"2024-12-11T23:43:30.568061533Z","hostname":"w-01JEW1EFDAGT0RY7YPFWJAPQ1M","pid":1234,"client":"2","":"downstairs","session_id":"8d0df198-239a-4ff2-9b83-83a1baec1a71"}
2782024-12-11T23:43:30.746Z{"msg":"[2] Transition from WaitActive to WaitQuorum","v":0,"name":"crucible","level":30,"time":"2024-12-11T23:43:30.568081935Z","hostname":"w-01JEW1EFDAGT0RY7YPFWJAPQ1M","pid":1234,"client":"2","":"downstairs","session_id":"8d0df198-239a-4ff2-9b83-83a1baec1a71"}
2792024-12-11T23:43:30.746Z{"msg":"Waiting for more clients to be ready","v":0,"name":"crucible","level":30,"time":"2024-12-11T23:43:30.568116633Z","hostname":"w-01JEW1EFDAGT0RY7YPFWJAPQ1M","pid":1234,"session_id":"8d0df198-239a-4ff2-9b83-83a1baec1a71"}
2802024-12-11T23:43:30.746Z{"msg":"ds_transition from WaitActive to WaitQuorum","v":0,"name":"crucible","level":30,"time":"2024-12-11T23:43:30.568140474Z","hostname":"w-01JEW1EFDAGT0RY7YPFWJAPQ1M","pid":1234,"client":"0","":"downstairs","session_id":"8d0df198-239a-4ff2-9b83-83a1baec1a71"}
2812024-12-11T23:43:30.746Z{"msg":"[0] Transition from WaitActive to WaitQuorum","v":0,"name":"crucible","level":30,"time":"2024-12-11T23:43:30.568170633Z","hostname":"w-01JEW1EFDAGT0RY7YPFWJAPQ1M","pid":1234,"client":"0","":"downstairs","session_id":"8d0df198-239a-4ff2-9b83-83a1baec1a71"}
2822024-12-11T23:43:30.746Z{"msg":"[0]R flush_numbers: [1502, 1502, 1502, 1502, 1502]","v":0,"name":"crucible","level":30,"time":"2024-12-11T23:43:30.568191846Z","hostname":"w-01JEW1EFDAGT0RY7YPFWJAPQ1M","pid":1234,"":"downstairs","":"downstairs","session_id":"8d0df198-239a-4ff2-9b83-83a1baec1a71"}
2832024-12-11T23:43:30.746Z{"msg":"[0]R generation: [31, 31, 31, 31, 31]","v":0,"name":"crucible","level":30,"time":"2024-12-11T23:43:30.568221735Z","hostname":"w-01JEW1EFDAGT0RY7YPFWJAPQ1M","pid":1234,"":"downstairs","":"downstairs","session_id":"8d0df198-239a-4ff2-9b83-83a1baec1a71"}
2842024-12-11T23:43:30.746Z{"msg":"[0]R dirty: [false, false, false, false, false]","v":0,"name":"crucible","level":30,"time":"2024-12-11T23:43:30.568242088Z","hostname":"w-01JEW1EFDAGT0RY7YPFWJAPQ1M","pid":1234,"":"downstairs","":"downstairs","session_id":"8d0df198-239a-4ff2-9b83-83a1baec1a71"}
2852024-12-11T23:43:30.746Z{"msg":"[1]R flush_numbers: [1502, 1502, 1502, 1502, 1502]","v":0,"name":"crucible","level":30,"time":"2024-12-11T23:43:30.568272896Z","hostname":"w-01JEW1EFDAGT0RY7YPFWJAPQ1M","pid":1234,"":"downstairs","":"downstairs","session_id":"8d0df198-239a-4ff2-9b83-83a1baec1a71"}
2862024-12-11T23:43:30.746Z{"msg":"[1]R generation: [31, 31, 31, 31, 31]","v":0,"name":"crucible","level":30,"time":"2024-12-11T23:43:30.56828918Z","hostname":"w-01JEW1EFDAGT0RY7YPFWJAPQ1M","pid":1234,"":"downstairs","":"downstairs","session_id":"8d0df198-239a-4ff2-9b83-83a1baec1a71"}
2872024-12-11T23:43:30.747ZWait for a query_work_queue command to finish before sending IO
2882024-12-11T23:43:30.747Z{"msg":"[1]R dirty: [false, false, false, false, false]","v":0,"name":"crucible","level":30,"time":"2024-12-11T23:43:30.568323578Z","hostname":"w-01JEW1EFDAGT0RY7YPFWJAPQ1M","pid":1234,"":"downstairs","":"downstairs","session_id":"8d0df198-239a-4ff2-9b83-83a1baec1a71"}
2892024-12-11T23:43:30.747Z{"msg":"[2]R flush_numbers: [1502, 1502, 1502, 1502, 1502]","v":0,"name":"crucible","level":30,"time":"2024-12-11T23:43:30.568347539Z","hostname":"w-01JEW1EFDAGT0RY7YPFWJAPQ1M","pid":1234,"":"downstairs","":"downstairs","session_id":"8d0df198-239a-4ff2-9b83-83a1baec1a71"}
2902024-12-11T23:43:30.747Z{"msg":"[2]R generation: [31, 31, 31, 31, 31]","v":0,"name":"crucible","level":30,"time":"2024-12-11T23:43:30.568376739Z","hostname":"w-01JEW1EFDAGT0RY7YPFWJAPQ1M","pid":1234,"":"downstairs","":"downstairs","session_id":"8d0df198-239a-4ff2-9b83-83a1baec1a71"}
2912024-12-11T23:43:30.747Z{"msg":"[2]R dirty: [false, false, false, false, false]","v":0,"name":"crucible","level":30,"time":"2024-12-11T23:43:30.568392003Z","hostname":"w-01JEW1EFDAGT0RY7YPFWJAPQ1M","pid":1234,"":"downstairs","":"downstairs","session_id":"8d0df198-239a-4ff2-9b83-83a1baec1a71"}
2922024-12-11T23:43:30.747Z{"msg":"Max found gen is 32","v":0,"name":"crucible","level":30,"time":"2024-12-11T23:43:30.568424232Z","hostname":"w-01JEW1EFDAGT0RY7YPFWJAPQ1M","pid":1234,"":"downstairs","":"downstairs","session_id":"8d0df198-239a-4ff2-9b83-83a1baec1a71"}
2932024-12-11T23:43:30.747Z{"msg":"Generation requested: 32 >= found:32","v":0,"name":"crucible","level":30,"time":"2024-12-11T23:43:30.568439906Z","hostname":"w-01JEW1EFDAGT0RY7YPFWJAPQ1M","pid":1234,"":"downstairs","":"downstairsDisk: sv:1 bs:4096 ts:204800 tb:50 max_io:50 or 204800
2942024-12-11T23:43:30.747Z","session_id":"8d0df198-239a-4ff2-9b83-83a1baec1a71"}
2952024-12-11T23:43:30.747Z{"msg":"Next flush: 1503","v":0,"name":"crucible","level":30,"time":"2024-12-11T23:43:30.568473284Z","hostname":"w-01JEW1EFDAGT0RY7YPFWJAPQ1M","pid":1234,"":"downstairs","":"downstairs","session_id":"8d0df198-239a-4ff2-9b83-83a1baec1a71"}
2962024-12-11T23:43:30.747Z{"msg":"All extents match","v":0,"name":"crucible","level":30,"time":"2024-12-11T23:43:30.568489418Z","hostname":"w-01JEW1EFDAGT0RY7YPFWJAPQ1M","pid":1234,"":"downstairs","":"downstairs","session_id":"8d0df198-239a-4ff2-9b83-83a1baec1a71"}
2972024-12-11T23:43:30.747Z{"msg":"No downstairs reconciliation required","v":0,"name":"crucible","level":30,"time":"2024-12-11T23:43:30.568521107Z","hostname":"w-01JEW1EFDAGT0RY7YPFWJAPQ1M","pid":1234,"session_id":"8d0df198-239a-4ff2-9b83-83a1baec1a71"}
2982024-12-11T23:43:30.747Z{"msg":"Transition from WaitQuorum to Active","v":0,"name":"crucible","level":30,"time":"2024-12-11T23:43:30.568538501Z","hostname":"w-01JEW1EFDAGT0RY7YPFWJAPQ1M","pid":1234,"client":"0","":"downstairs","session_id":"8d0df198-239a-4ff2-9b83-83a1baec1a71"}
2992024-12-11T23:43:30.747Z{"msg":"Transition from WaitQuorum to Active","v":0,"name":"crucible","level":30,"time":"2024-12-11T23:43:30.5685685Z","hostname":"w-01JEW1EFDAGT0RY7YPFWJAPQ1M","pid":1234,"client":"1","":"downstairs","session_id":"8d0df198-239a-4ff2-9b83-83a1baec1a71"}
3002024-12-11T23:43:30.747Z{"msg":"Transition from WaitQuorum to Active","v":0,"name":"crucible","level":30,"time":"2024-12-11T23:43:30.568589832Z","hostname":"w-01JEW1EFDAGT0RY7YPFWJAPQ1M","pid":1234,"client":"2","":"downstairs","session_id":"8d0df198-239a-4ff2-9b83-83a1baec1a71"}
3012024-12-11T23:43:30.747Z{"msg":"All required reconciliation work is completed","v":0,"name":"crucible","level":30,"time":"2024-12-11T23:43:30.568619252Z","hostname":"w-01JEW1EFDAGT0RY7YPFWJAPQ1M","pid":1234,"session_id":"8d0df198-239a-4ff2-9b83-83a1baec1a71"}
3022024-12-11T23:43:30.747Z{Loading write count information from file "/var/tmp/test_up-build/verify_file"
3032024-12-11T23:43:30.747Z"msg":"Set Downstairs and Upstairs active after reconciliation","v":0,"name":"crucible","level":30,"time":"2024-12-11T23:43:30.568649731Z","hostname":"w-01JEW1EFDAGT0RY7YPFWJAPQ1M","pid":1234,"session_id":"8d0df198-239a-4ff2-9b83-83a1baec1a71"}
3042024-12-11T23:43:30.747ZFill test
3052024-12-11T23:43:30.747Z{"msg":"a3b030ef-94d3-493b-b065-770be87e0fc2 is now active with session: 8d0df198-239a-4ff2-9b83-83a1baec1a71","v":0,"name":"crucible","level":30,"time":"2024-12-11T23:43:30.568682479Z","hostname":"w-01JEW1EFDAGT0RY7YPFWJAPQ1M","pid":1234,"session_id":"8d0df198-239a-4ff2-9b83-83a1baec1a71"}
3062024-12-11T23:43:30.747Z{"msg":"Set Active after no reconciliation","v":0,"name":"crucible","level":30,"time":"2024-12-11T23:43:30.568698743Z","hostname":"w-01JEW1EFDAGT0RY7YPFWJAPQ1M","pid":1234,"session_id":"8d0df198-239a-4ff2-9b83-83a1baec1a71"}
3072024-12-11T23:43:30.747Z{"msg":"The guest has finished waiting for activation with:32","v":0,"name":"crucible","level":30,"time":"2024-12-11T23:43:30.568720505Z","hostname":"w-01JEW1EFDAGT0RY7YPFWJAPQ1M","pid":1234}
3082024-12-11T23:43:30.750ZRead and Verify all blocks (0..50 range:false)
3092024-12-11T23:43:30.754ZWrote out file "/var/tmp/test_up-build/verify_file"
3102024-12-11T23:43:30.754ZCLIENT: Tests done. All submitted work has been ACK'd
3112024-12-11T23:43:30.758Z----------------------------------------------------------------
3122024-12-11T23:43:30.758Z Crucible gen:32 GIO:true work queues: Upstairs:0 downstairs:1
3132024-12-11T23:43:30.758ZStates: Active Active Active
3142024-12-11T23:43:30.758ZJOBID ACK TYPE BKS/EXT DS:0 DS:1 DS:2 REPLAY
3152024-12-11T23:43:30.758Z 1002 Acked Read 50 Done Done Done false
3162024-12-11T23:43:30.758Z STATES DS:0 DS:1 DS:2 TOTAL
3172024-12-11T23:43:30.758Z Sent 0 0 0 0
3182024-12-11T23:43:30.758Z Done 1 1 1 3
3192024-12-11T23:43:30.758Z Skipped 0 0 0 0
3202024-12-11T23:43:30.758Z Error 0 0 0 0
3212024-12-11T23:43:30.758ZLast Flush: 1001 1001 1001
3222024-12-11T23:43:30.758ZDownstairs last five completed: 1001 1000
3232024-12-11T23:43:30.758ZUpstairs last five completed: 1002 1001 1000
3242024-12-11T23:43:30.758ZCLIENT: Up:0 ds:1 act:3
3252024-12-11T23:43:34.756Z----------------------------------------------------------------
3262024-12-11T23:43:34.756Z Crucible gen:32 GIO:true work queues: Upstairs:0 downstairs:0
3272024-12-11T23:43:34.756ZDownstairs last five completed: 1003 1002 1001 1000
3282024-12-11T23:43:34.756ZUpstairs last five completed: 1003 1002 1001 1000
3292024-12-11T23:43:34.756ZCLIENT: Up:0 ds:0 act:3
3302024-12-11T23:43:34.756ZCLIENT: All crucible jobs finished, exiting program
3312024-12-11T23:43:34.759Z{"msg":"Guest handle has been dropped","v":0,"name":"crucible","level":40,"time":"2024-12-11T23:43:34.580743894Z","hostname":"w-01JEW1EFDAGT0RY7YPFWJAPQ1M","pid":1234}
3322024-12-11T23:43:34.762ZRepair part 1 passed
3332024-12-11T23:43:34.764Z
3342024-12-11T23:43:34.764ZKill the current downstairs
3352024-12-11T23:43:34.922ZDownstairs 2 stopped
3362024-12-11T23:43:34.922Zmv /var/tmp/test_up-build/8830 /var/tmp/test_up-build/new
3372024-12-11T23:43:34.925ZNow put back the original so we have a mismatch
3382024-12-11T23:43:34.925Zmv /var/tmp/test_up-build/previous /var/tmp/test_up-build/8830
3392024-12-11T23:43:34.928ZRestart downstairs with old directory
3402024-12-11T23:43:34.979Z/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
3412024-12-11T23:43:34.995ZEXT BLOCKS GEN0 GEN1 GEN2 FL0 FL1 FL2 D0 D1 D2 DIFF
3422024-12-11T23:43:34.997Z 0 000-009 32 32 31 1503 1503 1502 F F F <---
3432024-12-11T23:43:34.997Z 1 010-019 32 32 31 1503 1503 1502 F F F <---
3442024-12-11T23:43:34.997Z 2 020-029 32 32 31 1503 1503 1502 F F F <---
3452024-12-11T23:43:34.997Z 3 030-039 32 32 31 1503 1503 1502 F F F <---
3462024-12-11T23:43:34.997Z 4 040-049 32 32 31 1503 1503 1502 F F F <---
3472024-12-11T23:43:34.997ZMax gen: 32, Max flush: 1503
3482024-12-11T23:43:34.997ZError: Difference in extent metadata found!
3492024-12-11T23:43:35.000Zdump test found error as expected
3502024-12-11T23:43:35.000Z
3512024-12-11T23:43:35.000Z
3522024-12-11T23:43:35.000Z/var/tmp/bins/crutest verify --range -g 33 -q --dsc 127.0.0.1:9998 --verify-out /var/tmp/test_up-build/verify_file --verify-in /var/tmp/test_up-build/verify_file
3532024-12-11T23:43:35.057Z{"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":"2024-12-11T23:43:34.881047916Z","hostname":"w-01JEW1EFDAGT0RY7YPFWJAPQ1M","pid":1242,"task":"crutest"}
3542024-12-11T23:43:35.059Z{"msg":"dsc has 3 regions. This means 1 sub_volumes","v":0,"name":"crucible","level":30,"time":"2024-12-11T23:43:34.881603535Z","hostname":"w-01JEW1EFDAGT0RY7YPFWJAPQ1M","pid":1242,"task":"crutest"}
3552024-12-11T23:43:35.059Z{"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":"2024-12-11T23:43:34.883286769Z","hostname":"w-01JEW1EFDAGT0RY7YPFWJAPQ1M","pid":1242,"task":"crutest"}
3562024-12-11T23:43:35.060Z{"msg":"Upstairs starts","v":0,"name":"crucible","level":30,"time":"2024-12-11T23:43:34.883521185Z","hostname":"w-01JEW1EFDAGT0RY7YPFWJAPQ1M","pid":1242}
3572024-12-11T23:43:35.060Z{"msg":"Crucible Version: BuildInfo {\n version: \"0.0.1\",\n git_sha: \"d81f7fe7d3a87a2a3c58f4f5d619f7f37b0a05d0\",\n git_commit_timestamp: \"2024-12-11T23:24:14.000000000Z\",\n git_branch: \"mkeeter/separate-notify-task\",\n rustc_semver: \"1.82.0\",\n rustc_channel: \"stable\",\n rustc_host_triple: \"x86_64-unknown-illumos\",\n rustc_commit_sha: \"f6e511eec7342f59a25f7c0534f1dbea00d01b14\",\n cargo_triple: \"x86_64-unknown-illumos\",\n debug: true,\n opt_level: 0,\n}","v":0,"name":"crucible","level":30,"time":"2024-12-11T23:43:34.883560141Z","hostname":"w-01JEW1EFDAGT0RY7YPFWJAPQ1M","pid":1242}
3582024-12-11T23:43:35.060Z{"msg":"Upstairs <-> Downstairs Message Version: 12","v":0,"name":"crucible","level":30,"time":"2024-12-11T23:43:34.883583493Z","hostname":"w-01JEW1EFDAGT0RY7YPFWJAPQ1M","pid":1242}
3592024-12-11T23:43:35.060Z{"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: false, database_read_version: 1, database_write_version: 1 }","v":0,"name":"crucible","level":30,"time":"2024-12-11T23:43:34.883598887Z","hostname":"w-01JEW1EFDAGT0RY7YPFWJAPQ1M","pid":1242}
3602024-12-11T23:43:35.063Z{"msg":"Crucible 501dbabc-40d0-4e2b-afbd-58db0aa95971 has session id: e15bfd89-6497-4a4e-8b07-6d994b4b1bbe","v":0,"name":"crucible","level":30,"time":"2024-12-11T23:43:34.884121209Z","hostname":"w-01JEW1EFDAGT0RY7YPFWJAPQ1M","pid":1242,"session_id":"e15bfd89-6497-4a4e-8b07-6d994b4b1bbe"}
3612024-12-11T23:43:35.063Z{"msg":"Upstairs opts: Upstairs UUID: 501dbabc-40d0-4e2b-afbd-58db0aa95971, Targets: [127.0.0.1:8810, 127.0.0.1:8820, 127.0.0.1:8830], lossy: false, flush_timeout: None, key populated: false, 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":"2024-12-11T23:43:34.884166463Z","hostname":"w-01JEW1EFDAGT0RY7YPFWJAPQ1M","pid":1242,"session_id":"e15bfd89-6497-4a4e-8b07-6d994b4b1bbe"}
3622024-12-11T23:43:35.063Z{"msg":"Crucible stats registered with UUID: 501dbabc-40d0-4e2b-afbd-58db0aa95971","v":0,"name":"crucible","level":30,"time":"2024-12-11T23:43:34.884224442Z","hostname":"w-01JEW1EFDAGT0RY7YPFWJAPQ1M","pid":1242,"session_id":"e15bfd89-6497-4a4e-8b07-6d994b4b1bbe"}
3632024-12-11T23:43:35.063Z{"msg":"could not find Downstairs address for Nexus","v":0,"name":"crucible","level":40,"time":"2024-12-11T23:43:34.884262078Z","hostname":"w-01JEW1EFDAGT0RY7YPFWJAPQ1M","pid":1242,"session_id":"e15bfd89-6497-4a4e-8b07-6d994b4b1bbe"}
3642024-12-11T23:43:35.063Z{"msg":"Downstairs in volume = 3","v":0,"name":"crucible","level":30,"time":"2024-12-11T23:43:34.885207158Z","hostname":"w-01JEW1EFDAGT0RY7YPFWJAPQ1M","pid":1242,"task":"crutest"}
3652024-12-11T23:43:35.063Z{"msg":"The guest has requested activation with gen:33","v":0,"name":"crucible","level":30,"time":"2024-12-11T23:43:34.885275843Z","hostname":"w-01JEW1EFDAGT0RY7YPFWJAPQ1M","pid":1242}
3662024-12-11T23:43:35.063Z{"msg":"501dbabc-40d0-4e2b-afbd-58db0aa95971 active request set","v":0,"name":"crucible","level":30,"time":"2024-12-11T23:43:34.885308941Z","hostname":"w-01JEW1EFDAGT0RY7YPFWJAPQ1M","pid":1242,"session_id":"e15bfd89-6497-4a4e-8b07-6d994b4b1bbe"}
3672024-12-11T23:43:35.063Z{"msg":"sending connect oneshot to client","v":0,"name":"crucible","level":30,"time":"2024-12-11T23:43:34.885356724Z","hostname":"w-01JEW1EFDAGT0RY7YPFWJAPQ1M","pid":1242,"client":"0","":"downstairs","session_id":"e15bfd89-6497-4a4e-8b07-6d994b4b1bbe"}
3682024-12-11T23:43:35.063Z{"msg":"client set_active_request while in New; waiting...","v":0,"name":"crucible","level":30,"time":"2024-12-11T23:43:34.885429708Z","hostname":"w-01JEW1EFDAGT0RY7YPFWJAPQ1M","pid":1242,"client":"0","":"downstairs","session_id":"e15bfd89-6497-4a4e-8b07-6d994b4b1bbe"}
3692024-12-11T23:43:35.064Z{"msg":"sending connect oneshot to client","v":0,"name":"crucible","level":30,"time":"2024-12-11T23:43:34.885492105Z","hostname":"w-01JEW1EFDAGT0RY7YPFWJAPQ1M","pid":1242,"client":"1","":"downstairs","session_id":"e15bfd89-6497-4a4e-8b07-6d994b4b1bbe"}
3702024-12-11T23:43:35.064Z{"msg":"client set_active_request while in New; waiting...","v":0,"name":"crucible","level":30,"time":"2024-12-11T23:43:34.885552513Z","hostname":"w-01JEW1EFDAGT0RY7YPFWJAPQ1M","pid":1242,"client":"1","":"downstairs","session_id":"e15bfd89-6497-4a4e-8b07-6d994b4b1bbe"}
3712024-12-11T23:43:35.064Z{"msg":"sending connect oneshot to client","v":0,"name":"crucible","level":30,"time":"2024-12-11T23:43:34.885594229Z","hostname":"w-01JEW1EFDAGT0RY7YPFWJAPQ1M","pid":1242,"client":"2","":"downstairs","session_id":"e15bfd89-6497-4a4e-8b07-6d994b4b1bbe"}
3722024-12-11T23:43:35.064Z{"msg":"client set_active_request while in New; waiting...","v":0,"name":"crucible","level":30,"time":"2024-12-11T23:43:34.885634414Z","hostname":"w-01JEW1EFDAGT0RY7YPFWJAPQ1M","pid":1242,"client":"2","":"downstairs","session_id":"e15bfd89-6497-4a4e-8b07-6d994b4b1bbe"}
3732024-12-11T23:43:35.064Z{"msg":"connecting to 127.0.0.1:8810","v":0,"name":"crucible","level":30,"time":"2024-12-11T23:43:34.885659465Z","hostname":"w-01JEW1EFDAGT0RY7YPFWJAPQ1M","pid":1242,"":"io task","client":"0","":"downstairs","session_id":"e15bfd89-6497-4a4e-8b07-6d994b4b1bbe"}
3742024-12-11T23:43:35.064Z{"msg":"connecting to 127.0.0.1:8830","v":0,"name":"crucible","level":30,"time":"2024-12-11T23:43:34.885686175Z","hostname":"w-01JEW1EFDAGT0RY7YPFWJAPQ1M","pid":1242,"":"io task","client":"2","":"downstairs","session_id":"e15bfd89-6497-4a4e-8b07-6d994b4b1bbe"}
3752024-12-11T23:43:35.064Z{"msg":"connecting to 127.0.0.1:8820","v":0,"name":"crucible","level":30,"time":"2024-12-11T23:43:34.885713735Z","hostname":"w-01JEW1EFDAGT0RY7YPFWJAPQ1M","pid":1242,"":"io task","client":"1","":"downstairs","session_id":"e15bfd89-6497-4a4e-8b07-6d994b4b1bbe"}
3762024-12-11T23:43:35.064Z{"msg":"ds_connection connected from Ok(127.0.0.1:59221)","v":0,"name":"crucible","level":30,"time":"2024-12-11T23:43:34.885744694Z","hostname":"w-01JEW1EFDAGT0RY7YPFWJAPQ1M","pid":1242,"":"io task","client":"0","":"downstairs","session_id":"e15bfd89-6497-4a4e-8b07-6d994b4b1bbe"}
3772024-12-11T23:43:35.064Z{"msg":"ds_connection connected from Ok(127.0.0.1:57895)","v":0,"name":"crucible","level":30,"time":"2024-12-11T23:43:34.885778432Z","hostname":"w-01JEW1EFDAGT0RY7YPFWJAPQ1M","pid":1242,"":"io task","client":"1","":"downstairs","session_id":"e15bfd89-6497-4a4e-8b07-6d994b4b1bbe"}
3782024-12-11T23:43:35.064Z{"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":"2024-12-11T23:43:34.885814349Z","hostname":"w-01JEW1EFDAGT0RY7YPFWJAPQ1M","pid":1242,"":"io task","client":"2","":"downstairs","session_id":"e15bfd89-6497-4a4e-8b07-6d994b4b1bbe"}
3792024-12-11T23:43:35.064Z{"msg":"client task is sending Done(ConnectionFailed(Os { code: 146, kind: ConnectionRefused, message: \"Connection refused\" }))","v":0,"name":"crucible","level":40,"time":"2024-12-11T23:43:34.885892611Z","hostname":"w-01JEW1EFDAGT0RY7YPFWJAPQ1M","pid":1242,"":"io task","client":"2","":"downstairs","session_id":"e15bfd89-6497-4a4e-8b07-6d994b4b1bbe"}
3802024-12-11T23:43:35.064Z{"msg":"downstairs task for 2 stopped due to ConnectionFailed(Os { code: 146, kind: ConnectionRefused, message: \"Connection refused\" })","v":0,"name":"crucible","level":40,"time":"2024-12-11T23:43:34.885971793Z","hostname":"w-01JEW1EFDAGT0RY7YPFWJAPQ1M","pid":1242,"session_id":"e15bfd89-6497-4a4e-8b07-6d994b4b1bbe"}
3812024-12-11T23:43:35.064Z{"msg":"client task is exiting","v":0,"name":"crucible","level":30,"time":"2024-12-11T23:43:34.886023994Z","hostname":"w-01JEW1EFDAGT0RY7YPFWJAPQ1M","pid":1242,"":"io task","client":"2","":"downstairs","session_id":"e15bfd89-6497-4a4e-8b07-6d994b4b1bbe"}
3822024-12-11T23:43:35.064Z{"msg":"ds_transition from New to WaitActive","v":0,"name":"crucible","level":30,"time":"2024-12-11T23:43:34.886469183Z","hostname":"w-01JEW1EFDAGT0RY7YPFWJAPQ1M","pid":1242,"client":"0","":"downstairs","session_id":"e15bfd89-6497-4a4e-8b07-6d994b4b1bbe"}
3832024-12-11T23:43:35.064Z{"msg":"[0] Transition from New to WaitActive","v":0,"name":"crucible","level":30,"time":"2024-12-11T23:43:34.886500412Z","hostname":"w-01JEW1EFDAGT0RY7YPFWJAPQ1M","pid":1242,"client":"0","":"downstairs","session_id":"e15bfd89-6497-4a4e-8b07-6d994b4b1bbe"}
3842024-12-11T23:43:35.064Z{"msg":"ds_transition from New to WaitActive","v":0,"name":"crucible","level":30,"time":"2024-12-11T23:43:34.886516906Z","hostname":"w-01JEW1EFDAGT0RY7YPFWJAPQ1M","pid":1242,"client":"1","":"downstairs","session_id":"e15bfd89-6497-4a4e-8b07-6d994b4b1bbe"}
3852024-12-11T23:43:35.064Z{"msg":"[1] Transition from New to WaitActive","v":0,"name":"crucible","level":30,"time":"2024-12-11T23:43:34.886547865Z","hostname":"w-01JEW1EFDAGT0RY7YPFWJAPQ1M","pid":1242,"client":"1","":"downstairs","session_id":"e15bfd89-6497-4a4e-8b07-6d994b4b1bbe"}
3862024-12-11T23:43:35.064Z{"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":"2024-12-11T23:43:34.886993824Z","hostname":"w-01JEW1EFDAGT0RY7YPFWJAPQ1M","pid":1242,"client":"1","":"downstairs","session_id":"e15bfd89-6497-4a4e-8b07-6d994b4b1bbe"}
3872024-12-11T23:43:35.067Z{"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":"2024-12-11T23:43:34.887134564Z","hostname":"w-01JEW1EFDAGT0RY7YPFWJAPQ1M","pid":1242,"client":"0","":"downstairs","session_id":"e15bfd89-6497-4a4e-8b07-6d994b4b1bbe"}
3882024-12-11T23:43:35.067Z{"msg":"ds_transition from WaitActive to WaitQuorum","v":0,"name":"crucible","level":30,"time":"2024-12-11T23:43:34.887307901Z","hostname":"w-01JEW1EFDAGT0RY7YPFWJAPQ1M","pid":1242,"client":"1","":"downstairs","session_id":"e15bfd89-6497-4a4e-8b07-6d994b4b1bbe"}
3892024-12-11T23:43:35.067Z{"msg":"[1] Transition from WaitActive to WaitQuorum","v":0,"name":"crucible","level":30,"time":"2024-12-11T23:43:34.887346817Z","hostname":"w-01JEW1EFDAGT0RY7YPFWJAPQ1M","pid":1242,"client":"1","":"downstairs","session_id":"e15bfd89-6497-4a4e-8b07-6d994b4b1bbe"}
3902024-12-11T23:43:35.067Z{"msg":"Waiting for more clients to be ready","v":0,"name":"crucible","level":30,"time":"2024-12-11T23:43:34.887363961Z","hostname":"w-01JEW1EFDAGT0RY7YPFWJAPQ1M","pid":1242,"session_id":"e15bfd89-6497-4a4e-8b07-6d994b4b1bbe"}
3912024-12-11T23:43:35.067Z{"msg":"ds_transition from WaitActive to WaitQuorum","v":0,"name":"crucible","level":30,"time":"2024-12-11T23:43:34.887461926Z","hostname":"w-01JEW1EFDAGT0RY7YPFWJAPQ1M","pid":1242,"client":"0","":"downstairs","session_id":"e15bfd89-6497-4a4e-8b07-6d994b4b1bbe"}
3922024-12-11T23:43:35.067Z{"msg":"[0] Transition from WaitActive to WaitQuorum","v":0,"name":"crucible","level":30,"time":"2024-12-11T23:43:34.887489696Z","hostname":"w-01JEW1EFDAGT0RY7YPFWJAPQ1M","pid":1242,"client":"0","":"downstairs","session_id":"e15bfd89-6497-4a4e-8b07-6d994b4b1bbe"}
3932024-12-11T23:43:35.067Z{"msg":"Waiting for more clients to be ready","v":0,"name":"crucible","level":30,"time":"2024-12-11T23:43:34.88750492Z","hostname":"w-01JEW1EFDAGT0RY7YPFWJAPQ1M","pid":1242,"session_id":"e15bfd89-6497-4a4e-8b07-6d994b4b1bbe"}
3942024-12-11T23:43:45.066Z{"msg":"connecting to 127.0.0.1:8830","v":0,"name":"crucible","level":30,"time":"2024-12-11T23:43:44.886355184Z","hostname":"w-01JEW1EFDAGT0RY7YPFWJAPQ1M","pid":1242,"":"io task","client":"2","":"downstairs","session_id":"e15bfd89-6497-4a4e-8b07-6d994b4b1bbe"}
3952024-12-11T23:43:45.066Z{"msg":"ds_connection connected from Ok(127.0.0.1:40282)","v":0,"name":"crucible","level":30,"time":"2024-12-11T23:43:44.886434676Z","hostname":"w-01JEW1EFDAGT0RY7YPFWJAPQ1M","pid":1242,"":"io task","client":"2","":"downstairs","session_id":"e15bfd89-6497-4a4e-8b07-6d994b4b1bbe"}
3962024-12-11T23:43:45.070Z{"msg":"ds_transition from New to WaitActive","v":0,"name":"crucible","level":30,"time":"2024-12-11T23:43:44.887536709Z","hostname":"w-01JEW1EFDAGT0RY7YPFWJAPQ1M","pid":1242,"client":"2","":"downstairs","session_id":"e15bfd89-6497-4a4e-8b07-6d994b4b1bbe"}
3972024-12-11T23:43:45.070Z{"msg":"[2] Transition from New to WaitActive","v":0,"name":"crucible","level":30,"time":"2024-12-11T23:43:44.887601266Z","hostname":"w-01JEW1EFDAGT0RY7YPFWJAPQ1M","pid":1242,"client":"2","":"downstairs","session_id":"e15bfd89-6497-4a4e-8b07-6d994b4b1bbe"}
3982024-12-11T23:43:45.070Z{"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":"2024-12-11T23:43:44.888049964Z","hostname":"w-01JEW1EFDAGT0RY7YPFWJAPQ1M","pid":1242,"client":"2","":"downstairs","session_id":"e15bfd89-6497-4a4e-8b07-6d994b4b1bbe"}
3992024-12-11T23:43:45.070Z{"msg":"ds_transition from WaitActive to WaitQuorum","v":0,"name":"crucible","level":30,"time":"2024-12-11T23:43:44.888397839Z","hostname":"w-01JEW1EFDAGT0RY7YPFWJAPQ1M","pid":1242,"client":"2","":"downstairs","session_id":"e15bfd89-6497-4a4e-8b07-6d994b4b1bbe"}
4002024-12-11T23:43:45.070Z{"msg":"[2] Transition from WaitActive to WaitQuorum","v":0,"name":"crucible","level":30,"time":"2024-12-11T23:43:44.888431676Z","hostname":"w-01JEW1EFDAGT0RY7YPFWJAPQ1M","pid":1242,"client":"2","":"downstairs","session_id":"e15bfd89-6497-4a4e-8b07-6d994b4b1bbe"}
4012024-12-11T23:43:45.070Z{"msg":"[0]R flush_numbers: [1503, 1503, 1503, 1503, 1503]","v":0,"name":"crucible","level":30,"time":"2024-12-11T23:43:44.88844915Z","hostname":"w-01JEW1EFDAGT0RY7YPFWJAPQ1M","pid":1242,"":"downstairs","":"downstairs","session_id":"e15bfd89-6497-4a4e-8b07-6d994b4b1bbe"}
4022024-12-11T23:43:45.070Z{"msg":"[0]R generation: [32, 32, 32, 32, 32]","v":0,"name":"crucible","level":30,"time":"2024-12-11T23:43:44.888481569Z","hostname":"w-01JEW1EFDAGT0RY7YPFWJAPQ1M","pid":1242,"":"downstairs","":"downstairs","session_id":"e15bfd89-6497-4a4e-8b07-6d994b4b1bbe"}
4032024-12-11T23:43:45.071Z{"msg":"[0]R dirty: [false, false, false, false, false]","v":0,"name":"crucible","level":30,"time":"2024-12-11T23:43:44.888498452Z","hostname":"w-01JEW1EFDAGT0RY7YPFWJAPQ1M","pid":1242,"":"downstairs","":"downstairs","session_id":"e15bfd89-6497-4a4e-8b07-6d994b4b1bbe"}
4042024-12-11T23:43:45.071Z{"msg":"[1]R flush_numbers: [1503, 1503, 1503, 1503, 1503]","v":0,"name":"crucible","level":30,"time":"2024-12-11T23:43:44.888520295Z","hostname":"w-01JEW1EFDAGT0RY7YPFWJAPQ1M","pid":1242,"":"downstairs","":"downstairs","session_id":"e15bfd89-6497-4a4e-8b07-6d994b4b1bbe"}
4052024-12-11T23:43:45.071Z{"msg":"[1]R generation: [32, 32, 32, 32, 32]","v":0,"name":"crucible","level":30,"time":"2024-12-11T23:43:44.888535429Z","hostname":"w-01JEW1EFDAGT0RY7YPFWJAPQ1M","pid":1242,"":"downstairs","":"downstairs","session_id":"e15bfd89-6497-4a4e-8b07-6d994b4b1bbe"}
4062024-12-11T23:43:45.071Z{"msg":"[1]R dirty: [false, false, false, false, false]","v":0,"name":"crucible","level":30,"time":"2024-12-11T23:43:44.888556602Z","hostname":"w-01JEW1EFDAGT0RY7YPFWJAPQ1M","pid":1242,"":"downstairs","":"downstairs","session_id":"e15bfd89-6497-4a4e-8b07-6d994b4b1bbe"}
4072024-12-11T23:43:45.071Z{"msg":"[2]R flush_numbers: [1502, 1502, 1502, 1502, 1502]","v":0,"name":"crucible","level":30,"time":"2024-12-11T23:43:44.888570776Z","hostname":"w-01JEW1EFDAGT0RY7YPFWJAPQ1M","pid":1242,"":"downstairs","":"downstairs","session_id":"e15bfd89-6497-4a4e-8b07-6d994b4b1bbe"}
4082024-12-11T23:43:45.071Z{"msg":"[2]R generation: [31, 31, 31, 31, 31]","v":0,"name":"crucible","level":30,"time":"2024-12-11T23:43:44.888584771Z","hostname":"w-01JEW1EFDAGT0RY7YPFWJAPQ1M","pid":1242,"":"downstairs","":"downstairs","session_id":"e15bfd89-6497-4a4e-8b07-6d994b4b1bbe"}
4092024-12-11T23:43:45.071Z{"msg":"[2]R dirty: [false, false, false, false, false]","v":0,"name":"crucible","level":30,"time":"2024-12-11T23:43:44.888606544Z","hostname":"w-01JEW1EFDAGT0RY7YPFWJAPQ1M","pid":1242,"":"downstairs","":"downstairs","session_id":"e15bfd89-6497-4a4e-8b07-6d994b4b1bbe"}
4102024-12-11T23:43:45.071Z{"msg":"Max found gen is 33","v":0,"name":"crucible","level":30,"time":"2024-12-11T23:43:44.888620758Z","hostname":"w-01JEW1EFDAGT0RY7YPFWJAPQ1M","pid":1242,"":"downstairs","":"downstairs","session_id":"e15bfd89-6497-4a4e-8b07-6d994b4b1bbe"}
4112024-12-11T23:43:45.071Z{"msg":"Generation requested: 33 >= found:33","v":0,"name":"crucible","level":30,"time":"2024-12-11T23:43:44.888641561Z","hostname":"w-01JEW1EFDAGT0RY7YPFWJAPQ1M","pid":1242,"":"downstairs","":"downstairs","session_id":"e15bfd89-6497-4a4e-8b07-6d994b4b1bbe"}
4122024-12-11T23:43:45.071Z{"msg":"Next flush: 1504","v":0,"name":"crucible","level":30,"time":"2024-12-11T23:43:44.888655626Z","hostname":"w-01JEW1EFDAGT0RY7YPFWJAPQ1M","pid":1242,"":"downstairs","":"downstairs","session_id":"e15bfd89-6497-4a4e-8b07-6d994b4b1bbe"}
4132024-12-11T23:43:45.071Z{"msg":"Extent 0 has flush number mismatch","v":0,"name":"crucible","level":30,"time":"2024-12-11T23:43:44.888677158Z","hostname":"w-01JEW1EFDAGT0RY7YPFWJAPQ1M","pid":1242,"":"mend","":"downstairs","":"downstairs","session_id":"e15bfd89-6497-4a4e-8b07-6d994b4b1bbe"}
4142024-12-11T23:43:45.071Z{"msg":"First source client ID for extent 0","v":0,"name":"crucible","level":30,"time":"2024-12-11T23:43:44.888692313Z","hostname":"w-01JEW1EFDAGT0RY7YPFWJAPQ1M","pid":1242,"mrl":"flush_mismatch","":"mend","":"downstairs","":"downstairs","session_id":"e15bfd89-6497-4a4e-8b07-6d994b4b1bbe"}
4152024-12-11T23:43:45.071Z{"msg":"extent:0 gens: 32 32 31","v":0,"name":"crucible","level":30,"time":"2024-12-11T23:43:44.888713995Z","hostname":"w-01JEW1EFDAGT0RY7YPFWJAPQ1M","pid":1242,"mrl":"flush_mismatch","":"mend","":"downstairs","":"downstairs","session_id":"e15bfd89-6497-4a4e-8b07-6d994b4b1bbe"}
4162024-12-11T23:43:45.071Z{"msg":"extent:0 flush: 1503 1503 1502 scs: [ClientId(0), ClientId(1)]","v":0,"name":"crucible","level":30,"time":"2024-12-11T23:43:44.888729849Z","hostname":"w-01JEW1EFDAGT0RY7YPFWJAPQ1M","pid":1242,"mrl":"flush_mismatch","":"mend","":"downstairs","":"downstairs","session_id":"e15bfd89-6497-4a4e-8b07-6d994b4b1bbe"}
4172024-12-11T23:43:45.071Z{"msg":"max_flush now has: [ClientId(0), ClientId(1)]","v":0,"name":"crucible","level":30,"time":"2024-12-11T23:43:44.888751541Z","hostname":"w-01JEW1EFDAGT0RY7YPFWJAPQ1M","pid":1242,"mrl":"flush_mismatch","":"mend","":"downstairs","":"downstairs","session_id":"e15bfd89-6497-4a4e-8b07-6d994b4b1bbe"}
4182024-12-11T23:43:45.071Z{"msg":"extent:0 dirty: false false false","v":0,"name":"crucible","level":30,"time":"2024-12-11T23:43:44.888766786Z","hostname":"w-01JEW1EFDAGT0RY7YPFWJAPQ1M","pid":1242,"mrl":"flush_mismatch","":"mend","":"downstairs","":"downstairs","session_id":"e15bfd89-6497-4a4e-8b07-6d994b4b1bbe"}
4192024-12-11T23:43:45.071Z{"msg":"No maxes found, left with: [ClientId(0), ClientId(1)]","v":0,"name":"crucible","level":30,"time":"2024-12-11T23:43:44.888788278Z","hostname":"w-01JEW1EFDAGT0RY7YPFWJAPQ1M","pid":1242,"mrl":"flush_mismatch","":"mend","":"downstairs","":"downstairs","session_id":"e15bfd89-6497-4a4e-8b07-6d994b4b1bbe"}
4202024-12-11T23:43:45.071Z{"msg":"find dest for source 0 for extent at index 0","v":0,"name":"crucible","level":30,"time":"2024-12-11T23:43:44.888803813Z","hostname":"w-01JEW1EFDAGT0RY7YPFWJAPQ1M","pid":1242,"mrl":"flush_mismatch","":"mend","":"downstairs","":"downstairs","session_id":"e15bfd89-6497-4a4e-8b07-6d994b4b1bbe"}
4212024-12-11T23:43:45.072Z{"msg":"source 0, add dest 2 gen","v":0,"name":"crucible","level":30,"time":"2024-12-11T23:43:44.888825235Z","hostname":"w-01JEW1EFDAGT0RY7YPFWJAPQ1M","pid":1242,"mrl":"flush_mismatch","":"mend","":"downstairs","":"downstairs","session_id":"e15bfd89-6497-4a4e-8b07-6d994b4b1bbe"}
4222024-12-11T23:43:45.072Z{"msg":"Extent 1 has flush number mismatch","v":0,"name":"crucible","level":30,"time":"2024-12-11T23:43:44.888852095Z","hostname":"w-01JEW1EFDAGT0RY7YPFWJAPQ1M","pid":1242,"":"mend","":"downstairs","":"downstairs","session_id":"e15bfd89-6497-4a4e-8b07-6d994b4b1bbe"}
4232024-12-11T23:43:45.072Z{"msg":"First source client ID for extent 1","v":0,"name":"crucible","level":30,"time":"2024-12-11T23:43:44.888874327Z","hostname":"w-01JEW1EFDAGT0RY7YPFWJAPQ1M","pid":1242,"mrl":"flush_mismatch","":"mend","":"downstairs","":"downstairs","session_id":"e15bfd89-6497-4a4e-8b07-6d994b4b1bbe"}
4242024-12-11T23:43:45.072Z{"msg":"extent:1 gens: 32 32 31","v":0,"name":"crucible","level":30,"time":"2024-12-11T23:43:44.888889771Z","hostname":"w-01JEW1EFDAGT0RY7YPFWJAPQ1M","pid":1242,"mrl":"flush_mismatch","":"mend","":"downstairs","":"downstairs","session_id":"e15bfd89-6497-4a4e-8b07-6d994b4b1bbe"}
4252024-12-11T23:43:45.072Z{"msg":"extent:1 flush: 1503 1503 1502 scs: [ClientId(0), ClientId(1)]","v":0,"name":"crucible","level":30,"time":"2024-12-11T23:43:44.888912593Z","hostname":"w-01JEW1EFDAGT0RY7YPFWJAPQ1M","pid":1242,"mrl":"flush_mismatch","":"mend","":"downstairs","":"downstairs","session_id":"e15bfd89-6497-4a4e-8b07-6d994b4b1bbe"}
4262024-12-11T23:43:45.072Z{"msg":"max_flush now has: [ClientId(0), ClientId(1)]","v":0,"name":"crucible","level":30,"time":"2024-12-11T23:43:44.888928877Z","hostname":"w-01JEW1EFDAGT0RY7YPFWJAPQ1M","pid":1242,"mrl":"flush_mismatch","":"mend","":"downstairs","":"downstairs","session_id":"e15bfd89-6497-4a4e-8b07-6d994b4b1bbe"}
4272024-12-11T23:43:45.072Z{"msg":"extent:1 dirty: false false false","v":0,"name":"crucible","level":30,"time":"2024-12-11T23:43:44.888944302Z","hostname":"w-01JEW1EFDAGT0RY7YPFWJAPQ1M","pid":1242,"mrl":"flush_mismatch","":"mend","":"downstairs","":"downstairs","session_id":"e15bfd89-6497-4a4e-8b07-6d994b4b1bbe"}
4282024-12-11T23:43:45.072Z{"msg":"No maxes found, left with: [ClientId(0), ClientId(1)]","v":0,"name":"crucible","level":30,"time":"2024-12-11T23:43:44.888966154Z","hostname":"w-01JEW1EFDAGT0RY7YPFWJAPQ1M","pid":1242,"mrl":"flush_mismatch","":"mend","":"downstairs","":"downstairs","session_id":"e15bfd89-6497-4a4e-8b07-6d994b4b1bbe"}
4292024-12-11T23:43:45.072Z{"msg":"find dest for source 0 for extent at index 1","v":0,"name":"crucible","level":30,"time":"2024-12-11T23:43:44.888981569Z","hostname":"w-01JEW1EFDAGT0RY7YPFWJAPQ1M","pid":1242,"mrl":"flush_mismatch","":"mend","":"downstairs","":"downstairs","session_id":"e15bfd89-6497-4a4e-8b07-6d994b4b1bbe"}
4302024-12-11T23:43:45.072Z{"msg":"source 0, add dest 2 gen","v":0,"name":"crucible","level":30,"time":"2024-12-11T23:43:44.889003011Z","hostname":"w-01JEW1EFDAGT0RY7YPFWJAPQ1M","pid":1242,"mrl":"flush_mismatch","":"mend","":"downstairs","":"downstairs","session_id":"e15bfd89-6497-4a4e-8b07-6d994b4b1bbe"}
4312024-12-11T23:43:45.073Z{"msg":"Extent 2 has flush number mismatch","v":0,"name":"crucible","level":30,"time":"2024-12-11T23:43:44.889025073Z","hostname":"w-01JEW1EFDAGT0RY7YPFWJAPQ1M","pid":1242,"":"mend","":"downstairs","":"downstairs","session_id":"e15bfd89-6497-4a4e-8b07-6d994b4b1bbe"}
4322024-12-11T23:43:45.073Z{"msg":"First source client ID for extent 2","v":0,"name":"crucible","level":30,"time":"2024-12-11T23:43:44.889039967Z","hostname":"w-01JEW1EFDAGT0RY7YPFWJAPQ1M","pid":1242,"mrl":"flush_mismatch","":"mend","":"downstairs","":"downstairs","session_id":"e15bfd89-6497-4a4e-8b07-6d994b4b1bbe"}
4332024-12-11T23:43:45.073Z{"msg":"extent:2 gens: 32 32 31","v":0,"name":"crucible","level":30,"time":"2024-12-11T23:43:44.889054622Z","hostname":"w-01JEW1EFDAGT0RY7YPFWJAPQ1M","pid":1242,"mrl":"flush_mismatch","":"mend","":"downstairs","":"downstairs","session_id":"e15bfd89-6497-4a4e-8b07-6d994b4b1bbe"}
4342024-12-11T23:43:45.073Z{"msg":"extent:2 flush: 1503 1503 1502 scs: [ClientId(0), ClientId(1)]","v":0,"name":"crucible","level":30,"time":"2024-12-11T23:43:44.889076854Z","hostname":"w-01JEW1EFDAGT0RY7YPFWJAPQ1M","pid":1242,"mrl":"flush_mismatch","":"mend","":"downstairs","":"downstairs","session_id":"e15bfd89-6497-4a4e-8b07-6d994b4b1bbe"}
4352024-12-11T23:43:45.073Z{"msg":"max_flush now has: [ClientId(0), ClientId(1)]","v":0,"name":"crucible","level":30,"time":"2024-12-11T23:43:44.889092129Z","hostname":"w-01JEW1EFDAGT0RY7YPFWJAPQ1M","pid":1242,"mrl":"flush_mismatch","":"mend","":"downstairs","":"downstairs","session_id":"e15bfd89-6497-4a4e-8b07-6d994b4b1bbe"}
4362024-12-11T23:43:45.073Z{"msg":"extent:2 dirty: false false false","v":0,"name":"crucible","level":30,"time":"2024-12-11T23:43:44.889107613Z","hostname":"w-01JEW1EFDAGT0RY7YPFWJAPQ1M","pid":1242,"mrl":"flush_mismatch","":"mend","":"downstairs","":"downstairs","session_id":"e15bfd89-6497-4a4e-8b07-6d994b4b1bbe"}
4372024-12-11T23:43:45.073Z{"msg":"No maxes found, left with: [ClientId(0), ClientId(1)]","v":0,"name":"crucible","level":30,"time":"2024-12-11T23:43:44.889122598Z","hostname":"w-01JEW1EFDAGT0RY7YPFWJAPQ1M","pid":1242,"mrl":"flush_mismatch","":"mend","":"downstairs","":"downstairs","session_id":"e15bfd89-6497-4a4e-8b07-6d994b4b1bbe"}
4382024-12-11T23:43:45.073Z{"msg":"find dest for source 0 for extent at index 2","v":0,"name":"crucible","level":30,"time":"2024-12-11T23:43:44.889137662Z","hostname":"w-01JEW1EFDAGT0RY7YPFWJAPQ1M","pid":1242,"mrl":"flush_mismatch","":"mend","":"downstairs","":"downstairs","session_id":"e15bfd89-6497-4a4e-8b07-6d994b4b1bbe"}
4392024-12-11T23:43:45.073Z{"msg":"source 0, add dest 2 gen","v":0,"name":"crucible","level":30,"time":"2024-12-11T23:43:44.889159644Z","hostname":"w-01JEW1EFDAGT0RY7YPFWJAPQ1M","pid":1242,"mrl":"flush_mismatch","":"mend","":"downstairs","":"downstairs","session_id":"e15bfd89-6497-4a4e-8b07-6d994b4b1bbe"}
4402024-12-11T23:43:45.073Z{"msg":"Extent 3 has flush number mismatch","v":0,"name":"crucible","level":30,"time":"2024-12-11T23:43:44.889175189Z","hostname":"w-01JEW1EFDAGT0RY7YPFWJAPQ1M","pid":1242,"":"mend","":"downstairs","":"downstairs","session_id":"e15bfd89-6497-4a4e-8b07-6d994b4b1bbe"}
4412024-12-11T23:43:45.073Z{"msg":"First source client ID for extent 3","v":0,"name":"crucible","level":30,"time":"2024-12-11T23:43:44.889189294Z","hostname":"w-01JEW1EFDAGT0RY7YPFWJAPQ1M","pid":1242,"mrl":"flush_mismatch","":"mend","":"downstairs","":"downstairs","session_id":"e15bfd89-6497-4a4e-8b07-6d994b4b1bbe"}
4422024-12-11T23:43:45.073Z{"msg":"extent:3 gens: 32 32 31","v":0,"name":"crucible","level":30,"time":"2024-12-11T23:43:44.889210866Z","hostname":"w-01JEW1EFDAGT0RY7YPFWJAPQ1M","pid":1242,"mrl":"flush_mismatch","":"mend","":"downstairs","":"downstairs","session_id":"e15bfd89-6497-4a4e-8b07-6d994b4b1bbe"}
4432024-12-11T23:43:45.073Z{"msg":"extent:3 flush: 1503 1503 1502 scs: [ClientId(0), ClientId(1)]","v":0,"name":"crucible","level":30,"time":"2024-12-11T23:43:44.8892264Z","hostname":"w-01JEW1EFDAGT0RY7YPFWJAPQ1M","pid":1242,"mrl":"flush_mismatch","":"mend","":"downstairs","":"downstairs","session_id":"e15bfd89-6497-4a4e-8b07-6d994b4b1bbe"}
4442024-12-11T23:43:45.073Z{"msg":"max_flush now has: [ClientId(0), ClientId(1)]","v":0,"name":"crucible","level":30,"time":"2024-12-11T23:43:44.889248082Z","hostname":"w-01JEW1EFDAGT0RY7YPFWJAPQ1M","pid":1242,"mrl":"flush_mismatch","":"mend","":"downstairs","":"downstairs","session_id":"e15bfd89-6497-4a4e-8b07-6d994b4b1bbe"}
4452024-12-11T23:43:45.073Z{"msg":"extent:3 dirty: false false false","v":0,"name":"crucible","level":30,"time":"2024-12-11T23:43:44.889263467Z","hostname":"w-01JEW1EFDAGT0RY7YPFWJAPQ1M","pid":1242,"mrl":"flush_mismatch","":"mend","":"downstairs","":"downstairs","session_id":"e15bfd89-6497-4a4e-8b07-6d994b4b1bbe"}
4462024-12-11T23:43:45.073Z{"msg":"No maxes found, left with: [ClientId(0), ClientId(1)]","v":0,"name":"crucible","level":30,"time":"2024-12-11T23:43:44.889285229Z","hostname":"w-01JEW1EFDAGT0RY7YPFWJAPQ1M","pid":1242,"mrl":"flush_mismatch","":"mend","":"downstairs","":"downstairs","session_id":"e15bfd89-6497-4a4e-8b07-6d994b4b1bbe"}
4472024-12-11T23:43:45.073Z{"msg":"find dest for source 0 for extent at index 3","v":0,"name":"crucible","level":30,"time":"2024-12-11T23:43:44.889300463Z","hostname":"w-01JEW1EFDAGT0RY7YPFWJAPQ1M","pid":1242,"mrl":"flush_mismatch","":"mend","":"downstairs","":"downstairs","session_id":"e15bfd89-6497-4a4e-8b07-6d994b4b1bbe"}
4482024-12-11T23:43:45.073Z{"msg":"source 0, add dest 2 gen","v":0,"name":"crucible","level":30,"time":"2024-12-11T23:43:44.889333032Z","hostname":"w-01JEW1EFDAGT0RY7YPFWJAPQ1M","pid":1242,"mrl":"flush_mismatch","":"mend","":"downstairs","":"downstairs","session_id":"e15bfd89-6497-4a4e-8b07-6d994b4b1bbe"}
4492024-12-11T23:43:45.073Z{"msg":"Extent 4 has flush number mismatch","v":0,"name":"crucible","level":30,"time":"2024-12-11T23:43:44.88936615Z","hostname":"w-01JEW1EFDAGT0RY7YPFWJAPQ1M","pid":1242,"":"mend","":"downstairs","":"downstairs","session_id":"e15bfd89-6497-4a4e-8b07-6d994b4b1bbe"}
4502024-12-11T23:43:45.073Z{"msg":"First source client ID for extent 4","v":0,"name":"crucible","level":30,"time":"2024-12-11T23:43:44.889382684Z","hostname":"w-01JEW1EFDAGT0RY7YPFWJAPQ1M","pid":1242,"mrl":"flush_mismatch","":"mend","":"downstairs","":"downstairs","session_id":"e15bfd89-6497-4a4e-8b07-6d994b4b1bbe"}
4512024-12-11T23:43:45.073Z{"msg":"extent:4 gens: 32 32 31","v":0,"name":"crucible","level":30,"time":"2024-12-11T23:43:44.889404626Z","hostname":"w-01JEW1EFDAGT0RY7YPFWJAPQ1M","pid":1242,"mrl":"flush_mismatch","":"mend","":"downstairs","":"downstairs","session_id":"e15bfd89-6497-4a4e-8b07-6d994b4b1bbe"}
4522024-12-11T23:43:45.076Z{"msg":"extent:4 flush: 1503 1503 1502 scs: [ClientId(0), ClientId(1)]","v":0,"name":"crucible","level":30,"time":"2024-12-11T23:43:44.889420271Z","hostname":"w-01JEW1EFDAGT0RY7YPFWJAPQ1M","pid":1242,"mrl":"flush_mismatch","":"mend","":"downstairs","":"downstairs","session_id":"e15bfd89-6497-4a4e-8b07-6d994b4b1bbe"}
4532024-12-11T23:43:45.076Z{"msg":"max_flush now has: [ClientId(0), ClientId(1)]","v":0,"name":"crucible","level":30,"time":"2024-12-11T23:43:44.889454468Z","hostname":"w-01JEW1EFDAGT0RY7YPFWJAPQ1M","pid":1242,"mrl":"flush_mismatch","":"mend","":"downstairs","":"downstairs","session_id":"e15bfd89-6497-4a4e-8b07-6d994b4b1bbe"}
4542024-12-11T23:43:45.076Z{"msg":"extent:4 dirty: false false false","v":0,"name":"crucible","level":30,"time":"2024-12-11T23:43:44.889480169Z","hostname":"w-01JEW1EFDAGT0RY7YPFWJAPQ1M","pid":1242,"mrl":"flush_mismatch","":"mend","":"downstairs","":"downstairs","session_id":"e15bfd89-6497-4a4e-8b07-6d994b4b1bbe"}
4552024-12-11T23:43:45.076Z{"msg":"No maxes found, left with: [ClientId(0), ClientId(1)]","v":0,"name":"crucible","level":30,"time":"2024-12-11T23:43:44.889512827Z","hostname":"w-01JEW1EFDAGT0RY7YPFWJAPQ1M","pid":1242,"mrl":"flush_mismatch","":"mend","":"downstairs","":"downstairs","session_id":"e15bfd89-6497-4a4e-8b07-6d994b4b1bbe"}
4562024-12-11T23:43:45.076Z{"msg":"find dest for source 0 for extent at index 4","v":0,"name":"crucible","level":30,"time":"2024-12-11T23:43:44.889541577Z","hostname":"w-01JEW1EFDAGT0RY7YPFWJAPQ1M","pid":1242,"mrl":"flush_mismatch","":"mend","":"downstairs","":"downstairs","session_id":"e15bfd89-6497-4a4e-8b07-6d994b4b1bbe"}
4572024-12-11T23:43:45.076Z{"msg":"source 0, add dest 2 gen","v":0,"name":"crucible","level":30,"time":"2024-12-11T23:43:44.889585551Z","hostname":"w-01JEW1EFDAGT0RY7YPFWJAPQ1M","pid":1242,"mrl":"flush_mismatch","":"mend","":"downstairs","":"downstairs","session_id":"e15bfd89-6497-4a4e-8b07-6d994b4b1bbe"}
4582024-12-11T23:43:45.077Z{"msg":"Transition from WaitQuorum to Reconcile","v":0,"name":"crucible","level":30,"time":"2024-12-11T23:43:44.889628345Z","hostname":"w-01JEW1EFDAGT0RY7YPFWJAPQ1M","pid":1242,"client":"0","":"downstairs","session_id":"e15bfd89-6497-4a4e-8b07-6d994b4b1bbe"}
4592024-12-11T23:43:45.077Z{"msg":"Transition from WaitQuorum to Reconcile","v":0,"name":"crucible","level":30,"time":"2024-12-11T23:43:44.88964458Z","hostname":"w-01JEW1EFDAGT0RY7YPFWJAPQ1M","pid":1242,"client":"1","":"downstairs","session_id":"e15bfd89-6497-4a4e-8b07-6d994b4b1bbe"}
4602024-12-11T23:43:45.077Z{"msg":"Transition from WaitQuorum to Reconcile","v":0,"name":"crucible","level":30,"time":"2024-12-11T23:43:44.889665282Z","hostname":"w-01JEW1EFDAGT0RY7YPFWJAPQ1M","pid":1242,"client":"2","":"downstairs","session_id":"e15bfd89-6497-4a4e-8b07-6d994b4b1bbe"}
4612024-12-11T23:43:45.077Z{"msg":"Full repair list: {ExtentId(2): ExtentFix { source: ClientId(0), dest: [ClientId(2)] }, ExtentId(3): ExtentFix { source: ClientId(0), dest: [ClientId(2)] }, ExtentId(1): ExtentFix { source: ClientId(0), dest: [ClientId(2)] }, ExtentId(0): ExtentFix { source: ClientId(0), dest: [ClientId(2)] }, ExtentId(4): ExtentFix { source: ClientId(0), dest: [ClientId(2)] }}","v":0,"name":"crucible","level":30,"time":"2024-12-11T23:43:44.889683186Z","hostname":"w-01JEW1EFDAGT0RY7YPFWJAPQ1M","pid":1242,"":"downstairs","":"downstairs","session_id":"e15bfd89-6497-4a4e-8b07-6d994b4b1bbe"}
4622024-12-11T23:43:45.077Z{"msg":"Task list: [ReconcileIO { id: ReconciliationId(0), op: ExtentFlush { repair_id: ReconciliationId(0), extent_id: ExtentId(2), client_id: ClientId(0), flush_number: 1504, gen_number: 33 }, state: ClientData([New, New, New]) }, ReconcileIO { id: ReconciliationId(1), op: ExtentClose { repair_id: ReconciliationId(1), extent_id: ExtentId(2) }, state: ClientData([New, New, New]) }, ReconcileIO { id: ReconciliationId(2), op: ExtentRepair { repair_id: ReconciliationId(2), extent_id: ExtentId(2), source_client_id: ClientId(0), source_repair_address: 0.0.0.0:12810, dest_clients: [ClientId(2)] }, state: ClientData([New, New, New]) }, ReconcileIO { id: ReconciliationId(3), op: ExtentReopen { repair_id: ReconciliationId(3), extent_id: ExtentId(2) }, state: ClientData([New, New, New]) }, ReconcileIO { id: ReconciliationId(4), op: ExtentFlush { repair_id: ReconciliationId(4), extent_id: ExtentId(3), client_id: ClientId(0), flush_number: 1504, gen_number: 33 }, state: ClientData([New, New, New]) }, ReconcileIO { id: ReconciliationId(5), op: ExtentClose { repair_id: ReconciliationId(5), extent_id: ExtentId(3) }, state: ClientData([New, New, New]) }, ReconcileIO { id: ReconciliationId(6), op: ExtentRepair { repair_id: ReconciliationId(6), extent_id: ExtentId(3), source_client_id: ClientId(0), source_repair_address: 0.0.0.0:12810, dest_clients: [ClientId(2)] }, state: ClientData([New, New, New]) }, ReconcileIO { id: ReconciliationId(7), op: ExtentReopen { repair_id: ReconciliationId(7), extent_id: ExtentId(3) }, state: ClientData([New, New, New]) }, ReconcileIO { id: ReconciliationId(8), op: ExtentFlush { repair_id: ReconciliationId(8), extent_id: ExtentId(1), client_id: ClientId(0), flush_number: 1504, gen_number: 33 }, state: ClientData([New, New, New]) }, ReconcileIO { id: ReconciliationId(9), op: ExtentClose { repair_id: ReconciliationId(9), extent_id: ExtentId(1) }, state: ClientData([New, New, New]) }, ReconcileIO { id: ReconciliationId(10), op: ExtentRepair { repair_id: ReconciliationId(10), extent_id: ExtentId(1), source_client_id: ClientId(0), source_repair_address: 0.0.0.0:12810, dest_clients: [ClientId(2)] }, state: ClientData([New, New, New]) }, ReconcileIO { id: ReconciliationId(11), op: ExtentReopen { repair_id: ReconciliationId(11), extent_id: ExtentId(1) }, state: ClientData([New, New, New]) }, ReconcileIO { id: ReconciliationId(12), op: ExtentFlush { repair_id: ReconciliationId(12), extent_id: ExtentId(0), client_id: ClientId(0), flush_number: 1504, gen_number: 33 }, state: ClientData([New, New, New]) }, ReconcileIO { id: ReconciliationId(13), op: ExtentClose { repair_id: ReconciliationId(13), extent_id: ExtentId(0) }, state: ClientData([New, New, New]) }, ReconcileIO { id: ReconciliationId(14), op: ExtentRepair { repair_id: ReconciliationId(14), extent_id: ExtentId(0), source_client_id: ClientId(0), source_repair_address: 0.0.0.0:12810, dest_clients: [ClientId(2)] }, state: ClientData([New, New, New]) }, ReconcileIO { id: ReconciliationId(15), op: ExtentReopen { repair_id: ReconciliationId(15), extent_id: ExtentId(0) }, state: ClientData([New, New, New]) }, ReconcileIO { id: ReconciliationId(16), op: ExtentFlush { repair_id: ReconciliationId(16), extent_id: ExtentId(4), client_id: ClientId(0), flush_number: 1504, gen_number: 33 }, state: ClientData([New, New, New]) }, ReconcileIO { id: ReconciliationId(17), op: ExtentClose { repair_id: ReconciliationId(17), extent_id: ExtentId(4) }, state: ClientData([New, New, New]) }, ReconcileIO { id: ReconciliationId(18), op: ExtentRepair { repair_id: ReconciliationId(18), extent_id: ExtentId(4), source_client_id: ClientId(0), source_repair_address: 0.0.0.0:12810, dest_clients: [ClientId(2)] }, state: ClientData([New, New, New]) }, ReconcileIO { id: ReconciliationId(19), op: ExtentReopen { repair_id: ReconciliationId(19), extent_id: ExtentId(4) }, state: ClientData([New, New, New]) }]","v":0,"name":"crucible","level":30,"time":"2024-12-11T23:43:44.889818227Z","hostname":"w-01JEW1EFDAGT0RY7YPFWJAPQ1M","pid":1242,"":"downstairs","":"downstairs","session_id":"e15bfd89-6497-4a4e-8b07-6d994b4b1bbe"}
4632024-12-11T23:43:45.077Z{"msg":"starting reconciliation d55fc46e-c21f-4d75-91b3-d538145ef3e3: found 20 extents that need repair","v":0,"name":"crucible","level":30,"time":"2024-12-11T23:43:44.889870029Z","hostname":"w-01JEW1EFDAGT0RY7YPFWJAPQ1M","pid":1242,"":"downstairs","":"downstairs","session_id":"e15bfd89-6497-4a4e-8b07-6d994b4b1bbe"}
4642024-12-11T23:43:45.077Z{"msg":"sending reconcile request ReconciliationId(2)","v":0,"name":"crucible","level":30,"time":"2024-12-11T23:43:44.889900187Z","hostname":"w-01JEW1EFDAGT0RY7YPFWJAPQ1M","pid":1242,"client":"2","":"downstairs","session_id":"e15bfd89-6497-4a4e-8b07-6d994b4b1bbe"}
4652024-12-11T23:43:45.080Z{"msg":"sending reconcile request ReconciliationId(6)","v":0,"name":"crucible","level":30,"time":"2024-12-11T23:43:44.898173058Z","hostname":"w-01JEW1EFDAGT0RY7YPFWJAPQ1M","pid":1242,"client":"2","":"downstairs","session_id":"e15bfd89-6497-4a4e-8b07-6d994b4b1bbe"}
4662024-12-11T23:43:45.083Z{"msg":"sending reconcile request ReconciliationId(10)","v":0,"name":"crucible","level":30,"time":"2024-12-11T23:43:44.901721301Z","hostname":"w-01JEW1EFDAGT0RY7YPFWJAPQ1M","pid":1242,"client":"2","":"downstairs","session_id":"e15bfd89-6497-4a4e-8b07-6d994b4b1bbe"}
4672024-12-11T23:43:45.086Z{"msg":"sending reconcile request ReconciliationId(14)","v":0,"name":"crucible","level":30,"time":"2024-12-11T23:43:44.90530575Z","hostname":"w-01JEW1EFDAGT0RY7YPFWJAPQ1M","pid":1242,"client":"2","":"downstairs","session_id":"e15bfd89-6497-4a4e-8b07-6d994b4b1bbe"}
4682024-12-11T23:43:45.088Z{"msg":"sending reconcile request ReconciliationId(18)","v":0,"name":"crucible","level":30,"time":"2024-12-11T23:43:44.908957894Z","hostname":"w-01JEW1EFDAGT0RY7YPFWJAPQ1M","pid":1242,"client":"2","":"downstairs","session_id":"e15bfd89-6497-4a4e-8b07-6d994b4b1bbe"}
4692024-12-11T23:43:45.091Z{"msg":"done with reconciliation","v":0,"name":"crucible","level":30,"time":"2024-12-11T23:43:44.911855291Z","hostname":"w-01JEW1EFDAGT0RY7YPFWJAPQ1M","pid":1242,"":"downstairs","":"downstairs","session_id":"e15bfd89-6497-4a4e-8b07-6d994b4b1bbe"}
4702024-12-11T23:43:45.091Z{"msg":"Transition from Reconcile to Active","v":0,"name":"crucible","level":30,"time":"2024-12-11T23:43:44.91188616Z","hostname":"w-01JEW1EFDAGT0RY7YPFWJAPQ1M","pid":1242,"client":"0","":"downstairs","session_id":"e15bfd89-6497-4a4e-8b07-6d994b4b1bbe"}
4712024-12-11T23:43:45.091Z{"msg":"Transition from Reconcile to Active","v":0,"name":"crucible","level":30,"time":"2024-12-11T23:43:44.911902394Z","hostname":"w-01JEW1EFDAGT0RY7YPFWJAPQ1M","pid":1242,"client":"1","":"downstairs","session_id":"e15bfd89-6497-4a4e-8b07-6d994b4b1bbe"}
4722024-12-11T23:43:45.091Z{"msg":"Transition from Reconcile to Active","v":0,"name":"crucible","level":30,"time":"2024-12-11T23:43:44.911916489Z","hostname":"w-01JEW1EFDAGT0RY7YPFWJAPQ1M","pid":1242,"client":"2","":"downstairs","session_id":"e15bfd89-6497-4a4e-8b07-6d994b4b1bbe"}
4732024-12-11T23:43:45.091Z{"msg":"All required reconciliation work is completed","v":0,"name":"crucible","level":30,"time":"2024-12-11T23:43:44.911930214Z","hostname":"w-01JEW1EFDAGT0RY7YPFWJAPQ1M","pid":1242,"session_id":"e15bfd89-6497-4a4e-8b07-6d994b4b1bbe"}
4742024-12-11T23:43:45.091Z{"msg":"Set Downstairs and Upstairs active after reconciliation","v":0,"name":"crucible","level":30,"time":"2024-12-11T23:43:44.911942959Z","hostname":"w-01JEW1EFDAGT0RY7YPFWJAPQ1M","pid":1242,"session_id":"e15bfd89-6497-4a4e-8b07-6d994b4b1bbe"}
4752024-12-11T23:43:45.094Z{"msg":"501dbabc-40d0-4e2b-afbd-58db0aa95971 is now active with session: e15bfd89-6497-4a4e-8b07-6d994b4b1bbe","v":0,"name":"crucible","level":30,"time":"2024-12-11T23:43:44.911956284Z","hostname":"w-01JEW1EFDAGT0RY7YPFWJAPQ1M","pid":1242,"session_id":"e15bfd89-6497-4a4e-8b07-6d994b4b1bbe"}
4762024-12-11T23:43:45.094Z{"msg":"The guest has finished waiting for activation with:33","v":0,"name":"crucible","level":30,"time":"2024-12-11T23:43:44.911979106Z","hostname":"w-01JEW1EFDAGT0RY7YPFWJAPQ1M","pid":1242}
4772024-12-11T23:43:45.094ZWait for a query_work_queue command to finish before sending IO
4782024-12-11T23:43:45.094ZDisk: sv:1 bs:4096 ts:204800 tb:50 max_io:50 or 204800
4792024-12-11T23:43:45.094ZLoading write count information from file "/var/tmp/test_up-build/verify_file"
4802024-12-11T23:43:45.094ZRead and Verify all blocks (0..50 range:true)
4812024-12-11T23:43:45.098ZWrote out file "/var/tmp/test_up-build/verify_file"
4822024-12-11T23:43:45.098ZVerify test completed
4832024-12-11T23:43:45.101ZWrote out file "/var/tmp/test_up-build/verify_file"
4842024-12-11T23:43:45.101ZCLIENT: Tests done. All submitted work has been ACK'd
4852024-12-11T23:43:45.101Z----------------------------------------------------------------
4862024-12-11T23:43:45.101Z Crucible gen:33 GIO:true work queues: Upstairs:0 downstairs:1
4872024-12-11T23:43:45.101ZStates: Active Active Active
4882024-12-11T23:43:45.101ZJOBID ACK TYPE BKS/EXT DS:0 DS:1 DS:2 REPLAY
4892024-12-11T23:43:45.101Z 1000 Acked Read 50 Done Done Done false
4902024-12-11T23:43:45.101Z STATES DS:0 DS:1 DS:2 TOTAL
4912024-12-11T23:43:45.101Z Sent 0 0 0 0
4922024-12-11T23:43:45.101Z Done 1 1 1 3
4932024-12-11T23:43:45.101Z Skipped 0 0 0 0
4942024-12-11T23:43:45.101Z Error 0 0 0 0
4952024-12-11T23:43:45.101ZLast Flush: 0 0 0
4962024-12-11T23:43:45.101ZDownstairs last five completed:
4972024-12-11T23:43:45.101ZUpstairs last five completed: 1000
4982024-12-11T23:43:45.101ZCLIENT: Up:0 ds:1 act:3
4992024-12-11T23:43:49.102Z----------------------------------------------------------------
5002024-12-11T23:43:49.102Z Crucible gen:33 GIO:true work queues: Upstairs:0 downstairs:0
5012024-12-11T23:43:49.102ZDownstairs last five completed: 1001 1000
5022024-12-11T23:43:49.102ZUpstairs last five completed: 1001 1000
5032024-12-11T23:43:49.105ZCLIENT: Up:0 ds:0 act:3
5042024-12-11T23:43:49.105ZCLIENT: All crucible jobs finished, exiting program
5052024-12-11T23:43:49.105Z{"msg":"Guest handle has been dropped","v":0,"name":"crucible","level":40,"time":"2024-12-11T23:43:48.921559294Z","hostname":"w-01JEW1EFDAGT0RY7YPFWJAPQ1M","pid":1242}
5062024-12-11T23:43:49.108ZRepair part 2 passed
5072024-12-11T23:43:49.111Z/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
5082024-12-11T23:43:49.126ZEXT BLOCKS GEN0 GEN1 GEN2 FL0 FL1 FL2 D0 D1 D2 DIFF
5092024-12-11T23:43:49.126Z 0 000-009 32 32 32 1503 1503 1503 F F F
5102024-12-11T23:43:49.128Z 1 010-019 32 32 32 1503 1503 1503 F F F
5112024-12-11T23:43:49.128Z 2 020-029 32 32 32 1503 1503 1503 F F F
5122024-12-11T23:43:49.128Z 3 030-039 32 32 32 1503 1503 1503 F F F
5132024-12-11T23:43:49.128Z 4 040-049 32 32 32 1503 1503 1503 F F F
5142024-12-11T23:43:49.128ZMax gen: 32, Max flush: 1503
5152024-12-11T23:43:49.131Zdump test passed
5162024-12-11T23:43:49.131Z/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
5172024-12-11T23:43:49.144Z Extent 1
5182024-12-11T23:43:49.144ZGEN 32 32 32
5192024-12-11T23:43:49.144ZFLUSH_ID 1503 1503 1503
5202024-12-11T23:43:49.144ZDIRTY
5212024-12-11T23:43:49.144Z
5222024-12-11T23:43:49.148ZBLOCK D0 D1 D2 C0 C1 C2 DIFF
5232024-12-11T23:43:49.148Z010 A A A A A A
5242024-12-11T23:43:49.148Z011 A A A A A A
5252024-12-11T23:43:49.150Z012 A A A A A A
5262024-12-11T23:43:49.150Z013 A A A A A A
5272024-12-11T23:43:49.152Z014 A A A A A A
5282024-12-11T23:43:49.152Z015 A A A A A A
5292024-12-11T23:43:49.155Z016 A A A A A A
5302024-12-11T23:43:49.155Z017 A A A A A A
5312024-12-11T23:43:49.158Z018 A A A A A A
5322024-12-11T23:43:49.158Z019 A A A A A A
5332024-12-11T23:43:49.160Zdump extent test passed
5342024-12-11T23:43:49.160Z/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
5352024-12-11T23:43:49.175ZExtent 2 Block in extent 0 Actual block 20
5362024-12-11T23:43:49.175Z
5372024-12-11T23:43:49.177Z DATA SHA256 VER
5382024-12-11T23:43:49.177Z------ ---------------------------------------------------------------- ---
5392024-12-11T23:43:49.177Z 0 ad3d0e88276af7eb1f904413516e1a8c1f9c2fa8b17b86b2d842d08303e90aa2 A
5402024-12-11T23:43:49.178Z 1 ad3d0e88276af7eb1f904413516e1a8c1f9c2fa8b17b86b2d842d08303e90aa2 A
5412024-12-11T23:43:49.178Z 2 ad3d0e88276af7eb1f904413516e1a8c1f9c2fa8b17b86b2d842d08303e90aa2 A
5422024-12-11T23:43:49.178Z
5432024-12-11T23:43:49.178ZNONCES 0 1 2 DIFF
5442024-12-11T23:43:49.178Z------ ------------------------ ------------------------ ------------------------ -----
5452024-12-11T23:43:49.178Z
5462024-12-11T23:43:49.178Z TAGS 0 1 2 DIFF
5472024-12-11T23:43:49.178Z------ -------------------------------- -------------------------------- -------------------------------- -----
5482024-12-11T23:43:49.178Z
5492024-12-11T23:43:49.178ZHASHES 0 1 2 DIFF
5502024-12-11T23:43:49.178Z------ ---------------- ---------------- ---------------- -----
5512024-12-11T23:43:49.178Z 0 42916ab6fa364c70 42916ab6fa364c70 42916ab6fa364c70
5522024-12-11T23:43:49.178Z
5532024-12-11T23:43:49.180Zdump block test passed
5542024-12-11T23:43:49.180ZInitial upstairs tests have completed, stopping all downstairs
5552024-12-11T23:43:54.245ZCreating 4 larger downstairs regions
5562024-12-11T23:43:54.352ZStarting 4 downstairs
5572024-12-11T23:43:59.361Zdsc restarted at PID: 1255
5582024-12-11T23:43:59.581ZNow do the replace-reconcile test
5592024-12-11T23:43:59.634ZUsing 8840 for the replacement port
5602024-12-11T23:46:48.088ZCompleted test: replace-reconcile
5612024-12-11T23:46:48.091ZNow do the replace-before-active test
5622024-12-11T23:49:32.725ZCompleted test: replace-before-active
5632024-12-11T23:49:32.727ZAll tests have completed, stopping all downstairs
5642024-12-11T23:49:32.783Z
5652024-12-11T23:49:32.783ZAll Tests have passed
5662024-12-11T23:49:32.786Z8:05 Test duration
5672024-12-11T23:49:32.786Z
5682024-12-11T23:49:32.786Zreal 8:04.499563235
5692024-12-11T23:49:32.786Zuser 1:02.470897533
5702024-12-11T23:49:32.786Zsys 9.584396606
5712024-12-11T23:49:32.786Ztrap 0.087414388
5722024-12-11T23:49:32.786Ztflt 0.012561022
5732024-12-11T23:49:32.786Zdflt 0.238253051
5742024-12-11T23:49:32.786Zkflt 0.000949210
5752024-12-11T23:49:32.786Zlock 5:46:21.090005962
5762024-12-11T23:49:32.786Zslp 24:59.299127710
5772024-12-11T23:49:32.786Zlat 7.591356832
5782024-12-11T23:49:32.786Zstop 0.131060917
5792024-12-11T23:49:32.786Z+ echo 'test-up-unencrypted ends'
5802024-12-11T23:49:32.786Ztest-up-unencrypted ends
5812024-12-11T23:49:37.789Zprocess exited: duration 492834 ms, exit code 0
5822024-12-11T23:49:37.789Zexec warning: : stdio descriptors remain open after task exit; waiting 60 seconds for them to close
5832024-12-11T23:50:37.839Zexec warning: : stdout descriptor may be held open by a background process; giving up!
5842024-12-11T23:50:37.839Zexec warning: : stderr descriptor may be held open by a background process; giving up!
 
5852024-12-11T23:50:37.849Zfound 14 output files
5862024-12-11T23:50:37.849Zuploading: /tmp/test_up-build/dsc-out.txt (39465 bytes)
5872024-12-11T23:50:38.860Zuploaded: /tmp/test_up-build/dsc-out.txt
5882024-12-11T23:50:38.868Zuploading: /tmp/test_up-build/test_up_out.txt (9177026 bytes)
5892024-12-11T23:50:40.010Zuploaded: /tmp/test_up-build/test_up_out.txt
5902024-12-11T23:50:40.012Zuploading: /tmp/test_up-build/dsc/downstairs-8810.txt (2500 bytes)
5912024-12-11T23:50:41.019Zuploaded: /tmp/test_up-build/dsc/downstairs-8810.txt
5922024-12-11T23:50:41.022Zuploading: /tmp/test_up-build/dsc/downstairs-8820.txt (144651 bytes)
5932024-12-11T23:50:42.037Zuploaded: /tmp/test_up-build/dsc/downstairs-8820.txt
5942024-12-11T23:50:42.037Zuploading: /tmp/test_up-build/dsc/downstairs-8830.txt (251094 bytes)
5952024-12-11T23:50:43.060Zuploaded: /tmp/test_up-build/dsc/downstairs-8830.txt
5962024-12-11T23:50:43.063Zuploading: /tmp/test_up-build/dsc/downstairs-8840.txt (139421 bytes)
5972024-12-11T23:50:44.080Zuploaded: /tmp/test_up-build/dsc/downstairs-8840.txt
5982024-12-11T23:50:44.080Zuploading: /tmp/debug/df.txt (1270 bytes)
5992024-12-11T23:50:45.089Zuploaded: /tmp/debug/df.txt
6002024-12-11T23:50:45.092Zuploading: /tmp/debug/dtrace.txt (488003 bytes)
6012024-12-11T23:50:46.122Zuploaded: /tmp/debug/dtrace.txt
6022024-12-11T23:50:46.124Zuploading: /tmp/debug/iostat.txt (165559 bytes)
6032024-12-11T23:50:46.137Zupload warning: file "/tmp/debug/iostat.txt" changed size mid upload: 165559 -> 167967
6042024-12-11T23:50:47.145Zuploaded: /tmp/debug/iostat.txt
6052024-12-11T23:50:47.148Zuploading: /tmp/debug/mpstat.txt (401505 bytes)
6062024-12-11T23:50:47.171Zupload warning: file "/tmp/debug/mpstat.txt" changed size mid upload: 401505 -> 408075
6072024-12-11T23:50:48.177Zuploaded: /tmp/debug/mpstat.txt
6082024-12-11T23:50:48.179Zuploading: /tmp/debug/paging.txt (72490 bytes)
6092024-12-11T23:50:48.188Zupload warning: file "/tmp/debug/paging.txt" changed size mid upload: 72490 -> 73808
6102024-12-11T23:50:49.195Zuploaded: /tmp/debug/paging.txt
6112024-12-11T23:50:49.197Zuploading: /tmp/debug/prstat.txt (751315 bytes)
6122024-12-11T23:50:49.233Zupload warning: file "/tmp/debug/prstat.txt" changed size mid upload: 751315 -> 766801
6132024-12-11T23:50:50.241Zuploaded: /tmp/debug/prstat.txt
6142024-12-11T23:50:50.244Zuploading: /tmp/debug/psrinfo.txt (1528 bytes)
6152024-12-11T23:50:51.250Zuploaded: /tmp/debug/psrinfo.txt
6162024-12-11T23:50:51.252Zuploading: /tmp/debug/upstairs-info.txt (71288 bytes)
6172024-12-11T23:50:52.264Zuploaded: /tmp/debug/upstairs-info.txt