01HPDDYW2WHX6GSANR4D1ARQMX: test-up-encrypted

BasicConfig {
    output_rules: [
        "/tmp/test_up/*.txt",
        "/tmp/test_up/dsc/*.txt",
        "/tmp/core.*",
    ],
    rust_toolchain: None,
    target: Some(
        "helios-2.0",
    ),
    access_repos: [],
    publish: [],
    skip_clone: true,
}

Buildomat Job: 01HPDDZ4WRGP67K326KEB1DMD0

Tags:

Artefacts:

Output:

SEQ GLOBAL TIME DETAILS
12024-02-12T01:31:29.167Zjob dependencies complete; ready to run (waiting for 18 m 49 s)
22024-02-12T01:34:33.290Zjob assigned to worker 01HPDF5AMG830DHRA918X6V4ZC (queued for 3 m 4 s)
32024-02-12T01:34:34.078Zdownloading input: /input/build/work/bins/crucible-downstairs.gz
42024-02-12T01:34:47.239Zdownloaded input: /input/build/work/bins/crucible-downstairs.gz
52024-02-12T01:34:47.240Zdownloading input: /input/build/work/bins/crucible-hammer.gz
62024-02-12T01:34:51.515Zdownloaded input: /input/build/work/bins/crucible-hammer.gz
72024-02-12T01:34:51.515Zdownloading input: /input/build/work/bins/crutest.gz
82024-02-12T01:34:57.354Zdownloaded input: /input/build/work/bins/crutest.gz
92024-02-12T01:34:57.354Zdownloading input: /input/build/work/bins/dsc.gz
102024-02-12T01:35:06.164Zdownloaded input: /input/build/work/bins/dsc.gz
112024-02-12T01:35:06.167Zdownloading input: /input/build/work/scripts/perf-downstairs-tick.d
122024-02-12T01:35:06.178Zdownloaded input: /input/build/work/scripts/perf-downstairs-tick.d
132024-02-12T01:35:06.178Zdownloading input: /input/build/work/scripts/test_ds.sh
142024-02-12T01:35:06.194Zdownloaded input: /input/build/work/scripts/test_ds.sh
152024-02-12T01:35:06.194Zdownloading input: /input/build/work/scripts/test_live_repair.sh
162024-02-12T01:35:06.215Zdownloaded input: /input/build/work/scripts/test_live_repair.sh
172024-02-12T01:35:06.215Zdownloading input: /input/build/work/scripts/test_repair.sh
182024-02-12T01:35:06.229Zdownloaded input: /input/build/work/scripts/test_repair.sh
192024-02-12T01:35:06.230Zdownloading input: /input/build/work/scripts/test_replay.sh
202024-02-12T01:35:06.273Zdownloaded input: /input/build/work/scripts/test_replay.sh
212024-02-12T01:35:06.273Zdownloading input: /input/build/work/scripts/test_up.sh
222024-02-12T01:35:06.314Zdownloaded input: /input/build/work/scripts/test_up.sh
232024-02-12T01:35:06.314Zdownloading input: /input/build/work/scripts/upstairs_info.d
242024-02-12T01:35:06.337Zdownloaded input: /input/build/work/scripts/upstairs_info.d
252024-02-12T01:35:06.341Zdownloading input: /input/build/tmp/cargo-test-out.log
262024-02-12T01:35:10.247Zdownloaded input: /input/build/tmp/cargo-test-out.log
 
272024-02-12T01:35:10.247Zstarting task 0: "setup"
282024-02-12T01:35:10.488Z++ uname -s
292024-02-12T01:35:10.491Z+ kern=SunOS
302024-02-12T01:35:10.491Z+ case "$kern" in
312024-02-12T01:35:10.491Z+ groupadd -g 12345 build
322024-02-12T01:35:10.491Z+ useradd -u 12345 -g build -d /home/build -s /bin/bash -c build -P 'Primary Administrator' build
332024-02-12T01:35:12.500Z+ zfs create -o mountpoint=/work rpool/work
342024-02-12T01:35:12.597Z++ awk '$2 == "/home" { print $3 }' /etc/mnttab
352024-02-12T01:35:12.600Z+ home_fs=zfs
362024-02-12T01:35:12.600Z+ [[ zfs == autofs ]]
372024-02-12T01:35:12.600Z+ mkdir -p /home/build
382024-02-12T01:35:12.603Z+ chown build:build /home/build /work
392024-02-12T01:35:14.603Z+ chmod 0700 /home/build /work
402024-02-12T01:35:14.606Zprocess exited: duration 4374 ms, exit code 0
 
412024-02-12T01:35:14.612Zstarting task 1: "authentication"
422024-02-12T01:35:14.631Zprocess exited: duration 17 ms, exit code 0
 
432024-02-12T01:35:14.636Zstarting task 2: "build"
442024-02-12T01:35:14.642Z+ banner cores
452024-02-12T01:35:14.684Z
462024-02-12T01:35:14.684Z #### #### ##### ###### ####
472024-02-12T01:35:14.684Z # # # # # # # #
482024-02-12T01:35:14.684Z # # # # # ##### ####
492024-02-12T01:35:14.684Z # # # ##### # #
502024-02-12T01:35:14.684Z # # # # # # # # #
512024-02-12T01:35:14.684Z #### #### # # ###### ####
522024-02-12T01:35:14.684Z
532024-02-12T01:35:14.687Z+ pfexec coreadm -i /tmp/core.%f.%p -g /tmp/core.%f.%p -e global -e log -e proc-setid -e global-setid
542024-02-12T01:35:14.694Z+ echo 'input bins dir contains:'
552024-02-12T01:35:14.698Zinput bins dir contains:
562024-02-12T01:35:14.698Z+ ls -ltr /input/build/work/bins
572024-02-12T01:35:14.699Ztotal 761232
582024-02-12T01:35:14.699Z-rw-r--r-- 1 root root 121611746 Feb 12 01:34 crucible-downstairs.gz
592024-02-12T01:35:14.699Z-rw-r--r-- 1 root root 91139552 Feb 12 01:34 crucible-hammer.gz
602024-02-12T01:35:14.699Z-rw-r--r-- 1 root root 104810185 Feb 12 01:34 crutest.gz
612024-02-12T01:35:14.699Z-rw-r--r-- 1 root root 71941606 Feb 12 01:35 dsc.gz
622024-02-12T01:35:14.699Z+ banner unpack
632024-02-12T01:35:14.702Z
642024-02-12T01:35:14.703Z # # # # ##### ## #### # #
652024-02-12T01:35:14.703Z # # ## # # # # # # # # #
662024-02-12T01:35:14.703Z # # # # # # # # # # ####
672024-02-12T01:35:14.703Z # # # # # ##### ###### # # #
682024-02-12T01:35:14.703Z # # # ## # # # # # # #
692024-02-12T01:35:14.703Z #### # # # # # #### # #
702024-02-12T01:35:14.703Z
712024-02-12T01:35:14.703Z+ mkdir -p /var/tmp/bins
722024-02-12T01:35:14.703Z+ for t in "$input/bins/"*.gz
732024-02-12T01:35:14.703Z++ basename /input/build/work/bins/crucible-downstairs.gz
742024-02-12T01:35:14.706Z+ b=crucible-downstairs.gz
752024-02-12T01:35:14.706Z+ b=crucible-downstairs
762024-02-12T01:35:14.706Z+ gunzip
772024-02-12T01:35:17.558Z+ chmod +x /var/tmp/bins/crucible-downstairs
782024-02-12T01:35:17.561Z+ for t in "$input/bins/"*.gz
792024-02-12T01:35:17.561Z++ basename /input/build/work/bins/crucible-hammer.gz
802024-02-12T01:35:17.572Z+ b=crucible-hammer.gz
812024-02-12T01:35:17.572Z+ b=crucible-hammer
822024-02-12T01:35:17.572Z+ gunzip
832024-02-12T01:35:19.635Z+ chmod +x /var/tmp/bins/crucible-hammer
842024-02-12T01:35:19.638Z+ for t in "$input/bins/"*.gz
852024-02-12T01:35:19.638Z++ basename /input/build/work/bins/crutest.gz
862024-02-12T01:35:19.641Z+ b=crutest.gz
872024-02-12T01:35:19.641Z+ b=crutest
882024-02-12T01:35:19.641Z+ gunzip
892024-02-12T01:35:22.090Z+ chmod +x /var/tmp/bins/crutest
902024-02-12T01:35:22.093Z+ for t in "$input/bins/"*.gz
912024-02-12T01:35:22.096Z++ basename /input/build/work/bins/dsc.gz
922024-02-12T01:35:22.096Z+ b=dsc.gz
932024-02-12T01:35:22.096Z+ b=dsc
942024-02-12T01:35:22.096Z+ gunzip
952024-02-12T01:35:23.735Z+ chmod +x /var/tmp/bins/dsc
962024-02-12T01:35:23.740Z+ export BINDIR=/var/tmp/bins
972024-02-12T01:35:23.740Z+ BINDIR=/var/tmp/bins
982024-02-12T01:35:23.740Z+ banner test_up_encrypted
992024-02-12T01:35:23.743Z
1002024-02-12T01:35:23.743Z ##### ###### #### ##### # # ##### ###### # #
1012024-02-12T01:35:23.743Z # # # # # # # # # ## #
1022024-02-12T01:35:23.743Z # ##### #### # # # # # ##### # # #
1032024-02-12T01:35:23.743Z # # # # # # ##### # # # #
1042024-02-12T01:35:23.743Z # # # # # # # # # # ##
1052024-02-12T01:35:23.743Z # ###### #### # ####### #### # ####### ###### # #
1062024-02-12T01:35:23.743Z
1072024-02-12T01:35:23.744Z+ ptime -m bash /input/build/work/scripts/test_up.sh -N encrypted
1082024-02-12T01:35:23.883Z/input/build/work
1092024-02-12T01:35:23.895ZTurn off color for downstairs dump
1102024-02-12T01:35:24.034ZUpstairs using key: axRJJH+moTa0IfHpruLt7raezOdecgLR5Vi87Jg0zZI=
1112024-02-12T01:35:24.037Zdsc output goes to /tmp/test_up/dsc-out.txt
1122024-02-12T01:35:24.037ZCreating three downstairs regions
1132024-02-12T01:35:24.167ZStarting three downstairs
1142024-02-12T01:35:29.176ZDisable automatic restart on all downstairs
1152024-02-12T01:35:29.235Z
1162024-02-12T01:35:29.236ZBegin tests, output goes to /tmp/test_up/test_up_out.txt
1172024-02-12T01:35:29.239ZRunning test: span
1182024-02-12T01:35:33.295ZCompleted test: span
1192024-02-12T01:35:38.302ZRunning test: big
1202024-02-12T01:35:42.598ZCompleted test: big
1212024-02-12T01:35:47.605ZRunning test: dep
1222024-02-12T01:36:30.552ZCompleted test: dep
1232024-02-12T01:36:35.552ZRunning test: balloon
1242024-02-12T01:37:15.603ZCompleted test: balloon
1252024-02-12T01:37:20.613ZRunning test: deactivate
1262024-02-12T01:37:30.256ZCompleted test: deactivate
1272024-02-12T01:37:35.261ZRunning hammer
1282024-02-12T01:37:46.751ZRun repair tests
1292024-02-12T01:37:46.754Z/var/tmp/bins/crutest fill -g 31 -q --key axRJJH+moTa0IfHpruLt7raezOdecgLR5Vi87Jg0zZI= -t 127.0.0.1:8810 -t 127.0.0.1:8820 -t 127.0.0.1:8830 --verify-out /var/tmp/test_up/verify_file
1302024-02-12T01:37:46.770Z{"msg":"Upstairs starts","v":0,"name":"crucible","level":30,"time":"2024-02-12T01:37:45.087793723Z","hostname":"ip-10-150-1-57.us-west-2.compute.internal","pid":1175}
1312024-02-12T01:37:46.775Z{"msg":"Crucible Version: BuildInfo {\n version: \"0.0.1\",\n git_sha: \"9f74bb5fe2be09de9f7a47f2db64d7dce836b79c\",\n git_commit_timestamp: \"2024-02-12T01:11:14.000000000Z\",\n git_branch: \"main\",\n rustc_semver: \"1.75.0\",\n rustc_channel: \"stable\",\n rustc_host_triple: \"x86_64-unknown-illumos\",\n rustc_commit_sha: \"82e1608dfa6e0b5569232559e3d385fea5a93112\",\n cargo_triple: \"x86_64-unknown-illumos\",\n debug: true,\n opt_level: 0,\n}","v":0,"name":"crucible","level":30,"time":"2024-02-12T01:37:45.088087697Z","hostname":"ip-10-150-1-57.us-west-2.compute.internal","pid":1175}
1322024-02-12T01:37:46.776Z{"msg":"Upstairs <-> Downstairs Message Version: 5","v":0,"name":"crucible","level":30,"time":"2024-02-12T01:37:45.088138676Z","hostname":"ip-10-150-1-57.us-west-2.compute.internal","pid":1175}
1332024-02-12T01:37:46.776Z{"msg":"Crucible 0fe78a10-52bf-4382-b8f3-c5374f2372fa has session id: f7f5b86e-0ca0-4f2d-a66f-aed7aad48aa1","v":0,"name":"crucible","level":30,"time":"2024-02-12T01:37:45.088168115Z","hostname"Crucible runtime is spawned
1342024-02-12T01:37:46.776Z:"ip-10-150-1-57.us-west-2.compute.internal","pid":1175,"session_id":"f7f5b86e-0ca0-4f2d-a66f-aed7aad48aa1"}
1352024-02-12T01:37:46.776Z{"msg":"Upstairs opts: Upstairs UUID: 0fe78a10-52bf-4382-b8f3-c5374f2372fa, Targets: [127.0.0.1:8810, 127.0.0.1:8820, 127.0.0.1:8830], lossy: false, flush_timeout: None, key populated: true, cert_pem populated: false, key_pem populated: false, root_cert_pem populated: false, Control: None, read_only: false","v":0,"name":"crucible","level":30,"time":"2024-02-12T01:37:45.088233734Z","hostname":"ip-10-150-1-57.us-west-2.compute.internal","pid":1175,"session_id":"f7f5b86e-0ca0-4f2d-a66f-aed7aad48aa1"}
1362024-02-12T01:37:46.776Z{"msg":"Crucible stats registered with UUID: 0fe78a10-52bf-4382-b8f3-c5374f2372fa","v":0,"name":"crucible","level":30,"time":"2024-02-12T01:37:45.088267053Z","hostname":"ip-10-150-1-57.us-west-2.compute.internal","pid":1175,"session_id":"f7f5b86e-0ca0-4f2d-a66f-aed7aad48aa1"}
1372024-02-12T01:37:46.776Z{"msg":"The guest has requested activation with gen:31","v":0,"name":"crucible","level":30,"time":"2024-02-12T01:37:45.088289613Z","hostname":"ip-10-150-1-57.us-west-2.compute.internal","pid":1175}
1382024-02-12T01:37:46.776Z{"msg":"0fe78a10-52bf-4382-b8f3-c5374f2372fa active request set","v":0,"name":"crucible","level":30,"time":"2024-02-12T01:37:45.088400941Z","hostname":"ip-10-150-1-57.us-west-2.compute.internal","pid":1175,"session_id":"f7f5b86e-0ca0-4f2d-a66f-aed7aad48aa1"}
1392024-02-12T01:37:46.776Z{"msg":"sending connect oneshot to client","v":0,"name":"crucible","level":30,"time":"2024-02-12T01:37:45.08843686Z","hostname":"ip-10-150-1-57.us-west-2.compute.internal","pid":1175,"client":"0","":"downstairs","session_id":"f7f5b86e-0ca0-4f2d-a66f-aed7aad48aa1"}
1402024-02-12T01:37:46.776Z{"msg":"client set_active_request while in New; waiting...","v":0,"name":"crucible","level":30,"time":"2024-02-12T01:37:45.088481739Z","hostname":"ip-10-150-1-57.us-west-2.compute.internal","pid":1175,"client":"0","":"downstairs","session_id":"f7f5b86e-0ca0-4f2d-a66f-aed7aad48aa1"}
1412024-02-12T01:37:46.776Z{"msg":"sending connect oneshot to client","v":0,"name":"crucible","level":30,"time":"2024-02-12T01:37:45.088535868Z","hostname":"ip-10-150-1-57.us-west-2.compute.internal","pid":1175,"client":"1","":"downstairs","session_id":"f7f5b86e-0ca0-4f2d-a66f-aed7aad48aa1"}
1422024-02-12T01:37:46.776Z{"msg":"client set_active_request while in New; waiting...","v":0,"name":"crucible","level":30,"time":"2024-02-12T01:37:45.088587997Z","hostname":"ip-10-150-1-57.us-west-2.compute.internal","pid":1175,"client":"1","":"downstairs","session_id":"f7f5b86e-0ca0-4f2d-a66f-aed7aad48aa1"}
1432024-02-12T01:37:46.776Z{"msg":"sending connect oneshot to client","v":0,"name":"crucible","level":30,"time":"2024-02-12T01:37:45.088635556Z","hostname":"ip-10-150-1-57.us-west-2.compute.internal","pid":1175,"client":"2","":"downstairs","session_id":"f7f5b86e-0ca0-4f2d-a66f-aed7aad48aa1"}
1442024-02-12T01:37:46.776Z{"msg":"client set_active_request while in New; waiting...","v":0,"name":"crucible","level":30,"time":"2024-02-12T01:37:45.088695705Z","hostname":"ip-10-150-1-57.us-west-2.compute.internal","pid":1175,"client":"2","":"downstairs","session_id":"f7f5b86e-0ca0-4f2d-a66f-aed7aad48aa1"}
1452024-02-12T01:37:46.776Z{"msg":"connecting to 127.0.0.1:8830","v":0,"name":"crucible","level":30,"time":"2024-02-12T01:37:45.088858852Z","hostname":"ip-10-150-1-57.us-west-2.compute.internal","pid":1175,"":"io task","client":"2","":"downstairs","session_id":"f7f5b86e-0ca0-4f2d-a66f-aed7aad48aa1"}
1462024-02-12T01:37:46.776Z{"msg":"connecting to 127.0.0.1:8820","v":0,"name":"crucible","level":30,"time":"2024-02-12T01:37:45.088902801Z","hostname":"ip-10-150-1-57.us-west-2.compute.internal","pid":1175,"":"io task","client":"1","":"downstairs","session_id":"f7f5b86e-0ca0-4f2d-a66f-aed7aad48aa1"}
1472024-02-12T01:37:46.776Z{"msg":"connecting to 127.0.0.1:8810","v":0,"name":"crucible","level":30,"time":"2024-02-12T01:37:45.088923801Z","hostname":"ip-10-150-1-57.us-west-2.compute.internal","pid":1175,"":"io task","client":"0","":"downstairs","session_id":"f7f5b86e-0ca0-4f2d-a66f-aed7aad48aa1"}
1482024-02-12T01:37:46.776Z{"msg":"ds_connection connected","v":0,"name":"crucible","level":30,"time":"2024-02-12T01:37:45.08894714Z","hostname":"ip-10-150-1-57.us-west-2.compute.internal","pid":1175,"":"io task","client":"0","":"downstairs","session_id":"f7f5b86e-0ca0-4f2d-a66f-aed7aad48aa1"}
1492024-02-12T01:37:46.776Z{"msg":"ds_connection connected","v":0,"name":"crucible","level":30,"time":"2024-02-12T01:37:45.08896446Z","hostname":"ip-10-150-1-57.us-west-2.compute.internal","pid":1175,"":"io task","client":"2","":"downstairs","session_id":"f7f5b86e-0ca0-4f2d-a66f-aed7aad48aa1"}
1502024-02-12T01:37:46.776Z{"msg":"ds_connection connected","v":0,"name":"crucible","level":30,"time":"2024-02-12T01:37:45.088999939Z","hostname":"ip-10-150-1-57.us-west-2.compute.internal","pid":1175,"":"io task","client":"1","":"downstairs","session_id":"f7f5b86e-0ca0-4f2d-a66f-aed7aad48aa1"}
1512024-02-12T01:37:46.776Z{"msg":"ds_transition from New to WaitActive","v":0,"name":"crucible","level":30,"time":"2024-02-12T01:37:45.089426461Z","hostname":"ip-10-150-1-57.us-west-2.compute.internal","pid":1175,"client":"1","":"downstairs","session_id":"f7f5b86e-0ca0-4f2d-a66f-aed7aad48aa1"}
1522024-02-12T01:37:46.776Z{"msg":"[1] Transition from New to WaitActive","v":0,"name":"crucible","level":30,"time":"2024-02-12T01:37:45.08946358Z","hostname":"ip-10-150-1-57.us-west-2.compute.internal","pid":1175,"client":"1","":"downstairs","session_id":"f7f5b86e-0ca0-4f2d-a66f-aed7aad48aa1"}
1532024-02-12T01:37:46.776Z{"msg":"ds_transition from New to WaitActive","v":0,"name":"crucible","level":30,"time":"2024-02-12T01:37:45.08948016Z","hostname":"ip-10-150-1-57.us-west-2.compute.internal","pid":1175,"client":"2","":"downstairs","session_id":"f7f5b86e-0ca0-4f2d-a66f-aed7aad48aa1"}
1542024-02-12T01:37:46.776Z{"msg":"[2] Transition from New to WaitActive","v":0,"name":"crucible","level":30,"time":"2024-02-12T01:37:45.0894942Z","hostname":"ip-10-150-1-57.us-west-2.compute.internal","pid":1175,"client":"2","":"downstairs","session_id":"f7f5b86e-0ca0-4f2d-a66f-aed7aad48aa1"}
1552024-02-12T01:37:46.777Z{"msg":"ds_transition from New to WaitActive","v":0,"name":"crucible","level":30,"time":"2024-02-12T01:37:45.089521969Z","hostname":"ip-10-150-1-57.us-west-2.compute.internal","pid":1175,"client":"0","":"downstairs","session_id":"f7f5b86e-0ca0-4f2d-a66f-aed7aad48aa1"}
1562024-02-12T01:37:46.777Z{"msg":"[0] Transition from New to WaitActive","v":0,"name":"crucible","level":30,"time":"2024-02-12T01:37:45.089549319Z","hostname":"ip-10-150-1-57.us-west-2.compute.internal","pid":1175,"client":"0","":"downstairs","session_id":"f7f5b86e-0ca0-4f2d-a66f-aed7aad48aa1"}
1572024-02-12T01:37:46.777Z{"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-02-12T01:37:45.090025259Z","hostname":"ip-10-150-1-57.us-west-2.compute.internal","pid":1175,"client":"0","":"downstairs","session_id":"f7f5b86e-0ca0-4f2d-a66f-aed7aad48aa1"}
1582024-02-12T01:37:46.777Z{"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-02-12T01:37:45.090076888Z","hostname":"ip-10-150-1-57.us-west-2.compute.internal","pid":1175,"client":"1","":"downstairs","session_id":"f7f5b86e-0ca0-4f2d-a66f-aed7aad48aa1"}
1592024-02-12T01:37:46.777Z{"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-02-12T01:37:45.090130847Z","hostname":"ip-10-150-1-57.us-west-2.compute.internal","pid":1175,"client":"2","":"downstairs","session_id":"f7f5b86e-0ca0-4f2d-a66f-aed7aad48aa1"}
1602024-02-12T01:37:46.777Z{"msg":"ds_transition from WaitActive to WaitQuorum","v":0,"name":"crucible","level":30,"time":"2024-02-12T01:37:45.090533809Z","hostname":"ip-10-150-1-57.us-west-2.compute.internal","pid":1175,"client":"0","":"downstairs","session_id":"f7f5b86e-0ca0-4f2d-a66f-aed7aad48aa1"}
1612024-02-12T01:37:46.777Z{"msg":"[0] Transition from WaitActive to WaitQuorum","v":0,"name":"crucible","level":30,"time":"2024-02-12T01:37:45.090570139Z","hostname":"ip-10-150-1-57.us-west-2.compute.internal","pid":1175,"client":"0","":"downstairs","session_id":"f7f5b86e-0ca0-4f2d-a66f-aed7aad48aa1"}
1622024-02-12T01:37:46.777Z{"msg":"Waiting for true more clients to be ready","v":0,"name":"crucible","level":30,"time":"2024-02-12T01:37:45.090586228Z","hostname":"ip-10-150-1-57.us-west-2.compute.internal","pid":1175,"session_id":"f7f5b86e-0ca0-4f2d-a66f-aed7aad48aa1"}
1632024-02-12T01:37:46.777Z{"msg":"ds_transition from WaitActive to WaitQuorum","v":0,"name":"crucible","level":30,"time":"2024-02-12T01:37:45.090615038Z","hostname":"ip-10-150-1-57.us-west-2.compute.internal","pid":1175,"client":"1","":"downstairs","session_id":"f7f5b86e-0ca0-4f2d-a66f-aed7aad48aa1"}
1642024-02-12T01:37:46.777Z{"msg":"[1] Transition from WaitActive to WaitQuorum","v":0,"name":"crucible","level":30,"time":"2024-02-12T01:37:45.090631748Z","hostname":"ip-10-150-1-57.us-west-2.compute.internal","pid":1175,"client":"1","":"downstairs","session_id":"f7f5b86e-0ca0-4f2d-a66f-aed7aad48aa1"}
1652024-02-12T01:37:46.777Z{"msg":"Waiting for true more clients to be ready","v":0,"name":"crucible","level":30,"time":"2024-02-12T01:37:45.090645507Z","hostname":"ip-10-150-1-57.us-west-2.compute.internal","pid":1175,"session_id":"f7f5b86e-0ca0-4f2d-a66f-aed7aad48aa1"}
1662024-02-12T01:37:46.777Z{"msg":"ds_transition from WaitActive to WaitQuorum","v":0,"name":"crucible","level":30,"time":"2024-02-12T01:37:45.090679867Z","hostname":"ip-10-150-1-57.us-west-2.compute.internal","pid":1175,"client":"2","":"downstairs","session_id":"f7f5b86e-0ca0-4f2d-a66f-aed7aad48aa1"}
1672024-02-12T01:37:46.777Z{"msg":"[2] Transition from WaitActive to WaitQuorum","v":0,"name":"crucible","level":30,"time":"2024-02-12T01:37:45.090705566Z","hostname":"ip-10-150-1-57.us-west-2.compute.internal","pid":1175,"client":"2","":"downstairs","session_id":"f7f5b86e-0ca0-4f2d-a66f-aed7aad48aa1"}
1682024-02-12T01:37:46.777Z{"msg":"[0]R flush_numbers: [1659, 1659, 1659, 1659, 1659]","v":0,"name":"crucible","level":30,"time":"2024-02-12T01:37:45.090738916Z","hostname":"ip-10-150-1-57.us-west-2.compute.internal","pid":1175,"":"downstairs"Wait for a query_work_queue command to finish before sending IO
1692024-02-12T01:37:46.777Z,"":"downstairs","session_id":"f7f5b86e-0ca0-4f2d-a66f-aed7aad48aa1"}
1702024-02-12T01:37:46.777Z{"msg":"[0]R generation: [25, 25, 25, 25, 25]","v":0,"name":"crucible","level":30,"time":"2024-02-12T01:37:45.090766535Z","hostname":"ip-10-150-1-57.us-west-2.compute.internal","pid":1175,"":"downstairs","":"downstairs","session_id":"f7f5b86e-0ca0-4f2d-a66f-aed7aad48aa1"}
1712024-02-12T01:37:46.777Z{"msg":"[0]R dirty: [false, false, false, false, false]","v":0,"name":"crucible","level":30,"time":"2024-02-12T01:37:45.090789204Z","hostname":"ip-10-150-1-57.us-west-2.compute.internal","pid":1175,"":"downstairs","":"downstairs","session_id":"f7f5b86e-0ca0-4f2d-a66f-aed7aad48aa1"}
1722024-02-12T01:37:46.777Z{"msg":"[1]R flush_numbers: [1659, 1659, 1659, 1659, 1659]","v":0,"name":"crucible","level":30,"time":"2024-02-12T01:37:45.090813794Z","hostname":"ip-10-150-1-57.us-west-2.compute.internal","pid":1175,"":"downstairs","":"downstairs","session_id":"f7f5b86e-0ca0-4f2d-a66f-aed7aad48aa1"}
1732024-02-12T01:37:46.777Z{"msg":"[1]R generation: [25, 25, 25, 25, 25]","v":0,"name":"crucible","level":30,"time":"2024-02-12T01:37:45.090844454Z","hostname":"ip-10-150-1-57.us-west-2.compute.internal","pid":1175,"":"downstairs","":"downstairs","session_id":"f7f5b86e-0ca0-4f2d-a66f-aed7aad48aa1"}
1742024-02-12T01:37:46.777Z{"msg":"[1]R dirty: [false, false, false, false, false]","v":0,"name":"crucible","level":30,"time":"2024-02-12T01:37:45.090869943Z","hostname":"ip-10-150-1-57.us-west-2.compute.internal","pid":1175,"":"downstairs","":"downstairs","session_id":"f7f5b86e-0ca0-4f2d-a66f-aed7aad48aa1"}
1752024-02-12T01:37:46.777Z{"msg":"[2]R flush_numbers: [1659, 1659, 1659, 1659, 1659]","v":0,"name":"crucible","level":30,"time":"2024-02-12T01:37:45.090891953Z","hostname":"ip-10-150-1-57.us-west-2.compute.internal","pid":1175,"":"downstairs","":"downstairs","session_id":"f7f5b86e-0ca0-4f2d-a66f-aed7aad48aa1"}
1762024-02-12T01:37:46.777Z{"msg":"[2]R generation: [25, 25, 25, 25, 25]","v":0,"name":"crucible","level":30,"time":"2024-02-12T01:37:45.090913842Z","hostname":"ip-10-150-1-57.us-west-2.compute.internal","pid":1175,"":"downstairs","":"downstairs","session_id":"f7f5b86e-0ca0-4f2d-a66f-aed7aad48aa1"}
1772024-02-12T01:37:46.777Z{"msg":"[2]R dirty: [false, false, false, false, false]","v":0,"name":"crucible","level":30,"time":"2024-02-12T01:37:45.090941332Z","hostname":"ip-10-150-1-57.us-west-2.compute.internal","pid":1175,"":"downstairs","":"downstairs","session_id":"f7f5b86e-0ca0-4f2d-a66f-aed7aad48aa1"}
1782024-02-12T01:37:46.778Z{"msg":"Max found gen is 26","v":0,"name":"crucible","level":30,"time":"2024-02-12T01:37:45.090964281Z","hostname":"ip-10-150-1-57.us-west-2.compute.internal","pid":1175,"":"downstairs","":"downstairs","session_id":"f7f5b86e-0ca0-4f2d-a66f-aed7aad48aa1"}
1792024-02-12T01:37:46.778Z{"msg":"Generation requested: 31 >= found:26","v":0,"name":"crucible","level":30,"time":"2024-02-12T01:37:45.090991371Z","hostname":"ip-10-150-1-57.us-west-2.compute.internal","pid":1175,"":"downstairs","":"downstairs","session_id":"f7f5b86e-0ca0-4f2d-a66f-aed7aad48aa1"}
1802024-02-12T01:37:46.778Z{"msg":"Next flush: 1660","v":0,"name":"crucible","level":30,"time":"2024-02-12T01:37:45.09101414Z","hostname":"ip-10-150-1-57.us-west-2.compute.internal","pid":1175,"":"downstairs","":"downstairs","session_id":"f7f5b86e-0ca0-4f2d-a66f-aed7aad48aa1"}
1812024-02-12T01:37:46.778Z{"msg":"All extents match","v":0,"name":"crucible","level":30,"time":"2024-02-12T01:37:45.09104533Z","hostname":"ip-10-150-1-57.us-west-2.compute.internal","pid":1175,"":"downstairs","":"downstairs","session_id":"f7f5b86e-0ca0-4f2d-a66f-aed7aad48aa1"}
1822024-02-12T01:37:46.778Z{"msg":"No downstairs reconciliation required","v":0,"name":"crucible","level":30,"time":"2024-02-12T01:37:45.091069339Z","hostname":"ip-10-150-1-57.us-west-2.compute.internal","pid":1175,"session_id":"f7f5b86e-0ca0-4f2d-a66f-aed7aad48aa1"}
1832024-02-12T01:37:46.778Z{"msg":"Transition from WaitQuorum to Active","v":0,"name":"crucible","level":30,"time":"2024-02-12T01:37:45.091094489Z","hostname":"ip-10-150-1-57.us-west-2.compute.internal","pid":1175,"client":"0","":"downstairs","session_id":"f7f5b86e-0ca0-4f2d-a66f-aed7aad48aa1"}
1842024-02-12T01:37:46.778Z{"msg":"Transition from WaitQuorum to Active","v":0,"name":"crucible","level":30,"time":"2024-02-12T01:37:45.091118078Z","hostname":"ip-10-150-1-57.us-west-2.compute.internal","pid":1175,"client":"1","":"downstairs","session_id":"f7f5b86e-0ca0-4f2d-a66f-aed7aad48aa1"}
1852024-02-12T01:37:46.778Z{"msg":"Transition from WaitQuorum to Active","v":0,"name":"crucible","level":30,"time":"2024-02-12T01:37:45.091144598Z","hostname":"ip-10-150-1-57.us-west-2.compute.internal","pid":1175,"client":"2","":"downstairs","session_id":"f7f5b86e-0ca0-4f2d-a66f-aed7aad48aa1"}
1862024-02-12T01:37:46.778Z{"msg":"All required reconciliation work is completed","v":0,"name":"crucible","level":30,"time":"2024-02-12T01:37:45.091168417Z","hostname":"ip-10-150-1-57.us-west-2.compute.internal","pid":1175,"session_id":"f7f5b86e-0ca0-4f2d-a66f-aed7aad48aa1"}
1872024-02-12T01:37:46.778ZRegion: es:10 ec:5 bs:4096 ts:204800 tb:50 max_io:50 or 204800
1882024-02-12T01:37:46.778Z{"msg":"Set Downstairs and Upstairs active after reconciliation","v":0,"name":"crucible","level":30,"time":"2024-02-12T01:37:45.091196497Z","hostname":"ip-10-150-1-57.us-west-2.compute.internal","pid":1175,"session_id":"f7f5b86e-0ca0-4f2d-a66f-aed7aad48aa1"}
1892024-02-12T01:37:46.778Z{"msg":"Fill test
1902024-02-12T01:37:46.778Z0fe78a10-52bf-4382-b8f3-c5374f2372fa is now active with session: f7f5b86e-0ca0-4f2d-a66f-aed7aad48aa1","v":0,"name":"crucible","level":30,"time":"2024-02-12T01:37:45.091221546Z","hostname":"ip-10-150-1-57.us-west-2.compute.internal","pid":1175,"session_id":"f7f5b86e-0ca0-4f2d-a66f-aed7aad48aa1"}
1912024-02-12T01:37:46.778Z{"msg":"Set Active after no reconciliation","v":0,"name":"crucible","level":30,"time":"2024-02-12T01:37:45.091249966Z","hostname":"ip-10-150-1-57.us-west-2.compute.internal","pid":1175,"session_id":"f7f5b86e-0ca0-4f2d-a66f-aed7aad48aa1"}
1922024-02-12T01:37:46.778Z{"msg":"The guest has finished waiting for activation with:31","v":0,"name":"crucible","level":30,"time":"2024-02-12T01:37:45.091272345Z","hostname":"ip-10-150-1-57.us-west-2.compute.internal","pid":1175}
1932024-02-12T01:37:46.811ZRead and Verify all blocks (0..50 range:false)
1942024-02-12T01:37:46.853ZWrote out file "/var/tmp/test_up/verify_file"
1952024-02-12T01:37:46.853ZCLIENT: Tests done. All submitted work has been ACK'd
1962024-02-12T01:37:46.856Z----------------------------------------------------------------
1972024-02-12T01:37:46.857Z Crucible gen:31 GIO:true work queues: Upstairs:0 downstairs:1
1982024-02-12T01:37:46.857ZStates: Active Active Active
1992024-02-12T01:37:46.857ZGW_ID ACK DSID TYPE BLOCKS DS:0 DS:1 DS:2 REPLAY
2002024-02-12T01:37:46.857Z 3 Acked 1002 Read 50 Done Done Done false
2012024-02-12T01:37:46.857Z STATES DS:0 DS:1 DS:2 TOTAL
2022024-02-12T01:37:46.857Z New 0 0 0 0
2032024-02-12T01:37:46.857Z Sent 0 0 0 0
2042024-02-12T01:37:46.857Z Done 1 1 1 3
2052024-02-12T01:37:46.857Z Skipped 0 0 0 0
2062024-02-12T01:37:46.857Z Error 0 0 0 0
2072024-02-12T01:37:46.857ZLast Flush: 1001 1001 1001
2082024-02-12T01:37:46.857ZDownstairs last five completed: 1001 1000
2092024-02-12T01:37:46.857ZUpstairs last five completed: 3 2 1
2102024-02-12T01:37:46.857ZCLIENT: Up:0 ds:1 act:3
2112024-02-12T01:37:50.855Z----------------------------------------------------------------
2122024-02-12T01:37:50.856Z Crucible gen:31 GIO:true work queues: Upstairs:0 downstairs:0
2132024-02-12T01:37:50.856ZDownstairs last five completed: 1003 1002 1001 1000
2142024-02-12T01:37:50.856ZUpstairs last five completed: 4 3 2 1
2152024-02-12T01:37:50.856ZCLIENT: Up:0 ds:0 act:3
2162024-02-12T01:37:50.856ZCLIENT: All crucible jobs finished, exiting program
2172024-02-12T01:37:50.862ZRepair setup passed
2182024-02-12T01:37:50.866ZCopy the 8830 file
2192024-02-12T01:37:50.869Zcp -r /var/tmp/test_up/8830 /var/tmp/test_up/previous
2202024-02-12T01:37:50.872Z/var/tmp/bins/crutest repair -g 32 -q --key axRJJH+moTa0IfHpruLt7raezOdecgLR5Vi87Jg0zZI= -t 127.0.0.1:8810 -t 127.0.0.1:8820 -t 127.0.0.1:8830 --verify-out /var/tmp/test_up/verify_file --verify-in /var/tmp/test_up/verify_file
2212024-02-12T01:37:50.882Z{"msg":"Upstairs starts","v":0,"name":"crucible","level":30,"time":"2024-02-12T01:37:49.20238747Z","hostname":"ip-10-150-1-57.us-west-2.compute.internal","pid":1181}
2222024-02-12T01:37:50.882Z{"msg":"Crucible Version: BuildInfo {\n version: \"0.0.1\",\n git_sha: \"9f74bb5fe2be09de9f7a47f2db64d7dce836b79c\",\n git_commit_timestamp: \"2024-02-12T01:11:14.000000000Z\",\n git_branch: \"main\",\n rustc_semver: \"1.75.0\",\n rustc_channel: \"stable\",\n rustc_host_triple: \"x86_64-unknown-illumos\",\n rustc_commit_sha: \"82e1608dfa6e0b5569232559e3d385fea5a93112\",\n cargo_triple: \"x86_64-unknown-illumos\",\n debug: true,\n opt_level: 0,\n}","v":0,"name":"crucible","level":30,"time":"2024-02-12T01:37:49.202661914Z","hostname":"ip-10-150-1-57.us-west-2.compute.internal","pid":1181}
2232024-02-12T01:37:50.882Z{"msg":"Upstairs <-> Downstairs Message Version: 5","v":0,"name":"crucible","level":30,"time":"2024-02-12T01:37:49.202687794Z","hostname":"ip-10-150-1-57.us-west-2.compute.internal","pid":1181}
2242024-02-12T01:37:50.887Z{"msg":"Crucible 3e29b8cc-2d65-4d8d-bb86-63e9e09f8bfb has session id: 9366ad0c-4703-4d1b-99e1-ddc885208b8b","v":0,"name":"crucible","level":30,"time":"2024-02-12T01:37:49.202716044Z","hostname":"ip-10-150-1-57.us-west-2.compute.internal","pid":1181,"session_id":"9366ad0c-4703-4d1b-99e1-ddc885208b8b"}
2252024-02-12T01:37:50.887Z{"msg":"Crucible runtime is spawned
2262024-02-12T01:37:50.888ZUpstairs opts: Upstairs UUID: 3e29b8cc-2d65-4d8d-bb86-63e9e09f8bfb, Targets: [127.0.0.1:8810, 127.0.0.1:8820, 127.0.0.1:8830], lossy: false, flush_timeout: None, key populated: true, cert_pem populated: false, key_pem populated: false, root_cert_pem populated: false, Control: None, read_only: false","v":0,"name":"crucible","level":30,"time":"2024-02-12T01:37:49.202757833Z","hostname":"ip-10-150-1-57.us-west-2.compute.internal","pid":1181,"session_id":"9366ad0c-4703-4d1b-99e1-ddc885208b8b"}
2272024-02-12T01:37:50.888Z{"msg":"Crucible stats registered with UUID: 3e29b8cc-2d65-4d8d-bb86-63e9e09f8bfb","v":0,"name":"crucible","level":30,"time":"2024-02-12T01:37:49.202801932Z","hostname":"ip-10-150-1-57.us-west-2.compute.internal","pid":1181,"session_id":"9366ad0c-4703-4d1b-99e1-ddc885208b8b"}
2282024-02-12T01:37:50.888Z{"msg":"The guest has requested activation with gen:32","v":0,"name":"crucible","level":30,"time":"2024-02-12T01:37:49.202840701Z","hostname":"ip-10-150-1-57.us-west-2.compute.internal","pid":1181}
2292024-02-12T01:37:50.888Z{"msg":"3e29b8cc-2d65-4d8d-bb86-63e9e09f8bfb active request set","v":0,"name":"crucible","level":30,"time":"2024-02-12T01:37:49.202978678Z","hostname":"ip-10-150-1-57.us-west-2.compute.internal","pid":1181,"session_id":"9366ad0c-4703-4d1b-99e1-ddc885208b8b"}
2302024-02-12T01:37:50.888Z{"msg":"sending connect oneshot to client","v":0,"name":"crucible","level":30,"time":"2024-02-12T01:37:49.203016658Z","hostname":"ip-10-150-1-57.us-west-2.compute.internal","pid":1181,"client":"0","":"downstairs","session_id":"9366ad0c-4703-4d1b-99e1-ddc885208b8b"}
2312024-02-12T01:37:50.888Z{"msg":"client set_active_request while in New; waiting...","v":0,"name":"crucible","level":30,"time":"2024-02-12T01:37:49.203033057Z","hostname":"ip-10-150-1-57.us-west-2.compute.internal","pid":1181,"client":"0","":"downstairs","session_id":"9366ad0c-4703-4d1b-99e1-ddc885208b8b"}
2322024-02-12T01:37:50.888Z{"msg":"sending connect oneshot to client","v":0,"name":"crucible","level":30,"time":"2024-02-12T01:37:49.203065197Z","hostname":"ip-10-150-1-57.us-west-2.compute.internal","pid":1181,"client":"1","":"downstairs","session_id":"9366ad0c-4703-4d1b-99e1-ddc885208b8b"}
2332024-02-12T01:37:50.888Z{"msg":"client set_active_request while in New; waiting...","v":0,"name":"crucible","level":30,"time":"2024-02-12T01:37:49.203085676Z","hostname":"ip-10-150-1-57.us-west-2.compute.internal","pid":1181,"client":"1","":"downstairs","session_id":"9366ad0c-4703-4d1b-99e1-ddc885208b8b"}
2342024-02-12T01:37:50.888Z{"msg":"sending connect oneshot to client","v":0,"name":"crucible","level":30,"time":"2024-02-12T01:37:49.203101056Z","hostname":"ip-10-150-1-57.us-west-2.compute.internal","pid":1181,"client":"2","":"downstairs","session_id":"9366ad0c-4703-4d1b-99e1-ddc885208b8b"}
2352024-02-12T01:37:50.888Z{"msg":"client set_active_request while in New; waiting...","v":0,"name":"crucible","level":30,"time":"2024-02-12T01:37:49.203123156Z","hostname":"ip-10-150-1-57.us-west-2.compute.internal","pid":1181,"client":"2","":"downstairs","session_id":"9366ad0c-4703-4d1b-99e1-ddc885208b8b"}
2362024-02-12T01:37:50.888Z{"msg":"connecting to 127.0.0.1:8830","v":0,"name":"crucible","level":30,"time":"2024-02-12T01:37:49.203146205Z","hostname":"ip-10-150-1-57.us-west-2.compute.internal","pid":1181,"":"io task","client":"2","":"downstairs","session_id":"9366ad0c-4703-4d1b-99e1-ddc885208b8b"}
2372024-02-12T01:37:50.888Z{"msg":"connecting to 127.0.0.1:8810","v":0,"name":"crucible","level":30,"time":"2024-02-12T01:37:49.203191154Z","hostname":"ip-10-150-1-57.us-west-2.compute.internal","pid":1181,"":"io task","client":"0","":"downstairs","session_id":"9366ad0c-4703-4d1b-99e1-ddc885208b8b"}
2382024-02-12T01:37:50.888Z{"msg":"connecting to 127.0.0.1:8820","v":0,"name":"crucible","level":30,"time":"2024-02-12T01:37:49.203219084Z","hostname":"ip-10-150-1-57.us-west-2.compute.internal","pid":1181,"":"io task","client":"1","":"downstairs","session_id":"9366ad0c-4703-4d1b-99e1-ddc885208b8b"}
2392024-02-12T01:37:50.888Z{"msg":"ds_connection connected","v":0,"name":"crucible","level":30,"time":"2024-02-12T01:37:49.203371291Z","hostname":"ip-10-150-1-57.us-west-2.compute.internal","pid":1181,"":"io task","client":"1","":"downstairs","session_id":"9366ad0c-4703-4d1b-99e1-ddc885208b8b"}
2402024-02-12T01:37:50.888Z{"msg":"ds_connection connected","v":0,"name":"crucible","level":30,"time":"2024-02-12T01:37:49.20342172Z","hostname":"ip-10-150-1-57.us-west-2.compute.internal","pid":1181,"":"io task","client":"0","":"downstairs","session_id":"9366ad0c-4703-4d1b-99e1-ddc885208b8b"}
2412024-02-12T01:37:50.888Z{"msg":"ds_connection connected","v":0,"name":"crucible","level":30,"time":"2024-02-12T01:37:49.203453369Z","hostname":"ip-10-150-1-57.us-west-2.compute.internal","pid":1181,"":"io task","client":"2","":"downstairs","session_id":"9366ad0c-4703-4d1b-99e1-ddc885208b8b"}
2422024-02-12T01:37:50.889Z{"msg":"ds_transition from New to WaitActive","v":0,"name":"crucible","level":30,"time":"2024-02-12T01:37:49.204091637Z","hostname":"ip-10-150-1-57.us-west-2.compute.internal","pid":1181,"client":"0","":"downstairs","session_id":"9366ad0c-4703-4d1b-99e1-ddc885208b8b"}
2432024-02-12T01:37:50.889Z{"msg":"[0] Transition from New to WaitActive","v":0,"name":"crucible","level":30,"time":"2024-02-12T01:37:49.204127846Z","hostname":"ip-10-150-1-57.us-west-2.compute.internal","pid":1181,"client":"0","":"downstairs","session_id":"9366ad0c-4703-4d1b-99e1-ddc885208b8b"}
2442024-02-12T01:37:50.889Z{"msg":"ds_transition from New to WaitActive","v":0,"name":"crucible","level":30,"time":"2024-02-12T01:37:49.204143306Z","hostname":"ip-10-150-1-57.us-west-2.compute.internal","pid":1181,"client":"1","":"downstairs","session_id":"9366ad0c-4703-4d1b-99e1-ddc885208b8b"}
2452024-02-12T01:37:50.889Z{"msg":"[1] Transition from New to WaitActive","v":0,"name":"crucible","level":30,"time":"2024-02-12T01:37:49.204160255Z","hostname":"ip-10-150-1-57.us-west-2.compute.internal","pid":1181,"client":"1","":"downstairs","session_id":"9366ad0c-4703-4d1b-99e1-ddc885208b8b"}
2462024-02-12T01:37:50.889Z{"msg":"ds_transition from New to WaitActive","v":0,"name":"crucible","level":30,"time":"2024-02-12T01:37:49.204209275Z","hostname":"ip-10-150-1-57.us-west-2.compute.internal","pid":1181,"client":"2","":"downstairs","session_id":"9366ad0c-4703-4d1b-99e1-ddc885208b8b"}
2472024-02-12T01:37:50.889Z{"msg":"[2] Transition from New to WaitActive","v":0,"name":"crucible","level":30,"time":"2024-02-12T01:37:49.204244304Z","hostname":"ip-10-150-1-57.us-west-2.compute.internal","pid":1181,"client":"2","":"downstairs","session_id":"9366ad0c-4703-4d1b-99e1-ddc885208b8b"}
2482024-02-12T01:37:50.889Z{"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-02-12T01:37:49.204718205Z","hostname":"ip-10-150-1-57.us-west-2.compute.internal","pid":1181,"client":"1","":"downstairs","session_id":"9366ad0c-4703-4d1b-99e1-ddc885208b8b"}
2492024-02-12T01:37:50.889Z{"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-02-12T01:37:49.204851772Z","hostname":"ip-10-150-1-57.us-west-2.compute.internal","pid":1181,"client":"2","":"downstairs","session_id":"9366ad0c-4703-4d1b-99e1-ddc885208b8b"}
2502024-02-12T01:37:50.889Z{"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-02-12T01:37:49.204894581Z","hostname":"ip-10-150-1-57.us-west-2.compute.internal","pid":1181,"client":"0","":"downstairs","session_id":"9366ad0c-4703-4d1b-99e1-ddc885208b8b"}
2512024-02-12T01:37:50.889Z{"msg":"ds_transition from WaitActive to WaitQuorum","v":0,"name":"crucible","level":30,"time":"2024-02-12T01:37:49.205088177Z","hostname":"ip-10-150-1-57.us-west-2.compute.internal","pid":1181,"client":"1","":"downstairs","session_id":"9366ad0c-4703-4d1b-99e1-ddc885208b8b"}
2522024-02-12T01:37:50.889Z{"msg":"[1] Transition from WaitActive to WaitQuorum","v":0,"name":"crucible","level":30,"time":"2024-02-12T01:37:49.205158936Z","hostname":"ip-10-150-1-57.us-west-2.compute.internal","pid":1181,"client":"1","":"downstairs","session_id":"9366ad0c-4703-4d1b-99e1-ddc885208b8b"}
2532024-02-12T01:37:50.889Z{"msg":"Waiting for true more clients to be ready","v":0,"name":"crucible","level":30,"time":"2024-02-12T01:37:49.205199705Z","hostname":"ip-10-150-1-57.us-west-2.compute.internal","pid":1181,"session_id":"9366ad0c-4703-4d1b-99e1-ddc885208b8b"}
2542024-02-12T01:37:50.889Z{"msg":"ds_transition from WaitActive to WaitQuorum","v":0,"name":"crucible","level":30,"time":"2024-02-12T01:37:49.205224325Z","hostname":"ip-10-150-1-57.us-west-2.compute.internal","pid":1181,"client":"2","":"downstairs","session_id":"9366ad0c-4703-4d1b-99e1-ddc885208b8b"}
2552024-02-12T01:37:50.889Z{"msg":"[2] Transition from WaitActive to WaitQuorum","v":0,"name":"crucible","level":30,"time":"2024-02-12T01:37:49.205257954Z","hostname":"ip-10-150-1-57.us-west-2.compute.internal","pid":1181,"client":"2","":"downstairs","session_id":"9366ad0c-4703-4d1b-99e1-ddc885208b8b"}
2562024-02-12T01:37:50.890Z{"msg":"Waiting for true more clients to be ready","v":0,"name":"crucible","level":30,"time":"2024-02-12T01:37:49.205282694Z","hostname":"ip-10-150-1-57.us-west-2.compute.internal","pid":1181,"session_id":"9366ad0c-4703-4d1b-99e1-ddc885208b8b"}
2572024-02-12T01:37:50.890Z{"msg":"ds_transition from WaitActive to WaitQuorum","v":0,"name":"crucible","level":30,"time":"2024-02-12T01:37:49.205309453Z","hostname":"ip-10-150-1-57.us-west-2.compute.internal","pid":1181,"client":"0","":"downstairs","session_id":"9366ad0c-4703-4d1b-99e1-ddc885208b8b"}
2582024-02-12T01:37:50.890Z{"msg":"[0] Transition from WaitActive to WaitQuorum","v":0,"name":"crucible","level":30,"time":"2024-02-12T01:37:49.205333382Z","hostname":"ip-10-150-1-57.us-west-2.compute.internal","pid":1181,"client":"0","":"downstairs","session_id":"9366ad0c-4703-4d1b-99e1-ddc885208b8b"}
2592024-02-12T01:37:50.890Z{"msg":"[0]R flush_numbers: [1660, 1660, 1660, 1660, 1660]","v":0,"name":"crucible","level":30,"time":"2024-02-12T01:37:49.205370962Z","hostname":"ip-10-150-1-57.us-west-2.compute.internal","pid":1181,"":"downstairs","":"downstairs","session_id":"9366ad0c-4703-4d1b-99e1-ddc885208b8b"}
2602024-02-12T01:37:50.890ZWait for a query_work_queue command to finish before sending IO
2612024-02-12T01:37:50.890Z{"msg":"[0]R generation: [31, 31, 31, 31, 31]","v":0,"name":"crucible","level":30,"time":"2024-02-12T01:37:49.205408011Z","hostname":"ip-10-150-1-57.us-west-2.compute.internal","pid":1181,"":"downstairs","":"downstairs","session_id":"9366ad0c-4703-4d1b-99e1-ddc885208b8b"}
2622024-02-12T01:37:50.890Z{"msg":"[0]R dirty: [false, false, false, false, false]","v":0,"name":"crucible","level":30,"time":"2024-02-12T01:37:49.2054396Z","hostname":"ip-10-150-1-57.us-west-2.compute.internal","pid":1181,"":"downstairs","":"downstairs","session_id":"9366ad0c-4703-4d1b-99e1-ddc885208b8b"}
2632024-02-12T01:37:50.890Z{"msg":"[1]R flush_numbers: [1660, 1660, 1660, 1660, 1660]","v":0,"name":"crucible","level":30,"time":"2024-02-12T01:37:49.20547202Z","hostname":"ip-10-150-1-57.us-west-2.compute.internal","pid":1181,"":"downstairs","":"downstairs","session_id":"9366ad0c-4703-4d1b-99e1-ddc885208b8b"}
2642024-02-12T01:37:50.890Z{"msg":"[1]R generation: [31, 31, 31, 31, 31]","v":0,"name":"crucible","level":30,"time":"2024-02-12T01:37:49.205506499Z","hostname":"ip-10-150-1-57.us-west-2.compute.internal","pid":1181,"":"downstairs","":"downstairs","session_id":"9366ad0c-4703-4d1b-99e1-ddc885208b8b"}
2652024-02-12T01:37:50.890Z{"msg":"[1]R dirty: [false, false, false, false, false]","v":0,"name":"crucible","level":30,"time":"2024-02-12T01:37:49.205532379Z","hostname":"ip-10-150-1-57.us-west-2.compute.internal","pid":1181,"":"downstairs","":"downstairs","session_id":"9366ad0c-4703-4d1b-99e1-ddc885208b8b"}
2662024-02-12T01:37:50.890Z{"msg":"[2]R flush_numbers: [1660, 1660, 1660, 1660, 1660]","v":0,"name":"crucible","level":30,"time":"2024-02-12T01:37:49.205548928Z","hostname":"ip-10-150-1-57.us-west-2.compute.internal","pid":1181,"":"downstairs","":"downstairs","session_id":"9366ad0c-4703-4d1b-99e1-ddc885208b8b"}
2672024-02-12T01:37:50.890Z{"msg":"[2]R generation: [31, 31, 31, 31, 31]","v":0,"name":"crucible","level":30,"time":"2024-02-12T01:37:49.205582228Z","hostname":"ip-10-150-1-57.us-west-2.compute.internal","pid":1181,"":"downstairs","":"downstairs","session_id":"9366ad0c-4703-4d1b-99e1-ddc885208b8b"}
2682024-02-12T01:37:50.890Z{"msg":"[2]R dirty: [false, false, false, false, false]","v":0,"name":"crucible","level":30,"time":"2024-02-12T01:37:49.205610657Z","hostname":"ip-10-150-1-57.us-west-2.compute.internal","pid":1181,"":"downstairs","":"downstairs","session_id":"9366ad0c-4703-4d1b-99e1-ddc885208b8b"}
2692024-02-12T01:37:50.890Z{"msg":"Max found gen is 32","v":0,"name":"crucible","level":30,"time":"2024-02-12T01:37:49.205636277Z","hostname":"ip-10-150-1-57.us-west-2.compute.internal","pid":1181,"":"downstairs","":"downstairs","session_id":"9366ad0c-4703-4d1b-99e1-ddc885208b8b"}
2702024-02-12T01:37:50.890Z{"msg":"Generation requested: 32 >= found:32","v":0,"name":"crucible","level":30,"time":"2024-02-12T01:37:49.205667696Z","hostname":"ip-10-150-1-57.us-west-2.compute.internal","pid":1181,"":"downstairs","":"downstairs","session_id":"9366ad0c-4703-4d1b-99e1-ddc885208b8b"}
2712024-02-12T01:37:50.890Z{"msg":"Next flush: 1661","v":0,"name":"crucible","level":30,"time":"2024-02-12T01:37:49.205730815Z","hostname":"ip-10-150-1-57.us-west-2.compute.internal","pid":1181,"":"downstairs","":"downstairs","session_id":"9366ad0c-4703-4d1b-99e1-ddc885208b8b"}
2722024-02-12T01:37:50.891Z{"msg":"All extents match","v":0,"name":"crucible","level":30,"time":"2024-02-12T01:37:49.205750065Z","hostname":"ip-10-150-1-57.us-west-2.compute.internal","pid":1181,"":"downstairs","":"downstairs","session_id":"9366ad0c-4703-4d1b-99e1-ddc885208b8b"}
2732024-02-12T01:37:50.891Z{"msg":"No downstairs reconciliation required","v":0,"name":"crucible","level":30,"time":"2024-02-12T01:37:49.205785124Z","hostname":"ip-10-150-1-57.us-west-2.compute.internal","pid":1181,"session_id":"9366ad0c-4703-4d1b-99e1-ddc885208b8b"}
2742024-02-12T01:37:50.891Z{"msg":"Transition from WaitQuorum to Active","v":0,"name":"crucible","level":30,"time":"2024-02-12T01:37:49.205812143Z","hostname":"ip-10-150-1-57.us-west-2.compute.internal","pid":1181,"client":"0"Region: es:10 ec:5 bs:4096 ts:204800 tb:50 max_io:50 or 204800
2752024-02-12T01:37:50.891Z,"":"downstairs","session_id":"9366ad0c-4703-4d1b-99e1-ddc885208b8b"}
2762024-02-12T01:37:50.891Z{"msg":"Transition from WaitQuorum to Active","v":0,"name":"crucible","level":30,"time":"2024-02-12T01:37:49.205840503Z","hostname":"ip-10-150-1-57.us-west-2.compute.internal","pid":1181,"client":"1","":"downstairs","session_id":"9366ad0c-4703-4d1b-99e1-ddc885208b8b"}
2772024-02-12T01:37:50.891Z{"msg":"Transition from WaitQuorum to Active","v":0,"name":"crucible","level":30,"time":"2024-02-12T01:37:49.205874812Z","hostname":"ip-10-150-1-57.us-west-2.compute.internal","pid":1181,"client":"2","":"downstairs","session_id":"9366ad0c-4703-4d1b-99e1-ddc885208b8b"}
2782024-02-12T01:37:50.891Z{"msg":"All required reconciliation work is completed","v":0,"name":"crucible","level":30,"time":"2024-02-12T01:37:49.205909211Z","hostname":"ip-10-150-1-57.us-west-2.compute.internal","pid":1181,"session_id":"9366ad0c-4703-4d1b-99e1-ddc885208b8b"}
2792024-02-12T01:37:50.891Z{"msg":"Set Downstairs and Upstairs active after reconciliation","v":0,"name":"crucible","level":30,"time":"2024-02-12T01:37:49.205942801Z","hostname":"ip-10-150-1-57.us-west-2.compute.internal","pid":1181,"session_id":"9366ad0c-4703-4d1b-99e1-ddc885208b8b"}
2802024-02-12T01:37:50.891Z{"msg":"3e29b8cc-2d65-4d8d-bb86-63e9e09f8bfb is now active with session: 9366ad0c-4703-4d1b-99e1-ddc885208b8b","v":0,"name":"crucible","level":30,"time":"2024-02-12T01:37:49.20597345Z","hostname":"ip-10-150-1-57.us-west-2.compute.internal","pid":1181,"session_id":"9366ad0c-4703-4d1b-99e1-ddc885208b8b"}
2812024-02-12T01:37:50.891Z{"msg":"Set Active after no reconciliation","v":0,"name":"crucible","level":30,"time":"2024-02-12T01:37:49.20599282Z","hostname":"ip-10-150-1-57.us-west-2.compute.internal","pid":1181,"session_id":"9366ad0c-4703-4d1b-99e1-ddc885208b8b"}
2822024-02-12T01:37:50.891Z{"msg":"The guest has finished waiting for activation with:32","v":0,"name":"crucible","level":30,"time":"2024-02-12T01:37:49.206011569Z","hostname":"ip-10-150-1-57.us-west-2.compute.internal","pid":1181}
2832024-02-12T01:37:50.891ZLoading write count information from file "/var/tmp/test_up/verify_file"
2842024-02-12T01:37:50.891ZRun Repair workload
2852024-02-12T01:37:50.895Z01/10 Write block 16 len 20480 data: 2 2 2 2 2
2862024-02-12T01:37:50.895Z02/10 Write block 25 len 32768 data: 2 2 2 2 2 2 2 2
2872024-02-12T01:37:50.898Z03/10 Write block 44 len 20480 data: 2 2 2 2 2
2882024-02-12T01:37:50.902Z04/10 Read block 0 len 40960
2892024-02-12T01:37:50.908Z05/10 Write block 17 len 12288 data: 3 3 3
2902024-02-12T01:37:50.911Z06/10 Flush
2912024-02-12T01:37:50.914Z07/10 Write block 0 len 16384 data: 2 2 2 2
2922024-02-12T01:37:50.918Z08/10 Read block 23 len 36864
2932024-02-12T01:37:50.926Z09/10 Read block 5 len 8192
2942024-02-12T01:37:50.929Z10/10 Read block 23 len 24576
2952024-02-12T01:37:50.934Z----------------------------------------------------------------
2962024-02-12T01:37:50.934Z Crucible gen:32 GIO:true work queues: Upstairs:0 downstairs:4
2972024-02-12T01:37:50.934ZStates: Active Active Active
2982024-02-12T01:37:50.934ZGW_ID ACK DSID TYPE BLOCKS DS:0 DS:1 DS:2 REPLAY
2992024-02-12T01:37:50.934Z 7 Acked 1006 Write 4 Done Done Done false
3002024-02-12T01:37:50.934Z 8 Acked 1007 Read 9 Done Done Done false
3012024-02-12T01:37:50.934Z 9 Acked 1008 Read 2 Done Done Done false
3022024-02-12T01:37:50.934Z 10 Acked 1009 Read 6 Done Done Done false
3032024-02-12T01:37:50.934Z STATES DS:0 DS:1 DS:2 TOTAL
3042024-02-12T01:37:50.934Z New 0 0 0 0
3052024-02-12T01:37:50.934Z Sent 0 0 0 0
3062024-02-12T01:37:50.934Z Done 4 4 4 12
3072024-02-12T01:37:50.934Z Skipped 0 0 0 0
3082024-02-12T01:37:50.934Z Error 0 0 0 0
3092024-02-12T01:37:50.934ZLast Flush: 1005 1005 1005
3102024-02-12T01:37:50.937ZDownstairs last five completed: 1005 1004 1003 1002 1001
3112024-02-12T01:37:50.937ZUpstairs last five completed: 10 9 8 7 6
3122024-02-12T01:37:50.937Z{"msg":"Guest handle has been dropped","v":0,"name":"crucible","level":40,"time":"2024-02-12T01:37:49.2543541Z","hostname":"ip-10-150-1-57.us-west-2.compute.internal","pid":1181}
3132024-02-12T01:37:50.937ZWrote out file "/var/tmp/test_up/verify_file"
3142024-02-12T01:37:50.938ZRepair part 1 passed
3152024-02-12T01:37:50.938Z
3162024-02-12T01:37:50.938ZKill the current downstairs
3172024-02-12T01:37:51.044Zrm -rf /var/tmp/test_up/8830
3182024-02-12T01:37:51.044ZNow put back the original so we have a mismatch
3192024-02-12T01:37:51.044Zmv /var/tmp/test_up/previous /var/tmp/test_up/8830
3202024-02-12T01:37:51.049ZRestart downstairs with old directory
3212024-02-12T01:37:51.102Z/var/tmp/bins/crucible-downstairs dump --no-color -d /var/tmp/test_up/8810 -d /var/tmp/test_up/8820 -d /var/tmp/test_up/8830
3222024-02-12T01:37:51.116ZEXT BLOCKS GEN0 GEN1 GEN2 FL0 FL1 FL2 D0 D1 D2 DIFF
3232024-02-12T01:37:51.120Z 0 000-009 31 31 31 1660 1660 1660 T T F <---
3242024-02-12T01:37:51.120Z 1 010-019 32 32 31 1661 1661 1660 F F F <---
3252024-02-12T01:37:51.120Z 2 020-029 32 32 31 1661 1661 1660 F F F <---
3262024-02-12T01:37:51.120Z 3 030-039 32 32 31 1661 1661 1660 F F F <---
3272024-02-12T01:37:51.120Z 4 040-049 32 32 31 1661 1661 1660 F F F <---
3282024-02-12T01:37:51.120ZMax gen: 32, Max flush: 1661
3292024-02-12T01:37:51.120ZError: Difference in extent metadata found!
3302024-02-12T01:37:51.120Zdump test found error as expected
3312024-02-12T01:37:51.120Z
3322024-02-12T01:37:51.120Z
3332024-02-12T01:37:51.120Z/var/tmp/bins/crutest deactivate --range -g 33 -q --key axRJJH+moTa0IfHpruLt7raezOdecgLR5Vi87Jg0zZI= -t 127.0.0.1:8810 -t 127.0.0.1:8820 -t 127.0.0.1:8830 --verify-out /var/tmp/test_up/verify_file --verify-in /var/tmp/test_up/verify_file
3342024-02-12T01:37:51.131Z{"msg":"Upstairs starts","v":0,"name":"crucible","level":30,"time":"2024-02-12T01:37:49.45196142Z","hostname":"ip-10-150-1-57.us-west-2.compute.internal","pid":1188}
3352024-02-12T01:37:51.131Z{"msg":"Crucible Version: BuildInfo {\n version: \"0.0.1\",\n git_sha: \"9f74bb5fe2be09de9f7a47f2db64d7dce836b79c\",\n git_commit_timestamp: \"2024-02-12T01:11:14.000000000Z\",\n git_branch: \"main\",\n rustc_semver: \"1.75.0\",\n rustc_channel: \"stable\",\n rustc_host_triple: \"x86_64-unknown-illumos\",\n rustc_commit_sha: \"82e1608dfa6e0b5569232559e3d385fea5a93112\",\n cargo_triple: \"x86_64-unknown-illumos\",\n debug: true,\n opt_level: 0,\n}","v":0,"name":"crucible","level":30,"time":"2024-02-12T01:37:49.452233035Z","hostname":"ip-10-150-1-57.us-west-2.compute.internal","pid":1188}
3362024-02-12T01:37:51.136Z{"msg":"Upstairs <-> Downstairs Message Version: 5","v":0,"name":"crucible","level":30,"time":"2024-02-12T01:37:49.452280663Z","hostname":"ip-10-150-1-57.us-west-2.compute.internal","pid":1188}
3372024-02-12T01:37:51.136Z{"msg":"Crucible eeaedf48-605c-42eb-803a-a8f9d07886c6 has session id: 843ab90b-fdd4-4846-be44-cef96d9b1321","v":0,"name":"crucible","level":30Crucible runtime is spawned
3382024-02-12T01:37:51.136Z,"time":"2024-02-12T01:37:49.452323943Z","hostname":"ip-10-150-1-57.us-west-2.compute.internal","pid":1188,"session_id":"843ab90b-fdd4-4846-be44-cef96d9b1321"}
3392024-02-12T01:37:51.136Z{"msg":"Upstairs opts: Upstairs UUID: eeaedf48-605c-42eb-803a-a8f9d07886c6, Targets: [127.0.0.1:8810, 127.0.0.1:8820, 127.0.0.1:8830], lossy: false, flush_timeout: None, key populated: true, cert_pem populated: false, key_pem populated: false, root_cert_pem populated: false, Control: None, read_only: false","v":0,"name":"crucible","level":30,"time":"2024-02-12T01:37:49.452372042Z","hostname":"ip-10-150-1-57.us-west-2.compute.internal","pid":1188,"session_id":"843ab90b-fdd4-4846-be44-cef96d9b1321"}
3402024-02-12T01:37:51.136Z{"msg":"Crucible stats registered with UUID: eeaedf48-605c-42eb-803a-a8f9d07886c6","v":0,"name":"crucible","level":30,"time":"2024-02-12T01:37:49.452408351Z","hostname":"ip-10-150-1-57.us-west-2.compute.internal","pid":1188,"session_id":"843ab90b-fdd4-4846-be44-cef96d9b1321"}
3412024-02-12T01:37:51.136Z{"msg":"The guest has requested activation with gen:33","v":0,"name":"crucible","level":30,"time":"2024-02-12T01:37:49.452425941Z","hostname":"ip-10-150-1-57.us-west-2.compute.internal","pid":1188}
3422024-02-12T01:37:51.136Z{"msg":"eeaedf48-605c-42eb-803a-a8f9d07886c6 active request set","v":0,"name":"crucible","level":30,"time":"2024-02-12T01:37:49.452573838Z","hostname":"ip-10-150-1-57.us-west-2.compute.internal","pid":1188,"session_id":"843ab90b-fdd4-4846-be44-cef96d9b1321"}
3432024-02-12T01:37:51.136Z{"msg":"sending connect oneshot to client","v":0,"name":"crucible","level":30,"time":"2024-02-12T01:37:49.452605697Z","hostname":"ip-10-150-1-57.us-west-2.compute.internal","pid":1188,"client":"0","":"downstairs","session_id":"843ab90b-fdd4-4846-be44-cef96d9b1321"}
3442024-02-12T01:37:51.136Z{"msg":"client set_active_request while in New; waiting...","v":0,"name":"crucible","level":30,"time":"2024-02-12T01:37:49.452625737Z","hostname":"ip-10-150-1-57.us-west-2.compute.internal","pid":1188,"client":"0","":"downstairs","session_id":"843ab90b-fdd4-4846-be44-cef96d9b1321"}
3452024-02-12T01:37:51.137Z{"msg":"sending connect oneshot to client","v":0,"name":"crucible","level":30,"time":"2024-02-12T01:37:49.452644127Z","hostname":"ip-10-150-1-57.us-west-2.compute.internal","pid":1188,"client":"1","":"downstairs","session_id":"843ab90b-fdd4-4846-be44-cef96d9b1321"}
3462024-02-12T01:37:51.137Z{"msg":"client set_active_request while in New; waiting...","v":0,"name":"crucible","level":30,"time":"2024-02-12T01:37:49.452686166Z","hostname":"ip-10-150-1-57.us-west-2.compute.internal","pid":1188,"client":"1","":"downstairs","session_id":"843ab90b-fdd4-4846-be44-cef96d9b1321"}
3472024-02-12T01:37:51.137Z{"msg":"sending connect oneshot to client","v":0,"name":"crucible","level":30,"time":"2024-02-12T01:37:49.452724515Z","hostname":"ip-10-150-1-57.us-west-2.compute.internal","pid":1188,"client":"2","":"downstairs","session_id":"843ab90b-fdd4-4846-be44-cef96d9b1321"}
3482024-02-12T01:37:51.137Z{"msg":"client set_active_request while in New; waiting...","v":0,"name":"crucible","level":30,"time":"2024-02-12T01:37:49.452750525Z","hostname":"ip-10-150-1-57.us-west-2.compute.internal","pid":1188,"client":"2","":"downstairs","session_id":"843ab90b-fdd4-4846-be44-cef96d9b1321"}
3492024-02-12T01:37:51.137Z{"msg":"connecting to 127.0.0.1:8820","v":0,"name":"crucible","level":30,"time":"2024-02-12T01:37:49.452783684Z","hostname":"ip-10-150-1-57.us-west-2.compute.internal","pid":1188,"":"io task","client":"1","":"downstairs","session_id":"843ab90b-fdd4-4846-be44-cef96d9b1321"}
3502024-02-12T01:37:51.137Z{"msg":"connecting to 127.0.0.1:8830","v":0,"name":"crucible","level":30,"time":"2024-02-12T01:37:49.452825723Z","hostname":"ip-10-150-1-57.us-west-2.compute.internal","pid":1188,"":"io task","client":"2","":"downstairs","session_id":"843ab90b-fdd4-4846-be44-cef96d9b1321"}
3512024-02-12T01:37:51.137Z{"msg":"connecting to 127.0.0.1:8810","v":0,"name":"crucible","level":30,"time":"2024-02-12T01:37:49.452871592Z","hostname":"ip-10-150-1-57.us-west-2.compute.internal","pid":1188,"":"io task","client":"0","":"downstairs","session_id":"843ab90b-fdd4-4846-be44-cef96d9b1321"}
3522024-02-12T01:37:51.137Z{"msg":"ds_connection connected","v":0,"name":"crucible","level":30,"time":"2024-02-12T01:37:49.452898602Z","hostname":"ip-10-150-1-57.us-west-2.compute.internal","pid":1188,"":"io task","client":"1","":"downstairs","session_id":"843ab90b-fdd4-4846-be44-cef96d9b1321"}
3532024-02-12T01:37:51.137Z{"msg":"ds_connection connected","v":0,"name":"crucible","level":30,"time":"2024-02-12T01:37:49.452940251Z","hostname":"ip-10-150-1-57.us-west-2.compute.internal","pid":1188,"":"io task","client":"0","":"downstairs","session_id":"843ab90b-fdd4-4846-be44-cef96d9b1321"}
3542024-02-12T01:37:51.137Z{"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-02-12T01:37:49.453150387Z","hostname":"ip-10-150-1-57.us-west-2.compute.internal","pid":1188,"":"io task","client":"2","":"downstairs","session_id":"843ab90b-fdd4-4846-be44-cef96d9b1321"}
3552024-02-12T01:37:51.137Z{"msg":"client task is sending Done(ConnectionFailed(Os { code: 146, kind: ConnectionRefused, message: \"Connection refused\" }))","v":0,"name":"crucible","level":40,"time":"2024-02-12T01:37:49.453220225Z","hostname":"ip-10-150-1-57.us-west-2.compute.internal","pid":1188,"":"io task","client":"2","":"downstairs","session_id":"843ab90b-fdd4-4846-be44-cef96d9b1321"}
3562024-02-12T01:37:51.137Z{"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-02-12T01:37:49.453330203Z","hostname":"ip-10-150-1-57.us-west-2.compute.internal","pid":1188,"session_id":"843ab90b-fdd4-4846-be44-cef96d9b1321"}
3572024-02-12T01:37:51.137Z{"msg":"Gone missing, transition from New to Disconnected","v":0,"name":"crucible","level":30,"time":"2024-02-12T01:37:49.453390132Z","hostname":"ip-10-150-1-57.us-west-2.compute.internal","pid":1188,"client":"2","":"downstairs","session_id":"843ab90b-fdd4-4846-be44-cef96d9b1321"}
3582024-02-12T01:37:51.138Z{"msg":"Disconnected -> New","v":0,"name":"crucible","level":30,"time":"2024-02-12T01:37:49.453417761Z","hostname":"ip-10-150-1-57.us-west-2.compute.internal","pid":1188,"client":"2","":"downstairs","session_id":"843ab90b-fdd4-4846-be44-cef96d9b1321"}
3592024-02-12T01:37:51.138Z{"msg":"client task is exiting","v":0,"name":"crucible","level":30,"time":"2024-02-12T01:37:49.453442551Z","hostname":"ip-10-150-1-57.us-west-2.compute.internal","pid":1188,"":"io task","client":"2","":"downstairs","session_id":"843ab90b-fdd4-4846-be44-cef96d9b1321"}
3602024-02-12T01:37:51.138Z{"msg":"ds_transition from New to WaitActive","v":0,"name":"crucible","level":30,"time":"2024-02-12T01:37:49.453557419Z","hostname":"ip-10-150-1-57.us-west-2.compute.internal","pid":1188,"client":"0","":"downstairs","session_id":"843ab90b-fdd4-4846-be44-cef96d9b1321"}
3612024-02-12T01:37:51.138Z{"msg":"[0] Transition from New to WaitActive","v":0,"name":"crucible","level":30,"time":"2024-02-12T01:37:49.453585148Z","hostname":"ip-10-150-1-57.us-west-2.compute.internal","pid":1188,"client":"0","":"downstairs","session_id":"843ab90b-fdd4-4846-be44-cef96d9b1321"}
3622024-02-12T01:37:51.138Z{"msg":"ds_transition from New to WaitActive","v":0,"name":"crucible","level":30,"time":"2024-02-12T01:37:49.453599928Z","hostname":"ip-10-150-1-57.us-west-2.compute.internal","pid":1188,"client":"1","":"downstairs","session_id":"843ab90b-fdd4-4846-be44-cef96d9b1321"}
3632024-02-12T01:37:51.138Z{"msg":"[1] Transition from New to WaitActive","v":0,"name":"crucible","level":30,"time":"2024-02-12T01:37:49.453614218Z","hostname":"ip-10-150-1-57.us-west-2.compute.internal","pid":1188,"client":"1","":"downstairs","session_id":"843ab90b-fdd4-4846-be44-cef96d9b1321"}
3642024-02-12T01:37:51.138Z{"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-02-12T01:37:49.454209996Z","hostname":"ip-10-150-1-57.us-west-2.compute.internal","pid":1188,"client":"0","":"downstairs","session_id":"843ab90b-fdd4-4846-be44-cef96d9b1321"}
3652024-02-12T01:37:51.138Z{"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-02-12T01:37:49.454246805Z","hostname":"ip-10-150-1-57.us-west-2.compute.internal","pid":1188,"client":"1","":"downstairs","session_id":"843ab90b-fdd4-4846-be44-cef96d9b1321"}
3662024-02-12T01:37:51.138Z{"msg":"ds_transition from WaitActive to WaitQuorum","v":0,"name":"crucible","level":30,"time":"2024-02-12T01:37:49.45452805Z","hostname":"ip-10-150-1-57.us-west-2.compute.internal","pid":1188,"client":"1","":"downstairs","session_id":"843ab90b-fdd4-4846-be44-cef96d9b1321"}
3672024-02-12T01:37:51.138Z{"msg":"[1] Transition from WaitActive to WaitQuorum","v":0,"name":"crucible","level":30,"time":"2024-02-12T01:37:49.454566909Z","hostname":"ip-10-150-1-57.us-west-2.compute.internal","pid":1188,"client":"1","":"downstairs","session_id":"843ab90b-fdd4-4846-be44-cef96d9b1321"}
3682024-02-12T01:37:51.138Z{"msg":"Waiting for true more clients to be ready","v":0,"name":"crucible","level":30,"time":"2024-02-12T01:37:49.454583629Z","hostname":"ip-10-150-1-57.us-west-2.compute.internal","pid":1188,"session_id":"843ab90b-fdd4-4846-be44-cef96d9b1321"}
3692024-02-12T01:37:51.138Z{"msg":"ds_transition from WaitActive to WaitQuorum","v":0,"name":"crucible","level":30,"time":"2024-02-12T01:37:49.454603709Z","hostname":"ip-10-150-1-57.us-west-2.compute.internal","pid":1188,"client":"0","":"downstairs","session_id":"843ab90b-fdd4-4846-be44-cef96d9b1321"}
3702024-02-12T01:37:51.138Z{"msg":"[0] Transition from WaitActive to WaitQuorum","v":0,"name":"crucible","level":30,"time":"2024-02-12T01:37:49.454617508Z","hostname":"ip-10-150-1-57.us-west-2.compute.internal","pid":1188,"client":"0","":"downstairs","session_id":"843ab90b-fdd4-4846-be44-cef96d9b1321"}
3712024-02-12T01:37:51.139Z{"msg":"Waiting for true more clients to be ready","v":0,"name":"crucible","level":30,"time":"2024-02-12T01:37:49.454631188Z","hostname":"ip-10-150-1-57.us-west-2.compute.internal","pid":1188,"session_id":"843ab90b-fdd4-4846-be44-cef96d9b1321"}
3722024-02-12T01:37:52.135Z{"msg":"connecting to 127.0.0.1:8830","v":0,"name":"crucible","level":30,"time":"2024-02-12T01:37:50.45535666Z","hostname":"ip-10-150-1-57.us-west-2.compute.internal","pid":1188,"":"io task","client":"2","":"downstairs","session_id":"843ab90b-fdd4-4846-be44-cef96d9b1321"}
3732024-02-12T01:37:52.135Z{"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-02-12T01:37:50.455457138Z","hostname":"ip-10-150-1-57.us-west-2.compute.internal","pid":1188,"":"io task","client":"2","":"downstairs","session_id":"843ab90b-fdd4-4846-be44-cef96d9b1321"}
3742024-02-12T01:37:52.135Z{"msg":"client task is sending Done(ConnectionFailed(Os { code: 146, kind: ConnectionRefused, message: \"Connection refused\" }))","v":0,"name":"crucible","level":40,"time":"2024-02-12T01:37:50.455492437Z","hostname":"ip-10-150-1-57.us-west-2.compute.internal","pid":1188,"":"io task","client":"2","":"downstairs","session_id":"843ab90b-fdd4-4846-be44-cef96d9b1321"}
3752024-02-12T01:37:52.135Z{"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-02-12T01:37:50.455527517Z","hostname":"ip-10-150-1-57.us-west-2.compute.internal","pid":1188,"session_id":"843ab90b-fdd4-4846-be44-cef96d9b1321"}
3762024-02-12T01:37:52.138Z{"msg":"Gone missing, transition from New to Disconnected","v":0,"name":"crucible","level":30,"time":"2024-02-12T01:37:50.455553716Z","hostname":"ip-10-150-1-57.us-west-2.compute.internal","pid":1188,"client":"2","":"downstairs","session_id":"843ab90b-fdd4-4846-be44-cef96d9b1321"}
3772024-02-12T01:37:52.138Z{"msg":"Disconnected -> New","v":0,"name":"crucible","level":30,"time":"2024-02-12T01:37:50.455625055Z","hostname":"ip-10-150-1-57.us-west-2.compute.internal","pid":1188,"client":"2","":"downstairs","session_id":"843ab90b-fdd4-4846-be44-cef96d9b1321"}
3782024-02-12T01:37:52.138Z{"msg":"client task is exiting","v":0,"name":"crucible","level":30,"time":"2024-02-12T01:37:50.455767872Z","hostname":"ip-10-150-1-57.us-west-2.compute.internal","pid":1188,"":"io task","client":"2","":"downstairs","session_id":"843ab90b-fdd4-4846-be44-cef96d9b1321"}
3792024-02-12T01:37:53.136Z{"msg":"connecting to 127.0.0.1:8830","v":0,"name":"crucible","level":30,"time":"2024-02-12T01:37:51.456417855Z","hostname":"ip-10-150-1-57.us-west-2.compute.internal","pid":1188,"":"io task","client":"2","":"downstairs","session_id":"843ab90b-fdd4-4846-be44-cef96d9b1321"}
3802024-02-12T01:37:53.136Z{"msg":"ds_connection connected","v":0,"name":"crucible","level":30,"time":"2024-02-12T01:37:51.456550493Z","hostname":"ip-10-150-1-57.us-west-2.compute.internal","pid":1188,"":"io task","client":"2","":"downstairs","session_id":"843ab90b-fdd4-4846-be44-cef96d9b1321"}
3812024-02-12T01:37:53.143Z{"msg":"ds_transition from New to WaitActive","v":0,"name":"crucible","level":30,"time":"2024-02-12T01:37:51.457385327Z","hostname":"ip-10-150-1-57.us-west-2.compute.internal","pid":1188,"client":"2","":"downstairs","session_id":"843ab90b-fdd4-4846-be44-cef96d9b1321"}
3822024-02-12T01:37:53.143Z{"msg":"[2] Transition from New to WaitActive","v":0,"name":"crucible","level":30,"time":"2024-02-12T01:37:51.457428926Z","hostname":"ip-10-150-1-57.us-west-2.compute.internal","pid":1188,"client":"2","":"downstairs","session_id":"843ab90b-fdd4-4846-be44-cef96d9b1321"}
3832024-02-12T01:37:53.143Z{"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-02-12T01:37:51.457918276Z","hostname":"ip-10-150-1-57.us-west-2.compute.internal","pid":1188,"client":"2","":"downstairs","session_id":"843ab90b-fdd4-4846-be44-cef96d9b1321"}
3842024-02-12T01:37:53.143Z{"msg":"ds_transition from WaitActive to WaitQuorum","v":0,"name":"crucible","level":30,"time":"2024-02-12T01:37:51.458201951Z","hostname":"ip-10-150-1-57.us-west-2.compute.internal","pid":1188,"client":"2","":"downstairs","session_id":"843ab90b-fdd4-4846-be44-cef96d9b1321"}
3852024-02-12T01:37:53.143Z{"msg":"[2] Transition from WaitActive to WaitQuorum","v":0,"name":"crucible","level":30,"time":"2024-02-12T01:37:51.45822903Z","hostname":"ip-10-150-1-57.us-west-2.compute.internal","pid":1188,"client":"2","":"downstairs","session_id":"843ab90b-fdd4-4846-be44-cef96d9b1321"}
3862024-02-12T01:37:53.143Z{"msg":"[0]R flush_numbers: [1660, 1661, 1661, 1661, 1661]","v":0,"name":"crucible","level":30,"time":"2024-02-12T01:37:51.45824407Z","hostname":"ip-10-150-1-57.us-west-2.compute.internal","pid":1188,"":"downstairs","":"downstairs","session_id":"843ab90b-fdd4-4846-be44-cef96d9b1321"}
3872024-02-12T01:37:53.143Z{"msg":"[0]R generation: [31, 32, 32, 32, 32]","v":0,"name":"crucible","level":30,"time":"2024-02-12T01:37:51.45825818Z","hostname":"ip-10-150-1-57.us-west-2.compute.internal","pid":1188,"":"downstairs","":"downstairs","session_id":"843ab90b-fdd4-4846-be44-cef96d9b1321"}
3882024-02-12T01:37:53.143Z{"msg":"[0]R dirty: [true, false, false, false, false]","v":0,"name":"crucible","level":30,"time":"2024-02-12T01:37:51.458284469Z","hostname":"ip-10-150-1-57.us-west-2.compute.internal","pid":1188,"":"downstairs","":"downstairs","session_id":"843ab90b-fdd4-4846-be44-cef96d9b1321"}
3892024-02-12T01:37:53.143Z{"msg":"[1]R flush_numbers: [1660, 1661, 1661, 1661, 1661]","v":0,"name":"crucible","level":30,"time":"2024-02-12T01:37:51.458305809Z","hostname":"ip-10-150-1-57.us-west-2.compute.internal","pid":1188,"":"downstairs","":"downstairs","session_id":"843ab90b-fdd4-4846-be44-cef96d9b1321"}
3902024-02-12T01:37:53.143Z{"msg":"[1]R generation: [31, 32, 32, 32, 32]","v":0,"name":"crucible","level":30,"time":"2024-02-12T01:37:51.458332408Z","hostname":"ip-10-150-1-57.us-west-2.compute.internal","pid":1188,"":"downstairs","":"downstairs","session_id":"843ab90b-fdd4-4846-be44-cef96d9b1321"}
3912024-02-12T01:37:53.143Z{"msg":"[1]R dirty: [true, false, false, false, false]","v":0,"name":"crucible","level":30,"time":"2024-02-12T01:37:51.458354618Z","hostname":"ip-10-150-1-57.us-west-2.compute.internal","pid":1188,"":"downstairs","":"downstairs","session_id":"843ab90b-fdd4-4846-be44-cef96d9b1321"}
3922024-02-12T01:37:53.143Z{"msg":"[2]R flush_numbers: [1660, 1660, 1660, 1660, 1660]","v":0,"name":"crucible","level":30,"time":"2024-02-12T01:37:51.458387147Z","hostname":"ip-10-150-1-57.us-west-2.compute.internal","pid":1188,"":"downstairs","":"downstairs","session_id":"843ab90b-fdd4-4846-be44-cef96d9b1321"}
3932024-02-12T01:37:53.143Z{"msg":"[2]R generation: [31, 31, 31, 31, 31]","v":0,"name":"crucible","level":30,"time":"2024-02-12T01:37:51.458422656Z","hostname":"ip-10-150-1-57.us-west-2.compute.internal","pid":1188,"":"downstairs","":"downstairs","session_id":"843ab90b-fdd4-4846-be44-cef96d9b1321"}
3942024-02-12T01:37:53.143Z{"msg":"[2]R dirty: [false, false, false, false, false]","v":0,"name":"crucible","level":30,"time":"2024-02-12T01:37:51.458454106Z","hostname":"ip-10-150-1-57.us-west-2.compute.internal","pid":1188,"":"downstairs","":"downstairs","session_id":"843ab90b-fdd4-4846-be44-cef96d9b1321"}
3952024-02-12T01:37:53.143Z{"msg":"Max found gen is 33","v":0,"name":"crucible","level":30,"time":"2024-02-12T01:37:51.458478455Z","hostname":"ip-10-150-1-57.us-west-2.compute.internal","pid":1188,"":"downstairs","":"downstairs","session_id":"843ab90b-fdd4-4846-be44-cef96d9b1321"}
3962024-02-12T01:37:53.143Z{"msg":"Generation requested: 33 >= found:33","v":0,"name":"crucible","level":30,"time":"2024-02-12T01:37:51.458506195Z","hostname":"ip-10-150-1-57.us-west-2.compute.internal","pid":1188,"":"downstairs","":"downstairs","session_id":"843ab90b-fdd4-4846-be44-cef96d9b1321"}
3972024-02-12T01:37:53.143Z{"msg":"Next flush: 1662","v":0,"name":"crucible","level":30,"time":"2024-02-12T01:37:51.458528574Z","hostname":"ip-10-150-1-57.us-west-2.compute.internal","pid":1188,"":"downstairs","":"downstairs","session_id":"843ab90b-fdd4-4846-be44-cef96d9b1321"}
3982024-02-12T01:37:53.143Z{"msg":"Extents 0 dirty","v":0,"name":"crucible","level":30,"time":"2024-02-12T01:37:51.458556124Z","hostname":"ip-10-150-1-57.us-west-2.compute.internal","pid":1188,"":"mend","":"downstairs","":"downstairs","session_id":"843ab90b-fdd4-4846-be44-cef96d9b1321"}
3992024-02-12T01:37:53.144Z{"msg":"First source client ID for extent 0","v":0,"name":"crucible","level":30,"time":"2024-02-12T01:37:51.458581333Z","hostname":"ip-10-150-1-57.us-west-2.compute.internal","pid":1188,"mrl":"dirty","":"mend","":"downstairs","":"downstairs","session_id":"843ab90b-fdd4-4846-be44-cef96d9b1321"}
4002024-02-12T01:37:53.144Z{"msg":"extent:0 gens: 31 31 31","v":0,"name":"crucible","level":30,"time":"2024-02-12T01:37:51.458613973Z","hostname":"ip-10-150-1-57.us-west-2.compute.internal","pid":1188,"mrl":"dirty","":"mend","":"downstairs","":"downstairs","session_id":"843ab90b-fdd4-4846-be44-cef96d9b1321"}
4012024-02-12T01:37:53.144Z{"msg":"extent:0 flush: 1660 1660 1660 scs: [ClientId(0), ClientId(1), ClientId(2)]","v":0,"name":"crucible","level":30,"time":"2024-02-12T01:37:51.458641502Z","hostname":"ip-10-150-1-57.us-west-2.compute.internal","pid":1188,"mrl":"dirty","":"mend","":"downstairs","":"downstairs","session_id":"843ab90b-fdd4-4846-be44-cef96d9b1321"}
4022024-02-12T01:37:53.144Z{"msg":"max_flush now has: [ClientId(0), ClientId(1), ClientId(2)]","v":0,"name":"crucible","level":30,"time":"2024-02-12T01:37:51.458672322Z","hostname":"ip-10-150-1-57.us-west-2.compute.internal","pid":1188,"mrl":"dirty","":"mend","":"downstairs","":"downstairs","session_id":"843ab90b-fdd4-4846-be44-cef96d9b1321"}
4032024-02-12T01:37:53.144Z{"msg":"extent:0 dirty: true true false","v":0,"name":"crucible","level":30,"time":"2024-02-12T01:37:51.458698581Z","hostname":"ip-10-150-1-57.us-west-2.compute.internal","pid":1188,"mrl":"dirty","":"mend","":"downstairs","":"downstairs","session_id":"843ab90b-fdd4-4846-be44-cef96d9b1321"}
4042024-02-12T01:37:53.144Z{"msg":"find dest for source 0 for extent at index 0","v":0,"name":"crucible","level":30,"time":"2024-02-12T01:37:51.45872935Z","hostname":"ip-10-150-1-57.us-west-2.compute.internal","pid":1188,"mrl":"dirty","":"mend","":"downstairs","":"downstairs","session_id":"843ab90b-fdd4-4846-be44-cef96d9b1321"}
4052024-02-12T01:37:53.144Z{"msg":"source 0, add dest 1 source flush","v":0,"name":"crucible","level":30,"time":"2024-02-12T01:37:51.45875537Z","hostname":"ip-10-150-1-57.us-west-2.compute.internal","pid":1188,"mrl":"dirty","":"mend","":"downstairs","":"downstairs","session_id":"843ab90b-fdd4-4846-be44-cef96d9b1321"}
4062024-02-12T01:37:53.144Z{"msg":"source 0, add dest 2 source flush","v":0,"name":"crucible","level":30,"time":"2024-02-12T01:37:51.458787109Z","hostname":"ip-10-150-1-57.us-west-2.compute.internal","pid":1188,"mrl":"dirty","":"mend","":"downstairs","":"downstairs","session_id":"843ab90b-fdd4-4846-be44-cef96d9b1321"}
4072024-02-12T01:37:53.144Z{"msg":"Extent 1 has flush number mismatch","v":0,"name":"crucible","level":30,"time":"2024-02-12T01:37:51.458813519Z","hostname":"ip-10-150-1-57.us-west-2.compute.internal","pid":1188,"":"mend","":"downstairs","":"downstairs","session_id":"843ab90b-fdd4-4846-be44-cef96d9b1321"}
4082024-02-12T01:37:53.144Z{"msg":"First source client ID for extent 1","v":0,"name":"crucible","level":30,"time":"2024-02-12T01:37:51.458845348Z","hostname":"ip-10-150-1-57.us-west-2.compute.internal","pid":1188,"mrl":"flush_mismatch","":"mend","":"downstairs","":"downstairs","session_id":"843ab90b-fdd4-4846-be44-cef96d9b1321"}
4092024-02-12T01:37:53.144Z{"msg":"extent:1 gens: 32 32 31","v":0,"name":"crucible","level":30,"time":"2024-02-12T01:37:51.458871438Z","hostname":"ip-10-150-1-57.us-west-2.compute.internal","pid":1188,"mrl":"flush_mismatch","":"mend","":"downstairs","":"downstairs","session_id":"843ab90b-fdd4-4846-be44-cef96d9b1321"}
4102024-02-12T01:37:53.144Z{"msg":"extent:1 flush: 1661 1661 1660 scs: [ClientId(0), ClientId(1)]","v":0,"name":"crucible","level":30,"time":"2024-02-12T01:37:51.458901517Z","hostname":"ip-10-150-1-57.us-west-2.compute.internal","pid":1188,"mrl":"flush_mismatch","":"mend","":"downstairs","":"downstairs","session_id":"843ab90b-fdd4-4846-be44-cef96d9b1321"}
4112024-02-12T01:37:53.144Z{"msg":"max_flush now has: [ClientId(0), ClientId(1)]","v":0,"name":"crucible","level":30,"time":"2024-02-12T01:37:51.458972126Z","hostname":"ip-10-150-1-57.us-west-2.compute.internal","pid":1188,"mrl":"flush_mismatch","":"mend","":"downstairs","":"downstairs","session_id":"843ab90b-fdd4-4846-be44-cef96d9b1321"}
4122024-02-12T01:37:53.144Z{"msg":"extent:1 dirty: false false false","v":0,"name":"crucible","level":30,"time":"2024-02-12T01:37:51.459018355Z","hostname":"ip-10-150-1-57.us-west-2.compute.internal","pid":1188,"mrl":"flush_mismatch","":"mend","":"downstairs","":"downstairs","session_id":"843ab90b-fdd4-4846-be44-cef96d9b1321"}
4132024-02-12T01:37:53.144Z{"msg":"No maxes found, left with: [ClientId(0), ClientId(1)]","v":0,"name":"crucible","level":30,"time":"2024-02-12T01:37:51.459061704Z","hostname":"ip-10-150-1-57.us-west-2.compute.internal","pid":1188,"mrl":"flush_mismatch","":"mend","":"downstairs","":"downstairs","session_id":"843ab90b-fdd4-4846-be44-cef96d9b1321"}
4142024-02-12T01:37:53.144Z{"msg":"find dest for source 0 for extent at index 1","v":0,"name":"crucible","level":30,"time":"2024-02-12T01:37:51.459085343Z","hostname":"ip-10-150-1-57.us-west-2.compute.internal","pid":1188,"mrl":"flush_mismatch","":"mend","":"downstairs","":"downstairs","session_id":"843ab90b-fdd4-4846-be44-cef96d9b1321"}
4152024-02-12T01:37:53.144Z{"msg":"source 0, add dest 2 gen","v":0,"name":"crucible","level":30,"time":"2024-02-12T01:37:51.459117673Z","hostname":"ip-10-150-1-57.us-west-2.compute.internal","pid":1188,"mrl":"flush_mismatch","":"mend","":"downstairs","":"downstairs","session_id":"843ab90b-fdd4-4846-be44-cef96d9b1321"}
4162024-02-12T01:37:53.144Z{"msg":"Extent 2 has flush number mismatch","v":0,"name":"crucible","level":30,"time":"2024-02-12T01:37:51.459134143Z","hostname":"ip-10-150-1-57.us-west-2.compute.internal","pid":1188,"":"mend","":"downstairs","":"downstairs","session_id":"843ab90b-fdd4-4846-be44-cef96d9b1321"}
4172024-02-12T01:37:53.144Z{"msg":"First source client ID for extent 2","v":0,"name":"crucible","level":30,"time":"2024-02-12T01:37:51.459148132Z","hostname":"ip-10-150-1-57.us-west-2.compute.internal","pid":1188,"mrl":"flush_mismatch","":"mend","":"downstairs","":"downstairs","session_id":"843ab90b-fdd4-4846-be44-cef96d9b1321"}
4182024-02-12T01:37:53.144Z{"msg":"extent:2 gens: 32 32 31","v":0,"name":"crucible","level":30,"time":"2024-02-12T01:37:51.459166442Z","hostname":"ip-10-150-1-57.us-west-2.compute.internal","pid":1188,"mrl":"flush_mismatch","":"mend","":"downstairs","":"downstairs","session_id":"843ab90b-fdd4-4846-be44-cef96d9b1321"}
4192024-02-12T01:37:53.144Z{"msg":"extent:2 flush: 1661 1661 1660 scs: [ClientId(0), ClientId(1)]","v":0,"name":"crucible","level":30,"time":"2024-02-12T01:37:51.459192601Z","hostname":"ip-10-150-1-57.us-west-2.compute.internal","pid":1188,"mrl":"flush_mismatch","":"mend","":"downstairs","":"downstairs","session_id":"843ab90b-fdd4-4846-be44-cef96d9b1321"}
4202024-02-12T01:37:53.144Z{"msg":"max_flush now has: [ClientId(0), ClientId(1)]","v":0,"name":"crucible","level":30,"time":"2024-02-12T01:37:51.459240051Z","hostname":"ip-10-150-1-57.us-west-2.compute.internal","pid":1188,"mrl":"flush_mismatch","":"mend","":"downstairs","":"downstairs","session_id":"843ab90b-fdd4-4846-be44-cef96d9b1321"}
4212024-02-12T01:37:53.144Z{"msg":"extent:2 dirty: false false false","v":0,"name":"crucible","level":30,"time":"2024-02-12T01:37:51.45928576Z","hostname":"ip-10-150-1-57.us-west-2.compute.internal","pid":1188,"mrl":"flush_mismatch","":"mend","":"downstairs","":"downstairs","session_id":"843ab90b-fdd4-4846-be44-cef96d9b1321"}
4222024-02-12T01:37:53.145Z{"msg":"No maxes found, left with: [ClientId(0), ClientId(1)]","v":0,"name":"crucible","level":30,"time":"2024-02-12T01:37:51.459329899Z","hostname":"ip-10-150-1-57.us-west-2.compute.internal","pid":1188,"mrl":"flush_mismatch","":"mend","":"downstairs","":"downstairs","session_id":"843ab90b-fdd4-4846-be44-cef96d9b1321"}
4232024-02-12T01:37:53.145Z{"msg":"find dest for source 0 for extent at index 2","v":0,"name":"crucible","level":30,"time":"2024-02-12T01:37:51.459373338Z","hostname":"ip-10-150-1-57.us-west-2.compute.internal","pid":1188,"mrl":"flush_mismatch","":"mend","":"downstairs","":"downstairs","session_id":"843ab90b-fdd4-4846-be44-cef96d9b1321"}
4242024-02-12T01:37:53.145Z{"msg":"source 0, add dest 2 gen","v":0,"name":"crucible","level":30,"time":"2024-02-12T01:37:51.459411737Z","hostname":"ip-10-150-1-57.us-west-2.compute.internal","pid":1188,"mrl":"flush_mismatch","":"mend","":"downstairs","":"downstairs","session_id":"843ab90b-fdd4-4846-be44-cef96d9b1321"}
4252024-02-12T01:37:53.145Z{"msg":"Extent 3 has flush number mismatch","v":0,"name":"crucible","level":30,"time":"2024-02-12T01:37:51.459430107Z","hostname":"ip-10-150-1-57.us-west-2.compute.internal","pid":1188,"":"mend","":"downstairs","":"downstairs","session_id":"843ab90b-fdd4-4846-be44-cef96d9b1321"}
4262024-02-12T01:37:53.145Z{"msg":"First source client ID for extent 3","v":0,"name":"crucible","level":30,"time":"2024-02-12T01:37:51.459453096Z","hostname":"ip-10-150-1-57.us-west-2.compute.internal","pid":1188,"mrl":"flush_mismatch","":"mend","":"downstairs","":"downstairs","session_id":"843ab90b-fdd4-4846-be44-cef96d9b1321"}
4272024-02-12T01:37:53.145Z{"msg":"extent:3 gens: 32 32 31","v":0,"name":"crucible","level":30,"time":"2024-02-12T01:37:51.459468026Z","hostname":"ip-10-150-1-57.us-west-2.compute.internal","pid":1188,"mrl":"flush_mismatch","":"mend","":"downstairs","":"downstairs","session_id":"843ab90b-fdd4-4846-be44-cef96d9b1321"}
4282024-02-12T01:37:53.145Z{"msg":"extent:3 flush: 1661 1661 1660 scs: [ClientId(0), ClientId(1)]","v":0,"name":"crucible","level":30,"time":"2024-02-12T01:37:51.459483656Z","hostname":"ip-10-150-1-57.us-west-2.compute.internal","pid":1188,"mrl":"flush_mismatch","":"mend","":"downstairs","":"downstairs","session_id":"843ab90b-fdd4-4846-be44-cef96d9b1321"}
4292024-02-12T01:37:53.145Z{"msg":"max_flush now has: [ClientId(0), ClientId(1)]","v":0,"name":"crucible","level":30,"time":"2024-02-12T01:37:51.459498766Z","hostname":"ip-10-150-1-57.us-west-2.compute.internal","pid":1188,"mrl":"flush_mismatch","":"mend","":"downstairs","":"downstairs","session_id":"843ab90b-fdd4-4846-be44-cef96d9b1321"}
4302024-02-12T01:37:53.145Z{"msg":"extent:3 dirty: false false false","v":0,"name":"crucible","level":30,"time":"2024-02-12T01:37:51.459521075Z","hostname":"ip-10-150-1-57.us-west-2.compute.internal","pid":1188,"mrl":"flush_mismatch","":"mend","":"downstairs","":"downstairs","session_id":"843ab90b-fdd4-4846-be44-cef96d9b1321"}
4312024-02-12T01:37:53.145Z{"msg":"No maxes found, left with: [ClientId(0), ClientId(1)]","v":0,"name":"crucible","level":30,"time":"2024-02-12T01:37:51.459536155Z","hostname":"ip-10-150-1-57.us-west-2.compute.internal","pid":1188,"mrl":"flush_mismatch","":"mend","":"downstairs","":"downstairs","session_id":"843ab90b-fdd4-4846-be44-cef96d9b1321"}
4322024-02-12T01:37:53.145Z{"msg":"find dest for source 0 for extent at index 3","v":0,"name":"crucible","level":30,"time":"2024-02-12T01:37:51.459551485Z","hostname":"ip-10-150-1-57.us-west-2.compute.internal","pid":1188,"mrl":"flush_mismatch","":"mend","":"downstairs","":"downstairs","session_id":"843ab90b-fdd4-4846-be44-cef96d9b1321"}
4332024-02-12T01:37:53.145Z{"msg":"source 0, add dest 2 gen","v":0,"name":"crucible","level":30,"time":"2024-02-12T01:37:51.459565814Z","hostname":"ip-10-150-1-57.us-west-2.compute.internal","pid":1188,"mrl":"flush_mismatch","":"mend","":"downstairs","":"downstairs","session_id":"843ab90b-fdd4-4846-be44-cef96d9b1321"}
4342024-02-12T01:37:53.145Z{"msg":"Extent 4 has flush number mismatch","v":0,"name":"crucible","level":30,"time":"2024-02-12T01:37:51.459587744Z","hostname":"ip-10-150-1-57.us-west-2.compute.internal","pid":1188,"":"mend","":"downstairs","":"downstairs","session_id":"843ab90b-fdd4-4846-be44-cef96d9b1321"}
4352024-02-12T01:37:53.145Z{"msg":"First source client ID for extent 4","v":0,"name":"crucible","level":30,"time":"2024-02-12T01:37:51.459601704Z","hostname":"ip-10-150-1-57.us-west-2.compute.internal","pid":1188,"mrl":"flush_mismatch","":"mend","":"downstairs","":"downstairs","session_id":"843ab90b-fdd4-4846-be44-cef96d9b1321"}
4362024-02-12T01:37:53.145Z{"msg":"extent:4 gens: 32 32 31","v":0,"name":"crucible","level":30,"time":"2024-02-12T01:37:51.459616873Z","hostname":"ip-10-150-1-57.us-west-2.compute.internal","pid":1188,"mrl":"flush_mismatch","":"mend","":"downstairs","":"downstairs","session_id":"843ab90b-fdd4-4846-be44-cef96d9b1321"}
4372024-02-12T01:37:53.145Z{"msg":"extent:4 flush: 1661 1661 1660 scs: [ClientId(0), ClientId(1)]","v":0,"name":"crucible","level":30,"time":"2024-02-12T01:37:51.459631733Z","hostname":"ip-10-150-1-57.us-west-2.compute.internal","pid":1188,"mrl":"flush_mismatch","":"mend","":"downstairs","":"downstairs","session_id":"843ab90b-fdd4-4846-be44-cef96d9b1321"}
4382024-02-12T01:37:53.145Z{"msg":"max_flush now has: [ClientId(0), ClientId(1)]","v":0,"name":"crucible","level":30,"time":"2024-02-12T01:37:51.459653272Z","hostname":"ip-10-150-1-57.us-west-2.compute.internal","pid":1188,"mrl":"flush_mismatch","":"mend","":"downstairs","":"downstairs","session_id":"843ab90b-fdd4-4846-be44-cef96d9b1321"}
4392024-02-12T01:37:53.145Z{"msg":"extent:4 dirty: false false false","v":0,"name":"crucible","level":30,"time":"2024-02-12T01:37:51.459667852Z","hostname":"ip-10-150-1-57.us-west-2.compute.internal","pid":1188,"mrl":"flush_mismatch","":"mend","":"downstairs","":"downstairs","session_id":"843ab90b-fdd4-4846-be44-cef96d9b1321"}
4402024-02-12T01:37:53.145Z{"msg":"No maxes found, left with: [ClientId(0), ClientId(1)]","v":0,"name":"crucible","level":30,"time":"2024-02-12T01:37:51.459682922Z","hostname":"ip-10-150-1-57.us-west-2.compute.internal","pid":1188,"mrl":"flush_mismatch","":"mend","":"downstairs","":"downstairs","session_id":"843ab90b-fdd4-4846-be44-cef96d9b1321"}
4412024-02-12T01:37:53.145Z{"msg":"find dest for source 0 for extent at index 4","v":0,"name":"crucible","level":30,"time":"2024-02-12T01:37:51.459705902Z","hostname":"ip-10-150-1-57.us-west-2.compute.internal","pid":1188,"mrl":"flush_mismatch","":"mend","":"downstairs","":"downstairs","session_id":"843ab90b-fdd4-4846-be44-cef96d9b1321"}
4422024-02-12T01:37:53.145Z{"msg":"source 0, add dest 2 gen","v":0,"name":"crucible","level":30,"time":"2024-02-12T01:37:51.459720591Z","hostname":"ip-10-150-1-57.us-west-2.compute.internal","pid":1188,"mrl":"flush_mismatch","":"mend","":"downstairs","":"downstairs","session_id":"843ab90b-fdd4-4846-be44-cef96d9b1321"}
4432024-02-12T01:37:53.145Z{"msg":"Transition from WaitQuorum to Reconcile","v":0,"name":"crucible","level":30,"time":"2024-02-12T01:37:51.459735801Z","hostname":"ip-10-150-1-57.us-west-2.compute.internal","pid":1188,"client":"0","":"downstairs","session_id":"843ab90b-fdd4-4846-be44-cef96d9b1321"}
4442024-02-12T01:37:53.145Z{"msg":"Transition from WaitQuorum to Reconcile","v":0,"name":"crucible","level":30,"time":"2024-02-12T01:37:51.459749281Z","hostname":"ip-10-150-1-57.us-west-2.compute.internal","pid":1188,"client":"1","":"downstairs","session_id":"843ab90b-fdd4-4846-be44-cef96d9b1321"}
4452024-02-12T01:37:53.146Z{"msg":"Transition from WaitQuorum to Reconcile","v":0,"name":"crucible","level":30,"time":"2024-02-12T01:37:51.45976924Z","hostname":"ip-10-150-1-57.us-west-2.compute.internal","pid":1188,"client":"2","":"downstairs","session_id":"843ab90b-fdd4-4846-be44-cef96d9b1321"}
4462024-02-12T01:37:53.146Z{"msg":"Found 5 extents that need repair","v":0,"name":"crucible","level":30,"time":"2024-02-12T01:37:51.4597828Z","hostname":"ip-10-150-1-57.us-west-2.compute.internal","pid":1188,"":"downstairs","":"downstairs","session_id":"843ab90b-fdd4-4846-be44-cef96d9b1321"}
4472024-02-12T01:37:53.146Z{"msg":"Full repair list: {3: ExtentFix { source: ClientId(0), dest: [ClientId(2)] }, 4: ExtentFix { source: ClientId(0), dest: [ClientId(2)] }, 1: ExtentFix { source: ClientId(0), dest: [ClientId(2)] }, 0: ExtentFix { source: ClientId(0), dest: [ClientId(1), ClientId(2)] }, 2: ExtentFix { source: ClientId(0), dest: [ClientId(2)] }}","v":0,"name":"crucible","level":30,"time":"2024-02-12T01:37:51.45980127Z","hostname":"ip-10-150-1-57.us-west-2.compute.internal","pid":1188,"":"downstairs","":"downstairs","session_id":"843ab90b-fdd4-4846-be44-cef96d9b1321"}
4482024-02-12T01:37:53.146Z{"msg":"Task list: [ReconcileIO { id: ReconciliationId(0), op: ExtentFlush { repair_id: ReconciliationId(0), extent_id: 3, client_id: ClientId(0), flush_number: 1662, gen_number: 33 }, state: ClientData([New, New, New]) }, ReconcileIO { id: ReconciliationId(1), op: ExtentClose { repair_id: ReconciliationId(1), extent_id: 3 }, state: ClientData([New, New, New]) }, ReconcileIO { id: ReconciliationId(2), op: ExtentRepair { repair_id: ReconciliationId(2), extent_id: 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(3), op: ExtentReopen { repair_id: ReconciliationId(3), extent_id: 3 }, state: ClientData([New, New, New]) }, ReconcileIO { id: ReconciliationId(4), op: ExtentFlush { repair_id: ReconciliationId(4), extent_id: 4, client_id: ClientId(0), flush_number: 1662, gen_number: 33 }, state: ClientData([New, New, New]) }, ReconcileIO { id: ReconciliationId(5), op: ExtentClose { repair_id: ReconciliationId(5), extent_id: 4 }, state: ClientData([New, New, New]) }, ReconcileIO { id: ReconciliationId(6), op: ExtentRepair { repair_id: ReconciliationId(6), extent_id: 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(7), op: ExtentReopen { repair_id: ReconciliationId(7), extent_id: 4 }, state: ClientData([New, New, New]) }, ReconcileIO { id: ReconciliationId(8), op: ExtentFlush { repair_id: ReconciliationId(8), extent_id: 1, client_id: ClientId(0), flush_number: 1662, gen_number: 33 }, state: ClientData([New, New, New]) }, ReconcileIO { id: ReconciliationId(9), op: ExtentClose { repair_id: ReconciliationId(9), extent_id: 1 }, state: ClientData([New, New, New]) }, ReconcileIO { id: ReconciliationId(10), op: ExtentRepair { repair_id: ReconciliationId(10), extent_id: 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: 1 }, state: ClientData([New, New, New]) }, ReconcileIO { id: ReconciliationId(12), op: ExtentFlush { repair_id: ReconciliationId(12), extent_id: 0, client_id: ClientId(0), flush_number: 1662, gen_number: 33 }, state: ClientData([New, New, New]) }, ReconcileIO { id: ReconciliationId(13), op: ExtentClose { repair_id: ReconciliationId(13), extent_id: 0 }, state: ClientData([New, New, New]) }, ReconcileIO { id: ReconciliationId(14), op: ExtentRepair { repair_id: ReconciliationId(14), extent_id: 0, source_client_id: ClientId(0), source_repair_address: 0.0.0.0:12810, dest_clients: [ClientId(1), ClientId(2)] }, state: ClientData([New, New, New]) }, ReconcileIO { id: ReconciliationId(15), op: ExtentReopen { repair_id: ReconciliationId(15), extent_id: 0 }, state: ClientData([New, New, New]) }, ReconcileIO { id: ReconciliationId(16), op: ExtentFlush { repair_id: ReconciliationId(16), extent_id: 2, client_id: ClientId(0), flush_number: 1662, gen_number: 33 }, state: ClientData([New, New, New]) }, ReconcileIO { id: ReconciliationId(17), op: ExtentClose { repair_id: ReconciliationId(17), extent_id: 2 }, state: ClientData([New, New, New]) }, ReconcileIO { id: ReconciliationId(18), op: ExtentRepair { repair_id: ReconciliationId(18), extent_id: 2, source_client_id: ClientId(0), source_repair_address: 0.0.0.0:12810, dest_clients: [ClientId(2)] }, state: ClientData([New, New, New]) }, ReconcileIO { id: ReconciliationId(19), op: ExtentReopen { repair_id: ReconciliationId(19), extent_id: 2 }, state: ClientData([New, New, New]) }]","v":0,"name":"crucible","level":30,"time":"2024-02-12T01:37:51.459897298Z","hostname":"ip-10-150-1-57.us-west-2.compute.internal","pid":1188,"":"downstairs","":"downstairs","session_id":"843ab90b-fdd4-4846-be44-cef96d9b1321"}
4492024-02-12T01:37:53.146Z{"msg":"sending flush request ReconciliationId(0)","v":0,"name":"crucible","level":30,"time":"2024-02-12T01:37:51.459915958Z","hostname":"ip-10-150-1-57.us-west-2.compute.internal","pid":1188,"client":"0","":"downstairs","session_id":"843ab90b-fdd4-4846-be44-cef96d9b1321"}
4502024-02-12T01:37:53.146Z{"msg":"skipping flush request ReconciliationId(0)","v":0,"name":"crucible","level":30,"time":"2024-02-12T01:37:51.459930287Z","hostname":"ip-10-150-1-57.us-west-2.compute.internal","pid":1188,"client":"1","":"downstairs","session_id":"843ab90b-fdd4-4846-be44-cef96d9b1321"}
4512024-02-12T01:37:53.146Z{"msg":"skipping flush request ReconciliationId(0)","v":0,"name":"crucible","level":30,"time":"2024-02-12T01:37:51.459943457Z","hostname":"ip-10-150-1-57.us-west-2.compute.internal","pid":1188,"client":"2","":"downstairs","session_id":"843ab90b-fdd4-4846-be44-cef96d9b1321"}
4522024-02-12T01:37:53.146Z{"msg":"no action needed request ReconciliationId(2)","v":0,"name":"crucible","level":30,"time":"2024-02-12T01:37:51.459964506Z","hostname":"ip-10-150-1-57.us-west-2.compute.internal","pid":1188,"client":"0","":"downstairs","session_id":"843ab90b-fdd4-4846-be44-cef96d9b1321"}
4532024-02-12T01:37:53.146Z{"msg":"no action needed request ReconciliationId(2)","v":0,"name":"crucible","level":30,"time":"2024-02-12T01:37:51.459977986Z","hostname":"ip-10-150-1-57.us-west-2.compute.internal","pid":1188,"client":"1","":"downstairs","session_id":"843ab90b-fdd4-4846-be44-cef96d9b1321"}
4542024-02-12T01:37:53.146Z{"msg":"sending reconcile request ReconciliationId(2)","v":0,"name":"crucible","level":30,"time":"2024-02-12T01:37:51.459992946Z","hostname":"ip-10-150-1-57.us-west-2.compute.internal","pid":1188,"client":"2","":"downstairs","session_id":"843ab90b-fdd4-4846-be44-cef96d9b1321"}
4552024-02-12T01:37:53.201Z{"msg":"sending flush request ReconciliationId(4)","v":0,"name":"crucible","level":30,"time":"2024-02-12T01:37:51.522185827Z","hostname":"ip-10-150-1-57.us-west-2.compute.internal","pid":1188,"client":"0","":"downstairs","session_id":"843ab90b-fdd4-4846-be44-cef96d9b1321"}
4562024-02-12T01:37:53.201Z{"msg":"skipping flush request ReconciliationId(4)","v":0,"name":"crucible","level":30,"time":"2024-02-12T01:37:51.522242336Z","hostname":"ip-10-150-1-57.us-west-2.compute.internal","pid":1188,"client":"1","":"downstairs","session_id":"843ab90b-fdd4-4846-be44-cef96d9b1321"}
4572024-02-12T01:37:53.201Z{"msg":"skipping flush request ReconciliationId(4)","v":0,"name":"crucible","level":30,"time":"2024-02-12T01:37:51.522262436Z","hostname":"ip-10-150-1-57.us-west-2.compute.internal","pid":1188,"client":"2","":"downstairs","session_id":"843ab90b-fdd4-4846-be44-cef96d9b1321"}
4582024-02-12T01:37:53.204Z{"msg":"no action needed request ReconciliationId(6)","v":0,"name":"crucible","level":30,"time":"2024-02-12T01:37:51.522754986Z","hostname":"ip-10-150-1-57.us-west-2.compute.internal","pid":1188,"client":"0","":"downstairs","session_id":"843ab90b-fdd4-4846-be44-cef96d9b1321"}
4592024-02-12T01:37:53.205Z{"msg":"no action needed request ReconciliationId(6)","v":0,"name":"crucible","level":30,"time":"2024-02-12T01:37:51.522792305Z","hostname":"ip-10-150-1-57.us-west-2.compute.internal","pid":1188,"client":"1","":"downstairs","session_id":"843ab90b-fdd4-4846-be44-cef96d9b1321"}
4602024-02-12T01:37:53.205Z{"msg":"sending reconcile request ReconciliationId(6)","v":0,"name":"crucible","level":30,"time":"2024-02-12T01:37:51.522808965Z","hostname":"ip-10-150-1-57.us-west-2.compute.internal","pid":1188,"client":"2","":"downstairs","session_id":"843ab90b-fdd4-4846-be44-cef96d9b1321"}
4612024-02-12T01:37:53.241Z{"msg":"sending flush request ReconciliationId(8)","v":0,"name":"crucible","level":30,"time":"2024-02-12T01:37:51.561866676Z","hostname":"ip-10-150-1-57.us-west-2.compute.internal","pid":1188,"client":"0","":"downstairs","session_id":"843ab90b-fdd4-4846-be44-cef96d9b1321"}
4622024-02-12T01:37:53.241Z{"msg":"skipping flush request ReconciliationId(8)","v":0,"name":"crucible","level":30,"time":"2024-02-12T01:37:51.561913255Z","hostname":"ip-10-150-1-57.us-west-2.compute.internal","pid":1188,"client":"1","":"downstairs","session_id":"843ab90b-fdd4-4846-be44-cef96d9b1321"}
4632024-02-12T01:37:53.241Z{"msg":"skipping flush request ReconciliationId(8)","v":0,"name":"crucible","level":30,"time":"2024-02-12T01:37:51.561933295Z","hostname":"ip-10-150-1-57.us-west-2.compute.internal","pid":1188,"client":"2","":"downstairs","session_id":"843ab90b-fdd4-4846-be44-cef96d9b1321"}
4642024-02-12T01:37:53.244Z{"msg":"no action needed request ReconciliationId(10)","v":0,"name":"crucible","level":30,"time":"2024-02-12T01:37:51.562398896Z","hostname":"ip-10-150-1-57.us-west-2.compute.internal","pid":1188,"client":"0","":"downstairs","session_id":"843ab90b-fdd4-4846-be44-cef96d9b1321"}
4652024-02-12T01:37:53.244Z{"msg":"no action needed request ReconciliationId(10)","v":0,"name":"crucible","level":30,"time":"2024-02-12T01:37:51.562448025Z","hostname":"ip-10-150-1-57.us-west-2.compute.internal","pid":1188,"client":"1","":"downstairs","session_id":"843ab90b-fdd4-4846-be44-cef96d9b1321"}
4662024-02-12T01:37:53.244Z{"msg":"sending reconcile request ReconciliationId(10)","v":0,"name":"crucible","level":30,"time":"2024-02-12T01:37:51.562468185Z","hostname":"ip-10-150-1-57.us-west-2.compute.internal","pid":1188,"client":"2","":"downstairs","session_id":"843ab90b-fdd4-4846-be44-cef96d9b1321"}
4672024-02-12T01:37:53.281Z{"msg":"sending flush request ReconciliationId(12)","v":0,"name":"crucible","level":30,"time":"2024-02-12T01:37:51.601937726Z","hostname":"ip-10-150-1-57.us-west-2.compute.internal","pid":1188,"client":"0","":"downstairs","session_id":"843ab90b-fdd4-4846-be44-cef96d9b1321"}
4682024-02-12T01:37:53.281Z{"msg":"skipping flush request ReconciliationId(12)","v":0,"name":"crucible","level":30,"time":"2024-02-12T01:37:51.601983536Z","hostname":"ip-10-150-1-57.us-west-2.compute.internal","pid":1188,"client":"1","":"downstairs","session_id":"843ab90b-fdd4-4846-be44-cef96d9b1321"}
4692024-02-12T01:37:53.281Z{"msg":"skipping flush request ReconciliationId(12)","v":0,"name":"crucible","level":30,"time":"2024-02-12T01:37:51.602007365Z","hostname":"ip-10-150-1-57.us-west-2.compute.internal","pid":1188,"client":"2","":"downstairs","session_id":"843ab90b-fdd4-4846-be44-cef96d9b1321"}
4702024-02-12T01:37:53.285Z{"msg":"no action needed request ReconciliationId(14)","v":0,"name":"crucible","level":30,"time":"2024-02-12T01:37:51.603434288Z","hostname":"ip-10-150-1-57.us-west-2.compute.internal","pid":1188,"client":"0","":"downstairs","session_id":"843ab90b-fdd4-4846-be44-cef96d9b1321"}
4712024-02-12T01:37:53.285Z{"msg":"sending reconcile request ReconciliationId(14)","v":0,"name":"crucible","level":30,"time":"2024-02-12T01:37:51.603484276Z","hostname":"ip-10-150-1-57.us-west-2.compute.internal","pid":1188,"client":"1","":"downstairs","session_id":"843ab90b-fdd4-4846-be44-cef96d9b1321"}
4722024-02-12T01:37:53.285Z{"msg":"sending reconcile request ReconciliationId(14)","v":0,"name":"crucible","level":30,"time":"2024-02-12T01:37:51.603532606Z","hostname":"ip-10-150-1-57.us-west-2.compute.internal","pid":1188,"client":"2","":"downstairs","session_id":"843ab90b-fdd4-4846-be44-cef96d9b1321"}
4732024-02-12T01:37:53.334Z{"msg":"sending flush request ReconciliationId(16)","v":0,"name":"crucible","level":30,"time":"2024-02-12T01:37:51.654973536Z","hostname":"ip-10-150-1-57.us-west-2.compute.internal","pid":1188,"client":"0","":"downstairs","session_id":"843ab90b-fdd4-4846-be44-cef96d9b1321"}
4742024-02-12T01:37:53.334Z{"msg":"skipping flush request ReconciliationId(16)","v":0,"name":"crucible","level":30,"time":"2024-02-12T01:37:51.655026595Z","hostname":"ip-10-150-1-57.us-west-2.compute.internal","pid":1188,"client":"1","":"downstairs","session_id":"843ab90b-fdd4-4846-be44-cef96d9b1321"}
4752024-02-12T01:37:53.334Z{"msg":"skipping flush request ReconciliationId(16)","v":0,"name":"crucible","level":30,"time":"2024-02-12T01:37:51.655059084Z","hostname":"ip-10-150-1-57.us-west-2.compute.internal","pid":1188,"client":"2","":"downstairs","session_id":"843ab90b-fdd4-4846-be44-cef96d9b1321"}
4762024-02-12T01:37:53.337Z{"msg":"no action needed request ReconciliationId(18)","v":0,"name":"crucible","level":30,"time":"2024-02-12T01:37:51.655581314Z","hostname":"ip-10-150-1-57.us-west-2.compute.internal","pid":1188,"client":"0","":"downstairs","session_id":"843ab90b-fdd4-4846-be44-cef96d9b1321"}
4772024-02-12T01:37:53.337Z{"msg":"no action needed request ReconciliationId(18)","v":0,"name":"crucible","level":30,"time":"2024-02-12T01:37:51.655636843Z","hostname":"ip-10-150-1-57.us-west-2.compute.internal","pid":1188,"client":"1","":"downstairs","session_id":"843ab90b-fdd4-4846-be44-cef96d9b1321"}
4782024-02-12T01:37:53.337Z{"msg":"sending reconcile request ReconciliationId(18)","v":0,"name":"crucible","level":30,"time":"2024-02-12T01:37:51.655672722Z","hostname":"ip-10-150-1-57.us-west-2.compute.internal","pid":1188,"client":"2","":"downstairs","session_id":"843ab90b-fdd4-4846-be44-cef96d9b1321"}
4792024-02-12T01:37:53.372Z{"msg":"done with reconciliation","v":0,"name":"crucible","level":30,"time":"2024-02-12T01:37:51.693399429Z","hostname":"ip-10-150-1-57.us-west-2.compute.internal","pid":1188,"":"downstairs","":"downstairs","session_id":"843ab90b-fdd4-4846-be44-cef96d9b1321"}
4802024-02-12T01:37:53.372Z{Wait for a query_work_queue command to finish before sending IO
4812024-02-12T01:37:53.373Z"msg":"Transition from Reconcile to Active","v":0,"name":"crucible","level":30,"time":"2024-02-12T01:37:51.693461578Z","hostname":"ip-10-150-1-57.us-west-2.compute.internal","pid":1188,"client":"0","":"downstairs","session_id":"843ab90b-fdd4-4846-be44-cef96d9b1321"}
4822024-02-12T01:37:53.377Z{"msg":"Transition from Reconcile to Active","v":0,"name":"crucible","level":30,"time":"2024-02-12T01:37:51.693509497Z","hostname":"ip-10-150-1-57.us-west-2.compute.internal","pid":1188,"client":"1","":"downstairs","session_id":"843ab90b-fdd4-4846-be44-cef96d9b1321"}
4832024-02-12T01:37:53.377Z{"msg":"Transition from Reconcile to Active","v":0,"name":"crucible","level":30,"time":"2024-02-12T01:37:51.693555656Z","hostname":"ip-10-150-1-57.us-west-2.compute.internal","pid":1188,"client":"2","":"downstairs","session_id":"843ab90b-fdd4-4846-be44-cef96d9b1321"}
4842024-02-12T01:37:53.377Z{"msg":"All required reconciliation work is completed","v":0,"name":"crucible","level":30,"time":"2024-02-12T01:37:51.693603335Z","hostname":"ip-10-150-1-57.us-west-2.compute.internal","pid":1188,"session_id":"843ab90b-fdd4-4846-be44-cef96d9b1321"}
4852024-02-12T01:37:53.377Z{"msg":"Set Downstairs and Upstairs active after reconciliation","v":0,"name":"crucible","level":30,"time":"2024-02-12T01:37:51.693640344Z","hostname":"ip-10-150-1-57.us-west-2.compute.internal","pid":1188,"session_id":"843ab90b-fdd4-4846-be44-cef96d9b1321"}
4862024-02-12T01:37:53.377Z{"msg":"eeaedf48-605c-42eb-803a-a8f9d07886c6 is now active with session: 843ab90b-fdd4-4846-be44-cef96d9b1321","v":0,"name":"crucible","level":30,"time":"2024-02-12T01:37:51.693680274Z","hostname":"ip-10-150-1-57.us-west-2.compute.internal","pid":1188,"session_id":"843ab90b-fdd4-4846-be44-cef96d9b1321"}
4872024-02-12T01:37:53.377Z{"msg":"The guest has finished waiting for activation with:33","v":0,"name":"crucible","level":30,"time":"2024-02-12T01:37:51.693713183Z","hostname":"ip-10-150-1-57.us-west-2.compute.internal","pid":1188}
4882024-02-12T01:37:53.377ZRegion: es:10 ec:5 bs:4096 ts:204800 tb:50 max_io:50 or 204800
4892024-02-12T01:37:53.377ZLoading write count information from file "/var/tmp/test_up/verify_file"
4902024-02-12T01:37:53.377ZRead and Verify all blocks (0..50 range:true)
4912024-02-12T01:37:53.411ZWrote out file "/var/tmp/test_up/verify_file"
4922024-02-12T01:37:53.411ZVerify test completed
4932024-02-12T01:37:53.414ZWrote out file "/var/tmp/test_up/verify_file"
4942024-02-12T01:37:53.414ZCLIENT: Tests done. All submitted work has been ACK'd
4952024-02-12T01:37:53.414Z----------------------------------------------------------------
4962024-02-12T01:37:53.414Z Crucible gen:33 GIO:true work queues: Upstairs:0 downstairs:1
4972024-02-12T01:37:53.414ZStates: Active Active Active
4982024-02-12T01:37:53.414ZGW_ID ACK DSID TYPE BLOCKS DS:0 DS:1 DS:2 REPLAY
4992024-02-12T01:37:53.414Z 1 Acked 1000 Read 50 Done Done Done false
5002024-02-12T01:37:53.414Z STATES DS:0 DS:1 DS:2 TOTAL
5012024-02-12T01:37:53.415Z New 0 0 0 0
5022024-02-12T01:37:53.415Z Sent 0 0 0 0
5032024-02-12T01:37:53.415Z Done 1 1 1 3
5042024-02-12T01:37:53.415Z Skipped 0 0 0 0
5052024-02-12T01:37:53.415Z Error 0 0 0 0
5062024-02-12T01:37:53.415ZLast Flush: 0 0 0
5072024-02-12T01:37:53.415ZDownstairs last five completed:
5082024-02-12T01:37:53.415ZUpstairs last five completed: 1
5092024-02-12T01:37:53.415ZCLIENT: Up:0 ds:1 act:3
5102024-02-12T01:37:57.414Z----------------------------------------------------------------
5112024-02-12T01:37:57.414Z Crucible gen:33 GIO:true work queues: Upstairs:0 downstairs:0
5122024-02-12T01:37:57.414ZDownstairs last five completed: 1001 1000
5132024-02-12T01:37:57.414ZUpstairs last five completed: 2 1
5142024-02-12T01:37:57.414ZCLIENT: Up:0 ds:0 act:3
5152024-02-12T01:37:57.414ZCLIENT: All crucible jobs finished, exiting program
5162024-02-12T01:37:57.418ZRepair part 2 passed
5172024-02-12T01:37:57.420Z/var/tmp/bins/crucible-downstairs dump --no-color -d /var/tmp/test_up/8810 -d /var/tmp/test_up/8820 -d /var/tmp/test_up/8830
5182024-02-12T01:37:57.432ZEXT BLOCKS GEN0 GEN1 GEN2 FL0 FL1 FL2 D0 D1 D2 DIFF
5192024-02-12T01:37:57.432Z 0 000-009 33 33 33 1662 1662 1662 F F F
5202024-02-12T01:37:57.432Z 1 010-019 32 32 32 1661 1661 1661 F F F
5212024-02-12T01:37:57.432Z 2 020-029 32 32 32 1661 1661 1661 F F F
5222024-02-12T01:37:57.432Z 3 030-039 32 32 32 1661 1661 1661 F F F
5232024-02-12T01:37:57.432Z 4 040-049 32 32 32 1661 1661 1661 F F F
5242024-02-12T01:37:57.432ZMax gen: 33, Max flush: 1662
5252024-02-12T01:37:57.435Zdump test passed
5262024-02-12T01:37:57.435Z/var/tmp/bins/crucible-downstairs dump --no-color -d /var/tmp/test_up/8810 -d /var/tmp/test_up/8820 -d /var/tmp/test_up/8830 -e 1
5272024-02-12T01:37:57.447Z Extent 1
5282024-02-12T01:37:57.450ZGEN 32 32 32
5292024-02-12T01:37:57.450ZFLUSH_ID 1661 1661 1661
5302024-02-12T01:37:57.450ZDIRTY
5312024-02-12T01:37:57.450Z
5322024-02-12T01:37:57.450ZBLOCK D0 D1 D2 C0 C1 C2 DIFF
5332024-02-12T01:37:57.450Z010 A A A A A A
5342024-02-12T01:37:57.450Z011 A A A A A A
5352024-02-12T01:37:57.451Z012 A A A A A A
5362024-02-12T01:37:57.451Z013 A A A A A A
5372024-02-12T01:37:57.451Z014 A A A A A A
5382024-02-12T01:37:57.451Z015 A A A A A A
5392024-02-12T01:37:57.454Z016 A A A A A A
5402024-02-12T01:37:57.454Z017 A A A A A A
5412024-02-12T01:37:57.454Z018 A A A A A A
5422024-02-12T01:37:57.454Z019 A A A A A A
5432024-02-12T01:37:57.457Zdump extent test passed
5442024-02-12T01:37:57.457Z/var/tmp/bins/crucible-downstairs dump --no-color -d /var/tmp/test_up/8810 -d /var/tmp/test_up/8820 -d /var/tmp/test_up/8830 -b 20
5452024-02-12T01:37:57.466ZExtent 2 Block in extent 0 Actual block 20
5462024-02-12T01:37:57.467Z
5472024-02-12T01:37:57.470Z DATA SHA256 VER
5482024-02-12T01:37:57.470Z------ ---------------------------------------------------------------- ---
5492024-02-12T01:37:57.470Z 0 f9fb09053727a0335f19a6172617b8700eae6cbe9ab4ee405827eeb719b0884a A
5502024-02-12T01:37:57.470Z 1 f9fb09053727a0335f19a6172617b8700eae6cbe9ab4ee405827eeb719b0884a A
5512024-02-12T01:37:57.470Z 2 f9fb09053727a0335f19a6172617b8700eae6cbe9ab4ee405827eeb719b0884a A
5522024-02-12T01:37:57.470Z
5532024-02-12T01:37:57.470ZNONCES 0 1 2 DIFF
5542024-02-12T01:37:57.470Z------ ------------------------ ------------------------ ------------------------ -----
5552024-02-12T01:37:57.470Z 0 d9876a6f892c22adef124ef9 d9876a6f892c22adef124ef9 d9876a6f892c22adef124ef9
5562024-02-12T01:37:57.470Z
5572024-02-12T01:37:57.470Z TAGS 0 1 2 DIFF
5582024-02-12T01:37:57.470Z------ -------------------------------- -------------------------------- -------------------------------- -----
5592024-02-12T01:37:57.470Z 0 a7931f2efe5731ce680357c1885dcd7b a7931f2efe5731ce680357c1885dcd7b a7931f2efe5731ce680357c1885dcd7b
5602024-02-12T01:37:57.470Z
5612024-02-12T01:37:57.470ZHASHES 0 1 2 DIFF
5622024-02-12T01:37:57.470Z------ ---------------- ---------------- ---------------- -----
5632024-02-12T01:37:57.470Z 0 abcf74fe84ca332f abcf74fe84ca332f abcf74fe84ca332f
5642024-02-12T01:37:57.470Z
5652024-02-12T01:37:57.474Zdump block test passed
5662024-02-12T01:37:57.474ZUpstairs tests have completed, stopping all downstairs
5672024-02-12T01:37:57.532Z
5682024-02-12T01:37:57.532ZAll Tests have passed
5692024-02-12T01:37:57.535Z2:33 Test duration
5702024-02-12T01:37:57.535Z
5712024-02-12T01:37:57.535Zreal 2:33.707639456
5722024-02-12T01:37:57.535Zuser 2:19.179319396
5732024-02-12T01:37:57.535Zsys 6.836524499
5742024-02-12T01:37:57.535Ztrap 0.183776665
5752024-02-12T01:37:57.535Ztflt 0.005718793
5762024-02-12T01:37:57.535Zdflt 0.003946332
5772024-02-12T01:37:57.535Zkflt 0.000883966
5782024-02-12T01:37:57.535Zlock 34:34.507660021
5792024-02-12T01:37:57.536Zslp 4:56.516657226
5802024-02-12T01:37:57.536Zlat 13.625191703
5812024-02-12T01:37:57.536Zstop 0.030661850
5822024-02-12T01:37:57.536Zprocess exited: duration 162887 ms, exit code 0
 
5832024-02-12T01:37:57.546Zfound 5 output files
5842024-02-12T01:37:57.546Zuploading: /tmp/test_up/dsc-out.txt (4483 bytes)
5852024-02-12T01:37:58.556Zuploaded: /tmp/test_up/dsc-out.txt
5862024-02-12T01:37:58.557Zuploading: /tmp/test_up/test_up_out.txt (4568507 bytes)
5872024-02-12T01:38:03.009Zuploaded: /tmp/test_up/test_up_out.txt
5882024-02-12T01:38:03.012Zuploading: /tmp/test_up/dsc/downstairs-8810.txt (54178 bytes)
5892024-02-12T01:38:04.026Zuploaded: /tmp/test_up/dsc/downstairs-8810.txt
5902024-02-12T01:38:04.033Zuploading: /tmp/test_up/dsc/downstairs-8820.txt (49410 bytes)
5912024-02-12T01:38:05.043Zuploaded: /tmp/test_up/dsc/downstairs-8820.txt
5922024-02-12T01:38:05.047Zuploading: /tmp/test_up/dsc/downstairs-8830.txt (10940 bytes)
5932024-02-12T01:38:06.054Zuploaded: /tmp/test_up/dsc/downstairs-8830.txt