01HAZHJ54WA80V0YB3GBCD9G95: 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: 01HAZHJEYFZHGX6BRCWS0TVARX

Tags:

Artefacts:

Output:

SEQ GLOBAL TIME DETAILS
12023-09-22T23:21:23.328Zjob dependencies complete; ready to run (waiting for 27 m 46 s)
22023-09-22T23:22:27.715Zjob assigned to worker 01HAZK5GYDTVTBPYJEDDDPCWVN (queued for 1 m 4 s)
32023-09-22T23:22:28.522Zdownloading input: /input/build/work/bins/crucible-downstairs.gz
42023-09-22T23:22:46.276Zdownloaded input: /input/build/work/bins/crucible-downstairs.gz
52023-09-22T23:22:46.289Zdownloading input: /input/build/work/bins/crucible-hammer.gz
62023-09-22T23:22:55.100Zdownloaded input: /input/build/work/bins/crucible-hammer.gz
72023-09-22T23:22:55.108Zdownloading input: /input/build/work/bins/crutest.gz
82023-09-22T23:23:09.019Zdownloaded input: /input/build/work/bins/crutest.gz
92023-09-22T23:23:09.023Zdownloading input: /input/build/work/bins/dsc.gz
102023-09-22T23:23:18.076Zdownloaded input: /input/build/work/bins/dsc.gz
112023-09-22T23:23:18.079Zdownloading input: /input/build/work/scripts/test_ds.sh
122023-09-22T23:23:18.091Zdownloaded input: /input/build/work/scripts/test_ds.sh
132023-09-22T23:23:18.094Zdownloading input: /input/build/work/scripts/test_live_repair.sh
142023-09-22T23:23:18.105Zdownloaded input: /input/build/work/scripts/test_live_repair.sh
152023-09-22T23:23:18.108Zdownloading input: /input/build/work/scripts/test_repair.sh
162023-09-22T23:23:18.123Zdownloaded input: /input/build/work/scripts/test_repair.sh
172023-09-22T23:23:18.126Zdownloading input: /input/build/work/scripts/test_replay.sh
182023-09-22T23:23:18.137Zdownloaded input: /input/build/work/scripts/test_replay.sh
192023-09-22T23:23:18.140Zdownloading input: /input/build/work/scripts/test_up.sh
202023-09-22T23:23:18.152Zdownloaded input: /input/build/work/scripts/test_up.sh
212023-09-22T23:23:18.155Zdownloading input: /input/build/tmp/cargo-test-out.log
222023-09-22T23:23:19.263Zdownloaded input: /input/build/tmp/cargo-test-out.log
 
232023-09-22T23:23:19.273Zstarting task 0: "setup"
242023-09-22T23:23:19.396Z++ uname -s
252023-09-22T23:23:19.399Z+ kern=SunOS
262023-09-22T23:23:19.402Z+ case "$kern" in
272023-09-22T23:23:19.405Z+ groupadd -g 12345 build
282023-09-22T23:23:19.408Z+ useradd -u 12345 -g build -d /home/build -s /bin/bash -c build -P 'Primary Administrator' build
292023-09-22T23:23:21.415Z+ zfs create -o mountpoint=/work rpool/work
302023-09-22T23:23:21.619Z++ awk '$2 == "/home" { print $3 }' /etc/mnttab
312023-09-22T23:23:21.635Z+ home_fs=zfs
322023-09-22T23:23:21.652Z+ [[ zfs == autofs ]]
332023-09-22T23:23:21.659Z+ mkdir -p /home/build
342023-09-22T23:23:21.663Z+ chown build:build /home/build /work
352023-09-22T23:23:23.618Z+ chmod 0700 /home/build /work
362023-09-22T23:23:23.625Zprocess exited: duration 4339 ms, exit code 0
 
372023-09-22T23:23:23.659Zstarting task 1: "authentication"
382023-09-22T23:23:23.694Zprocess exited: duration 28 ms, exit code 0
 
392023-09-22T23:23:23.701Zstarting task 2: "build"
402023-09-22T23:23:23.712Z+ banner cores
412023-09-22T23:23:23.786Z
422023-09-22T23:23:23.797Z #### #### ##### ###### ####
432023-09-22T23:23:23.818Z # # # # # # # #
442023-09-22T23:23:24.250Z # # # # # ##### ####
452023-09-22T23:23:24.268Z # # # ##### # #
462023-09-22T23:23:24.293Z # # # # # # # # #
472023-09-22T23:23:24.307Z #### #### # # ###### ####
482023-09-22T23:23:24.325Z
492023-09-22T23:23:24.337Z+ pfexec coreadm -i /tmp/core.%f.%p -g /tmp/core.%f.%p -e global -e log -e proc-setid -e global-setid
502023-09-22T23:23:24.347Z+ echo 'input bins dir contains:'
512023-09-22T23:23:24.354Zinput bins dir contains:
522023-09-22T23:23:24.360Z+ ls -ltr /input/build/work/bins
532023-09-22T23:23:24.368Ztotal 703419
542023-09-22T23:23:24.374Z-rw-r--r-- 1 root root 108909782 Sep 22 23:22 crucible-downstairs.gz
552023-09-22T23:23:24.381Z-rw-r--r-- 1 root root 86315868 Sep 22 23:22 crucible-hammer.gz
562023-09-22T23:23:24.384Z-rw-r--r-- 1 root root 96159197 Sep 22 23:23 crutest.gz
572023-09-22T23:23:24.387Z-rw-r--r-- 1 root root 68523274 Sep 22 23:23 dsc.gz
582023-09-22T23:23:24.391Z+ banner unpack
592023-09-22T23:23:24.394Z
602023-09-22T23:23:24.399Z # # # # ##### ## #### # #
612023-09-22T23:23:24.402Z # # ## # # # # # # # # #
622023-09-22T23:23:24.405Z # # # # # # # # # # ####
632023-09-22T23:23:24.408Z # # # # # ##### ###### # # #
642023-09-22T23:23:24.411Z # # # ## # # # # # # #
652023-09-22T23:23:24.414Z #### # # # # # #### # #
662023-09-22T23:23:24.417Z
672023-09-22T23:23:24.420Z+ mkdir -p /var/tmp/bins
682023-09-22T23:23:24.423Z+ for t in "$input/bins/"*.gz
692023-09-22T23:23:24.426Z++ basename /input/build/work/bins/crucible-downstairs.gz
702023-09-22T23:23:24.430Z+ b=crucible-downstairs.gz
712023-09-22T23:23:24.433Z+ b=crucible-downstairs
722023-09-22T23:23:24.436Z+ gunzip
732023-09-22T23:23:27.671Z+ chmod +x /var/tmp/bins/crucible-downstairs
742023-09-22T23:23:27.683Z+ for t in "$input/bins/"*.gz
752023-09-22T23:23:27.699Z++ basename /input/build/work/bins/crucible-hammer.gz
762023-09-22T23:23:27.708Z+ b=crucible-hammer.gz
772023-09-22T23:23:27.721Z+ b=crucible-hammer
782023-09-22T23:23:27.736Z+ gunzip
792023-09-22T23:23:30.645Z+ chmod +x /var/tmp/bins/crucible-hammer
802023-09-22T23:23:30.653Z+ for t in "$input/bins/"*.gz
812023-09-22T23:23:30.659Z++ basename /input/build/work/bins/crutest.gz
822023-09-22T23:23:30.664Z+ b=crutest.gz
832023-09-22T23:23:30.671Z+ b=crutest
842023-09-22T23:23:30.675Z+ gunzip
852023-09-22T23:23:33.949Z+ chmod +x /var/tmp/bins/crutest
862023-09-22T23:23:33.962Z+ for t in "$input/bins/"*.gz
872023-09-22T23:23:33.970Z++ basename /input/build/work/bins/dsc.gz
882023-09-22T23:23:33.979Z+ b=dsc.gz
892023-09-22T23:23:33.993Z+ b=dsc
902023-09-22T23:23:34.008Z+ gunzip
912023-09-22T23:23:36.264Z+ chmod +x /var/tmp/bins/dsc
922023-09-22T23:23:36.267Z+ export BINDIR=/var/tmp/bins
932023-09-22T23:23:36.270Z+ BINDIR=/var/tmp/bins
942023-09-22T23:23:36.273Z+ banner test_up_encrypted
952023-09-22T23:23:36.277Z
962023-09-22T23:23:36.280Z ##### ###### #### ##### # # ##### ###### # #
972023-09-22T23:23:36.283Z # # # # # # # # # ## #
982023-09-22T23:23:36.286Z # ##### #### # # # # # ##### # # #
992023-09-22T23:23:36.289Z # # # # # # ##### # # # #
1002023-09-22T23:23:36.292Z # # # # # # # # # # ##
1012023-09-22T23:23:36.295Z # ###### #### # ####### #### # ####### ###### # #
1022023-09-22T23:23:36.300Z
1032023-09-22T23:23:36.304Z+ ptime -m bash /input/build/work/scripts/test_up.sh -N encrypted
1042023-09-22T23:23:36.308Z/input/build/work
1052023-09-22T23:23:36.312ZTurn off color for downstairs dump
1062023-09-22T23:23:36.439ZUpstairs using key: qGG0x4QYrGYwxtQQkXTfx0CabBUcjy4poXsgGc6mOEc=
1072023-09-22T23:23:36.443Zdsc output goes to /tmp/test_up/dsc-out.txt
1082023-09-22T23:23:36.447ZCreating three downstairs regions
1092023-09-22T23:23:36.951ZStarting three downstairs
1102023-09-22T23:23:41.960ZDisable automatic restart on all downstairs
1112023-09-22T23:23:42.087Z
1122023-09-22T23:23:42.121ZBegin tests, output goes to /tmp/test_up/test_up_out.txt
1132023-09-22T23:23:42.128ZRunning test: span
1142023-09-22T23:23:46.262ZCompleted test: span
1152023-09-22T23:23:46.267ZRunning test: big
1162023-09-22T23:23:51.036ZCompleted test: big
1172023-09-22T23:23:51.040ZRunning test: dep
1182023-09-22T23:25:39.895ZCompleted test: dep
1192023-09-22T23:25:39.899ZRunning test: balloon
1202023-09-22T23:28:00.439ZCompleted test: balloon
1212023-09-22T23:28:00.444ZRunning test: deactivate
1222023-09-22T23:28:11.539ZCompleted test: deactivate
1232023-09-22T23:28:11.544ZRunning hammer
1242023-09-22T23:28:37.691ZRun repair tests
1252023-09-22T23:28:37.696Z/var/tmp/bins/crutest fill -g 26 -q --key qGG0x4QYrGYwxtQQkXTfx0CabBUcjy4poXsgGc6mOEc= -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
1262023-09-22T23:28:37.716Z{"msg":"Upstairs starts","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:37.716771962Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1191}
1272023-09-22T23:28:37.719Z{"msg":"Crucible Version: BuildInfo {\n version: \"0.0.1\",\n git_sha: \"ed48f294784d46ea7d4bb99336918b74358eca46\",\n git_commit_timestamp: \"2023-09-22T22:51:18.000000000Z\",\n git_branch: \"main\",\n rustc_semver: \"1.70.0\",\n rustc_channel: \"stable\",\n rustc_host_triple: \"x86_64-unknown-illumos\",\n rustc_commit_sha: \"90c541806f23a127002de5b4038be731ba1458ca\",\n cargo_triple: \"x86_64-unknown-illumos\",\n debug: true,\n opt_level: 0,\n}","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:37.717277447Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1191}
1282023-09-22T23:28:37.722Z{"msg":"Upstairs <-> Downstairs Message Version: 4","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:37.717329344Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1191}
1292023-09-22T23:28:37.725Z{"msg":"Crucible stats registered with UUID: 97c9db57-64ee-426e-a180-ee7a97164a6a","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:37.717352891Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1191}
1302023-09-22T23:28:37.729Z{"msg":"Crucible 97c9db57-64ee-426e-a180-ee7a97164a6a has session id: 125cd49a-bfa5-4750-9dee-f8c74e5ec021","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:37.71737417Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1191}
1312023-09-22T23:28:37.746ZCrucible runtime is spawned
1322023-09-22T23:28:37.752Z{"msg":"up_listen starts","v":0,"name":"crucible","level":30The guest has requested activation with gen:26
1332023-09-22T23:28:37.761Z,"time":"2023-09-22T23:28:37.717793032Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1191,"task":"up_listen"}
1342023-09-22T23:28:37.769Z{"msg":"Wait for all three downstairs to come online","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:37.717922567Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1191}
1352023-09-22T23:28:37.778Z{"msg":"Flush timeout: 0.5","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:37.717975176Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1191}
1362023-09-22T23:28:37.788Z{"msg":"[0] connecting to 127.0.0.1:8810","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:37.718015668Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1191,"looper":"0"}
1372023-09-22T23:28:37.794Z{"msg":"[0] 97c9db57-64ee-426e-a180-ee7a97164a6a looper connected","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:37.718230949Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1191,"looper":"0"}
1382023-09-22T23:28:37.801Z{"msg":"[2] connecting to 127.0.0.1:8830","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:37.718301166Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1191,"looper":"2"}
1392023-09-22T23:28:37.809Z{"msg":"[1] connecting to 127.0.0.1:8820","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:37.718396518Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1191,"looper":"1"}
1402023-09-22T23:28:37.817Z{"msg":"[2] 97c9db57-64ee-426e-a180-ee7a97164a6a looper connected","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:37.718489073Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1191,"looper":"2"}
1412023-09-22T23:28:37.828Z{"msg":"[1] 97c9db57-64ee-426e-a180-ee7a97164a6a looper connected","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:37.718691721Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1191,"looper":"1"}
1422023-09-22T23:28:38.236Z{"msg":"97c9db57-64ee-426e-a180-ee7a97164a6a active request set","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:37.71884365Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1191}
1432023-09-22T23:28:38.240Z{"msg":"Set desired generation to :26","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:37.718902741Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1191}
1442023-09-22T23:28:38.244Z{"msg":"[0] Proc runs for 127.0.0.1:8810 in state New","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:37.719071733Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1191}
1452023-09-22T23:28:38.247Z{"msg":"[2] Proc runs for 127.0.0.1:8830 in state New","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:37.719220163Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1191}
1462023-09-22T23:28:38.254Z{"msg":"[1] Proc runs for 127.0.0.1:8820 in state New","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:37.719527906Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1191}
1472023-09-22T23:28:38.262Z{"msg":"[0] 97c9db57-64ee-426e-a180-ee7a97164a6a (92d481d1-a4aa-4c60-8d5b-6af2cc439b88) New New New ds_transition to WaitActive","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:37.71984172Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1191}
1482023-09-22T23:28:38.266Z{"msg":"[0] Transition from New to WaitActive","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:37.719875419Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1191}
1492023-09-22T23:28:38.270Z{"msg":"[2] 97c9db57-64ee-426e-a180-ee7a97164a6a (92d481d1-a4aa-4c60-8d5b-6af2cc439b88) WaitActive New New ds_transition to WaitActive","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:37.719937082Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1191}
1502023-09-22T23:28:38.275Z{"msg":"[2] Transition from New to WaitActive","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:37.719977631Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1191}
1512023-09-22T23:28:38.279Z{"msg":"[0] client is_active_req TRUE, promote! session 92d481d1-a4aa-4c60-8d5b-6af2cc439b88","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:37.720033272Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1191}
1522023-09-22T23:28:38.282Z{"msg":"[2] client is_active_req TRUE, promote! session 92d481d1-a4aa-4c60-8d5b-6af2cc439b88","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:37.72017078Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1191}
1532023-09-22T23:28:38.285Z{"msg":"[1] 97c9db57-64ee-426e-a180-ee7a97164a6a (92d481d1-a4aa-4c60-8d5b-6af2cc439b88) WaitActive New WaitActive ds_transition to WaitActive","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:37.720276933Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1191}
1542023-09-22T23:28:38.288Z{"msg":"[1] Transition from New to WaitActive","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:37.72035623Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1191}
1552023-09-22T23:28:38.291Z{"msg":"[1] client is_active_req TRUE, promote! session 92d481d1-a4aa-4c60-8d5b-6af2cc439b88","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:37.720396054Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1191}
1562023-09-22T23:28:38.294Z{"msg":"[0] downstairs client at 127.0.0.1:8810 has UUID 12345678-0000-0000-0000-000000008810","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:37.720802673Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1191}
1572023-09-22T23:28:38.297Z{"msg":"[2] downstairs client at 127.0.0.1:8830 has UUID 12345678-0000-0000-0000-000000008830","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:37.720862294Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1191}
1582023-09-22T23:28:38.300Z{"msg":"[1] downstairs client at 127.0.0.1:8820 has UUID 12345678-0000-0000-0000-000000008820","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:37.720887795Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1191}
1592023-09-22T23:28:38.303Z{"msg":"[0] Got region def RegionDefinition { block_size: 4096, extent_size: Block { value: 10, shift: 12 }, extent_count: 5, uuid: 12345678-0000-0000-0000-000000008810, encrypted: true, database_read_version: 1, database_write_version: 1 }","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:37.720971155Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1191}
1602023-09-22T23:28:38.306Z{"msg":"[2] Got region def RegionDefinition { block_size: 4096, extent_size: Block { value: 10, shift: 12 }, extent_count: 5, uuid: 12345678-0000-0000-0000-000000008830, encrypted: true, database_read_version: 1, database_write_version: 1 }","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:37.721028772Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1191}
1612023-09-22T23:28:38.309Z{"msg":"[1] Got region def RegionDefinition { block_size: 4096, extent_size: Block { value: 10, shift: 12 }, extent_count: 5, uuid: 12345678-0000-0000-0000-000000008820, encrypted: true, database_read_version: 1, database_write_version: 1 }","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:37.721083006Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1191}
1622023-09-22T23:28:38.312Z{"msg":"97c9db57-64ee-426e-a180-ee7a97164a6a WaitActive WaitActive WaitActive","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:37.721139269Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1191}
1632023-09-22T23:28:38.315Z{"msg":"97c9db57-64ee-426e-a180-ee7a97164a6a WaitActive WaitActive WaitActive","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:37.721199524Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1191}
1642023-09-22T23:28:38.318Z{"msg":"97c9db57-64ee-426e-a180-ee7a97164a6a WaitActive WaitActive WaitActive","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:37.721289487Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1191}
1652023-09-22T23:28:38.321Z{"msg":"[0] 97c9db57-64ee-426e-a180-ee7a97164a6a (92d481d1-a4aa-4c60-8d5b-6af2cc439b88) WaitActive WaitActive WaitActive ds_transition to WaitQuorum","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:37.721778157Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1191}
1662023-09-22T23:28:38.324Z{"msg":"[0] Transition from WaitActive to WaitQuorum","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:37.721851178Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1191}
1672023-09-22T23:28:38.328Z{"msg":"[0] new RM replaced this: None","v":0,"name":"crucible","level":40,"time":"2023-09-22T23:28:37.721933712Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1191}
1682023-09-22T23:28:38.331Z{"msg":"[0] 127.0.0.1:8810 task reports connection:true","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:37.721978831Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1191}
1692023-09-22T23:28:38.334Z{"msg":"[1] 97c9db57-64ee-426e-a180-ee7a97164a6a (92d481d1-a4aa-4c60-8d5b-6af2cc439b88) WaitQuorum WaitActive WaitActive ds_transition to WaitQuorum","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:37.722021Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1191}
1702023-09-22T23:28:38.337Z{"msg":"[1] Transition from WaitActive to WaitQuorum","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:37.72204178Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1191}
1712023-09-22T23:28:38.340Z{"msg":"[1] new RM replaced this: None","v":0,"name":"crucible","level":40,"time":"2023-09-22T23:28:37.722078141Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1191}
1722023-09-22T23:28:38.343Z{"msg":"97c9db57-64ee-426e-a180-ee7a97164a6a WaitQuorum WaitQuorum WaitActive","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:37.722123321Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1191}
1732023-09-22T23:28:38.346Z{"msg":"[2] 97c9db57-64ee-426e-a180-ee7a97164a6a (92d481d1-a4aa-4c60-8d5b-6af2cc439b88) WaitQuorum WaitQuorum WaitActive ds_transition to WaitQuorum","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:37.72214826Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1191}
1742023-09-22T23:28:38.350Z{"msg":"[2] Transition from WaitActive to WaitQuorum","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:37.722167004Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1191}
1752023-09-22T23:28:38.353Z{"msg":"[2] new RM replaced this: None","v":0,"name":"crucible","level":40,"time":"2023-09-22T23:28:37.722209096Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1191}
1762023-09-22T23:28:38.356Z{"msg":"[0] Starts reconcile loop","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:37.722230375Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1191}
1772023-09-22T23:28:38.359Z{"msg":"[1] Starts reconcile loop","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:37.722267017Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1191}
1782023-09-22T23:28:38.362Z{"msg":"[0]R flush_numbers: [1936, 1936, 1936, 1936, 1936]","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:37.722413831Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1191}
1792023-09-22T23:28:38.365Z{"msg":"[0]R generation: [20, 20, 20, 20, 20]","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:37.722472693Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1191}
1802023-09-22T23:28:38.368Z{"msg":"[0]R dirty: [false, false, false, false, false]","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:37.722515201Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1191}
1812023-09-22T23:28:38.372Z{"msg":"[1]R flush_numbers: [1936, 1936, 1936, 1936, 1936]","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:37.722553767Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1191}
1822023-09-22T23:28:38.376Z{"msg":"[1]R generation: [20, 20, 20, 20, 20]","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:37.722591568Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1191}
1832023-09-22T23:28:38.380Z{"msg":"[1]R dirty: [false, false, false, false, false]","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:37.722629168Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1191}
1842023-09-22T23:28:38.384Z{"msg":"[2]R flush_numbers: [1936, 1936, 1936, 1936, 1936]","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:37.722666719Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1191}
1852023-09-22T23:28:38.388Z{"msg":"[2]R generation: [20, 20, 20, 20, 20]","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:37.722704752Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1191}
1862023-09-22T23:28:38.393Z{"msg":"[2]R dirty: [false, false, false, false, false]","v":0,"name":"crucible","level":30The guest has finished waiting for activation with:26
1872023-09-22T23:28:38.398ZWait for a query_work_queue command to finish before sending IO
1882023-09-22T23:28:38.402Z,"time":"2023-09-22T23:28:37.722768551Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1191}
1892023-09-22T23:28:38.407Z{"msg":"Max found gen is 21","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:37.722992288Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1191}
1902023-09-22T23:28:38.411Z{"msg":"Generation requested: 26 >= found:21","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:37.723070177Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1191}
1912023-09-22T23:28:38.416Z{"msg":"Next flush: 1937","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:37.723137121Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1191}
1922023-09-22T23:28:38.420Z{"msg":"All extents match","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:37.723181707Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1191}
1932023-09-22T23:28:38.424Z{"msg":"No downstairs repair required","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:37.723201845Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1191}
1942023-09-22T23:28:38.428Z{"msg":"[2] Starts reconcile loop","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:37.723218903Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1191}
1952023-09-22T23:28:38.433Z{"msg":"No initial repair work was required","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:37.723236264Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1191}
1962023-09-22T23:28:38.437Z{"msg":"Set Downstairs and Upstairs active","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:37.723253302Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1191}
1972023-09-22T23:28:38.441Z{"msg":"97c9db57-64ee-426e-a180-ee7a97164a6a is now active with session: 92d481d1-a4aa-4c60-8d5b-6af2cc439b88","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:37.723272141Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1191}
1982023-09-22T23:28:38.445Z{"msg":"97c9db57-64ee-426e-a180-ee7a97164a6a Set Active after no repair","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:37.723290722Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1191}
1992023-09-22T23:28:38.449Z{"msg":"Notify all downstairs, region set compare is done.","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:37.723308601Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1191}
2002023-09-22T23:28:38.454Z{"msg":"Set check for repair","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:37.723325288Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1191}
2012023-09-22T23:28:38.457Z{"msg":"[1] 127.0.0.1:8820 task reports connection:true","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:37.723342828Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1191}
2022023-09-22T23:28:38.462Z{"msg":"97c9db57-64ee-426e-a180-ee7a97164a6a Active Active Active","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:37.723360897Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1191}
2032023-09-22T23:28:38.466Z{"msg":"Set check for repair","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:37.723384781Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1191}
2042023-09-22T23:28:38.470Z{"msg":"[2] 127.0.0.1:8830 task reports connection:true","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:37.723418208Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1191}
2052023-09-22T23:28:38.474Z{"msg":"97c9db57-64ee-426e-a180-ee7a97164a6a Active Active Active","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:37.723454856Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1191}
2062023-09-22T23:28:38.478Z{"msg":"Set check for repair","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:37.723490301Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1191}
2072023-09-22T23:28:38.483Z{"msg":"[2] received reconcile message","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:37.72352347Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1191}
2082023-09-22T23:28:38.487Z{"msg":"[2] All repairs completed, exit","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:37.723545949Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1191}
2092023-09-22T23:28:38.493Z{"msg":"[0] received reconcile message","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:37.723563366Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1191}
2102023-09-22T23:28:38.498Z{"msg":"[2] Starts cmd_loop","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:37.723593915Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1191}
2112023-09-22T23:28:38.502Z{"msg":"[1] received reconcile message","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:37.723627335Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1191}
2122023-09-22T23:28:38.510Z{"msg":"[0] All repairs completed, exit","v":0,"name":"crucible","level":30Region: es:10 ec:5 bs:4096 ts:204800 tb:50 max_io:50 or 204800
2132023-09-22T23:28:38.514Z,"time":"2023-09-22T23:28:37.723658976Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1191}
2142023-09-22T23:28:38.519Z{"msg":"[1] All repairs completed, exit","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:37.723688052Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1191}
2152023-09-22T23:28:38.523Z{"msg":"[1] Starts cmd_loop","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:37.723716813Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1191}
2162023-09-22T23:28:38.527Z{"msg":"[0] Starts cmd_loop","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:37.723749923Z","hostname":"Fill test
2172023-09-22T23:28:38.531Zip-10-150-1-92.us-west-2.compute.internal","pid":1191}
2182023-09-22T23:28:38.535ZRead and Verify all blocks (0..50 range:false)
2192023-09-22T23:28:38.539ZWrote out file "/var/tmp/test_up/verify_file"
2202023-09-22T23:28:38.543ZCLIENT: Tests done. All submitted work has been ACK'd
2212023-09-22T23:28:38.547Z----------------------------------------------------------------
2222023-09-22T23:28:38.551Z Crucible gen:26 GIO:true work queues: Upstairs:0 downstairs:1
2232023-09-22T23:28:38.563ZGW_ID ACK DSID TYPE BLOCKS DS:0 DS:1 DS:2 REPLAY
2242023-09-22T23:28:38.566Z 3 Acked 1002 Read 50 Done Done Done false
2252023-09-22T23:28:38.570Z STATES DS:0 DS:1 DS:2 TOTAL
2262023-09-22T23:28:38.574Z New 0 0 0 0
2272023-09-22T23:28:38.578Z Sent 0 0 0 0
2282023-09-22T23:28:38.582Z Done 1 1 1 3
2292023-09-22T23:28:38.586Z Skipped 0 0 0 0
2302023-09-22T23:28:38.590Z Error 0 0 0 0
2312023-09-22T23:28:38.605ZLast Flush: 1001 1001 1001
2322023-09-22T23:28:38.612ZDownstairs last five completed: 1001 1000
2332023-09-22T23:28:38.616ZUpstairs last five completed: 3 2 1
2342023-09-22T23:28:38.621ZCLIENT: Up:0 ds:1 act:3
2352023-09-22T23:28:38.722Z{"msg":"Checking if live repair is needed","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:38.723761219Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1191}
2362023-09-22T23:28:38.727Z{"msg":"No Live Repair required at this time","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:38.723844889Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1191}
2372023-09-22T23:28:42.069Z----------------------------------------------------------------
2382023-09-22T23:28:42.072Z Crucible gen:26 GIO:true work queues: Upstairs:0 downstairs:0
2392023-09-22T23:28:42.075ZDownstairs last five completed: 1003 1002 1001 1000
2402023-09-22T23:28:42.078ZUpstairs last five completed: 4 3 2 1
2412023-09-22T23:28:42.081ZCLIENT: Up:0 ds:0 act:3
2422023-09-22T23:28:42.084ZCLIENT: All crucible jobs finished, exiting program
2432023-09-22T23:28:42.087ZRepair setup passed
2442023-09-22T23:28:42.091ZCopy the 8830 file
2452023-09-22T23:28:42.094Zcp -r /var/tmp/test_up/8830 /var/tmp/test_up/previous
2462023-09-22T23:28:42.119Z/var/tmp/bins/crutest repair -g 27 -q --key qGG0x4QYrGYwxtQQkXTfx0CabBUcjy4poXsgGc6mOEc= -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
2472023-09-22T23:28:42.139Z{"msg":"Upstairs starts","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:42.13975635Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1197}
2482023-09-22T23:28:42.143Z{"msg":"Crucible Version: BuildInfo {\n version: \"0.0.1\",\n git_sha: \"ed48f294784d46ea7d4bb99336918b74358eca46\",\n git_commit_timestamp: \"2023-09-22T22:51:18.000000000Z\",\n git_branch: \"main\",\n rustc_semver: \"1.70.0\",\n rustc_channel: \"stable\",\n rustc_host_triple: \"x86_64-unknown-illumos\",\n rustc_commit_sha: \"90c541806f23a127002de5b4038be731ba1458ca\",\n cargo_triple: \"x86_64-unknown-illumos\",\n debug: true,\n opt_level: 0,\n}","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:42.140172301Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1197}
2492023-09-22T23:28:42.146Z{"msg":"Upstairs <-> Downstairs Message Version: 4","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:42.140234054Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1197}
2502023-09-22T23:28:42.149Z{"msg":"Crucible stats registered with UUID: 2847a81c-d93c-440c-83bf-dbd25bb6b28a","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:42.140258891Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1197}
2512023-09-22T23:28:42.152Z{"msg":"Crucible 2847a81c-d93c-440c-83bf-dbd25bb6b28a has session id: 9665f029-ed17-47e7-ad88-5c6b1678ec72","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:42.140298351Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1197}
2522023-09-22T23:28:42.155ZCrucible runtime is spawned
2532023-09-22T23:28:42.159ZThe guest has requested activation with gen:27
2542023-09-22T23:28:42.162Z{"msg":"up_listen starts","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:42.140729182Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1197,"task":"up_listen"}
2552023-09-22T23:28:42.165Z{"msg":"Wait for all three downstairs to come online","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:42.140815614Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1197}
2562023-09-22T23:28:42.168Z{"msg":"Flush timeout: 0.5","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:42.14088482Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1197}
2572023-09-22T23:28:42.172Z{"msg":"[0] connecting to 127.0.0.1:8810","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:42.140950314Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1197,"looper":"0"}
2582023-09-22T23:28:42.174Z{"msg":"[0] 2847a81c-d93c-440c-83bf-dbd25bb6b28a looper connected","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:42.141172356Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1197,"looper":"0"}
2592023-09-22T23:28:42.178Z{"msg":"[1] connecting to 127.0.0.1:8820","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:42.14124668Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1197,"looper":"1"}
2602023-09-22T23:28:42.181Z{"msg":"[2] connecting to 127.0.0.1:8830","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:42.141420342Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1197,"looper":"2"}
2612023-09-22T23:28:42.184Z{"msg":"[1] 2847a81c-d93c-440c-83bf-dbd25bb6b28a looper connected","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:42.14149889Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1197,"looper":"1"}
2622023-09-22T23:28:42.187Z{"msg":"[2] 2847a81c-d93c-440c-83bf-dbd25bb6b28a looper connected","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:42.14156367Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1197,"looper":"2"}
2632023-09-22T23:28:42.190Z{"msg":"2847a81c-d93c-440c-83bf-dbd25bb6b28a active request set","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:42.14195935Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1197}
2642023-09-22T23:28:42.193Z{"msg":"Set desired generation to :27","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:42.142017972Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1197}
2652023-09-22T23:28:42.196Z{"msg":"[0] Proc runs for 127.0.0.1:8810 in state New","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:42.142140266Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1197}
2662023-09-22T23:28:42.199Z{"msg":"[1] Proc runs for 127.0.0.1:8820 in state New","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:42.142454701Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1197}
2672023-09-22T23:28:42.202Z{"msg":"[2] Proc runs for 127.0.0.1:8830 in state New","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:42.142587243Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1197}
2682023-09-22T23:28:42.206Z{"msg":"[0] 2847a81c-d93c-440c-83bf-dbd25bb6b28a (2f376a52-757e-429a-a169-d4616499e7c5) New New New ds_transition to WaitActive","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:42.142848877Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1197}
2692023-09-22T23:28:42.209Z{"msg":"[0] Transition from New to WaitActive","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:42.142933942Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1197}
2702023-09-22T23:28:42.212Z{"msg":"[0] client is_active_req TRUE, promote! session 2f376a52-757e-429a-a169-d4616499e7c5","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:42.142983999Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1197}
2712023-09-22T23:28:42.215Z{"msg":"[2] 2847a81c-d93c-440c-83bf-dbd25bb6b28a (2f376a52-757e-429a-a169-d4616499e7c5) WaitActive New New ds_transition to WaitActive","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:42.143039126Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1197}
2722023-09-22T23:28:42.220Z{"msg":"[2] Transition from New to WaitActive","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:42.143127296Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1197}
2732023-09-22T23:28:42.224Z{"msg":"[2] client is_active_req TRUE, promote! session 2f376a52-757e-429a-a169-d4616499e7c5","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:42.14318565Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1197}
2742023-09-22T23:28:42.227Z{"msg":"[1] 2847a81c-d93c-440c-83bf-dbd25bb6b28a (2f376a52-757e-429a-a169-d4616499e7c5) WaitActive New WaitActive ds_transition to WaitActive","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:42.14321204Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1197}
2752023-09-22T23:28:42.234Z{"msg":"[1] Transition from New to WaitActive","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:42.143263648Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1197}
2762023-09-22T23:28:42.237Z{"msg":"[1] client is_active_req TRUE, promote! session 2f376a52-757e-429a-a169-d4616499e7c5","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:42.143323947Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1197}
2772023-09-22T23:28:42.240Z{"msg":"[0] downstairs client at 127.0.0.1:8810 has UUID 12345678-0000-0000-0000-000000008810","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:42.143636918Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1197}
2782023-09-22T23:28:42.243Z{"msg":"[0] Got region def RegionDefinition { block_size: 4096, extent_size: Block { value: 10, shift: 12 }, extent_count: 5, uuid: 12345678-0000-0000-0000-000000008810, encrypted: true, database_read_version: 1, database_write_version: 1 }","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:42.143712276Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1197}
2792023-09-22T23:28:42.246Z{"msg":"[2] downstairs client at 127.0.0.1:8830 has UUID 12345678-0000-0000-0000-000000008830","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:42.143784382Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1197}
2802023-09-22T23:28:42.251Z{"msg":"[2] Got region def RegionDefinition { block_size: 4096, extent_size: Block { value: 10, shift: 12 }, extent_count: 5, uuid: 12345678-0000-0000-0000-000000008830, encrypted: true, database_read_version: 1, database_write_version: 1 }","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:42.143856207Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1197}
2812023-09-22T23:28:42.254Z{"msg":"2847a81c-d93c-440c-83bf-dbd25bb6b28a WaitActive WaitActive WaitActive","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:42.143926739Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1197}
2822023-09-22T23:28:42.258Z{"msg":"[1] downstairs client at 127.0.0.1:8820 has UUID 12345678-0000-0000-0000-000000008820","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:42.14399793Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1197}
2832023-09-22T23:28:42.262Z{"msg":"[1] Got region def RegionDefinition { block_size: 4096, extent_size: Block { value: 10, shift: 12 }, extent_count: 5, uuid: 12345678-0000-0000-0000-000000008820, encrypted: true, database_read_version: 1, database_write_version: 1 }","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:42.144078218Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1197}
2842023-09-22T23:28:42.268Z{"msg":"2847a81c-d93c-440c-83bf-dbd25bb6b28a WaitActive WaitActive WaitActive","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:42.14412192Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1197}
2852023-09-22T23:28:42.271Z{"msg":"2847a81c-d93c-440c-83bf-dbd25bb6b28a WaitActive WaitActive WaitActive","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:42.144161807Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1197}
2862023-09-22T23:28:42.280Z{"msg":"[2] 2847a81c-d93c-440c-83bf-dbd25bb6b28a (2f376a52-757e-429a-a169-d4616499e7c5) WaitActive WaitActive WaitActive ds_transition to WaitQuorum","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:42.144440103Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1197}
2872023-09-22T23:28:42.289Z{"msg":"[2] Transition from WaitActive to WaitQuorum","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:42.144524082Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1197}
2882023-09-22T23:28:42.294Z{"msg":"[2] new RM replaced this: None","v":0,"name":"crucible","level":40,"time":"2023-09-22T23:28:42.14457795Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1197}
2892023-09-22T23:28:42.298Z{"msg":"[2] Starts reconcile loop","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:42.144620191Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1197}
2902023-09-22T23:28:42.304Z{"msg":"[2] 127.0.0.1:8830 task reports connection:true","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:42.144659161Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1197}
2912023-09-22T23:28:42.314Z{"msg":"2847a81c-d93c-440c-83bf-dbd25bb6b28a WaitActive WaitActive WaitQuorum","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:42.144697787Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1197}
2922023-09-22T23:28:42.319Z{"msg":"Waiting for 2 more clients to be ready","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:42.144736114Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1197}
2932023-09-22T23:28:42.325Z{"msg":"Set check for repair","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:42.144787968Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1197}
2942023-09-22T23:28:42.333Z{"msg":"[1] 2847a81c-d93c-440c-83bf-dbd25bb6b28a (2f376a52-757e-429a-a169-d4616499e7c5) WaitActive WaitActive WaitQuorum ds_transition to WaitQuorum","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:42.144837349Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1197}
2952023-09-22T23:28:42.338Z{"msg":"[1] Transition from WaitActive to WaitQuorum","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:42.144888433Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1197}
2962023-09-22T23:28:42.342Z{"msg":"[1] new RM replaced this: None","v":0,"name":"crucible","level":40,"time":"2023-09-22T23:28:42.144928077Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1197}
2972023-09-22T23:28:42.350Z{"msg":"[1] Starts reconcile loop","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:42.144965979Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1197}
2982023-09-22T23:28:42.359Z{"msg":"[1] 127.0.0.1:8820 task reports connection:true","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:42.145004074Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1197}
2992023-09-22T23:28:42.362Z{"msg":"[0] 2847a81c-d93c-440c-83bf-dbd25bb6b28a (2f376a52-757e-429a-a169-d4616499e7c5) WaitActive WaitQuorum WaitQuorum ds_transition to WaitQuorum","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:42.145044275Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1197}
3002023-09-22T23:28:42.365Z{"msg":"[0] Transition from WaitActive to WaitQuorum","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:42.145082718Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1197}
3012023-09-22T23:28:42.369Z{"msg":"[0] new RM replaced this: None","v":0,"name":"crucible","level":40,"time":"2023-09-22T23:28:42.14513133Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1197}
3022023-09-22T23:28:42.372ZThe guest has finished waiting for activation with:27
3032023-09-22T23:28:42.375Z{"msg":"Wait for a query_work_queue command to finish before sending IO
3042023-09-22T23:28:42.378Z2847a81c-d93c-440c-83bf-dbd25bb6b28a WaitQuorum WaitQuorum WaitQuorum","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:42.145204695Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1197}
3052023-09-22T23:28:42.381Z{"msg":"[0] Starts reconcile loop","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:42.145279439Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1197}
3062023-09-22T23:28:42.384Z{"msg":"[0]R flush_numbers: [1937, 1937, 1937, 1937, 1937]","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:42.145337278Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1197}
3072023-09-22T23:28:42.388Z{"msg":"[0]R generation: [26, 26, 26, 26, 26]","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:42.145413334Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1197}
3082023-09-22T23:28:42.390Z{"msg":"[0]R dirty: [false, false, false, false, false]","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:42.145453522Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1197}
3092023-09-22T23:28:42.394Z{"msg":"[1]R flush_numbers: [1937, 1937, 1937, 1937, 1937]","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:42.145506077Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1197}
3102023-09-22T23:28:42.397Z{"msg":"[1]R generation: [26, 26, 26, 26, 26]","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:42.145528271Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1197}
3112023-09-22T23:28:42.400Z{"msg":"[1]R dirty: [false, false, false, false, false]","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:42.145572004Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1197}
3122023-09-22T23:28:42.406Z{"msg":"[2]R flush_numbers: [1937, 1937, 1937, 1937, 1937]","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:42.14559168Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1197}
3132023-09-22T23:28:42.410Z{"msg":"[2]R generation: [26, 26, 26, 26, 26]","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:42.145611007Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1197}
3142023-09-22T23:28:42.413Z{"msg":"[2]R dirty: [false, false, false, false, false]","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:42.145665892Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1197}
3152023-09-22T23:28:42.418Z{"msg":"Max found gen is 27","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:42.14570161Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1197}
3162023-09-22T23:28:42.421Z{"msg":"Generation requested: 27 >= found:27","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:42.145730768Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1197}
3172023-09-22T23:28:42.424Z{"msg":"Next flush: 1938","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:42.145749638Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1197}
3182023-09-22T23:28:42.427Z{"msg":"All extents match","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:42.145766706Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1197}
3192023-09-22T23:28:42.430Z{"msg":"No downstairs repair required","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:42.145787347Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1197}
3202023-09-22T23:28:42.433Z{"msg":"No initial repair work was required","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:42.145810057Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1197}
3212023-09-22T23:28:42.436Z{"msg":"Set Downstairs and Upstairs active","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:42.14582806Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1197}
3222023-09-22T23:28:42.439Z{"msg":"2847a81c-d93c-440c-83bf-dbd25bb6b28a is now active with session: 2f376a52-757e-429a-a169-d4616499e7c5","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:42.145861098Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1197}
3232023-09-22T23:28:42.442Z{"msg":"2847a81c-d93c-440c-83bf-dbd25bb6b28a Set Active after no repair","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:42.145896651Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1197}
3242023-09-22T23:28:42.447Z{"msg":"Notify all downstairs, region set compare is done.","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:42.14592491Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1197}
3252023-09-22T23:28:42.450Z{"msg":"Set check for repair","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:42.145943172Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1197}
3262023-09-22T23:28:42.453Z{"msg":"[0] 127.0.0.1:8810 task reports connection:true","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:42.145961387Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1197}
3272023-09-22T23:28:42.456Z{"msg":"2847a81c-d93c-440c-83bf-dbd25bb6b28a Active Active Active","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:42.145979634Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1197}
3282023-09-22T23:28:42.458Z{"msg":"Set check for repair","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:42.145996782Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1197}
3292023-09-22T23:28:42.462Z{"msg":"[1] received reconcile message","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:42.146014387Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1197}
3302023-09-22T23:28:42.465Z{"msg":"[0] received reconcile message","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:42.146037545Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1197}
3312023-09-22T23:28:42.468Z{"msg":"[2] received reconcile message","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:42.146070406Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1197}
3322023-09-22T23:28:42.471Z{"msg":"[1] All repairs completed, exit","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:42.14609887Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1197}
3332023-09-22T23:28:42.474Z{"msg":"[1] Starts cmd_loop","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:42.146122507Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1197}
3342023-09-22T23:28:42.476ZRegion: es:10 ec:5 bs:4096 ts:204800 tb:50 max_io:50 or 204800
3352023-09-22T23:28:42.479Z{"msg":"[0] All repairs completed, exit","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:42.146158852Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1197}
3362023-09-22T23:28:42.482Z{"msg":"[0] Starts cmd_loop","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:42.146190693Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1197}
3372023-09-22T23:28:42.485Z{"msg":"[2] All repairs completed, exit","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:42.146220354Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1197}
3382023-09-22T23:28:42.488Z{"msg":"[2] Starts cmd_loop","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:42.146251774Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1197}
3392023-09-22T23:28:42.491ZLoading write count information from file "/var/tmp/test_up/verify_file"
3402023-09-22T23:28:42.494ZRun Repair workload
3412023-09-22T23:28:42.497Z01/10 Write block 44 len 12288 data: 2 2 2
3422023-09-22T23:28:42.500Z02/10 Write block 37 len 36864 data: 2 2 2 2 2 2 2 3 3
3432023-09-22T23:28:42.503Z03/10 Write block 3 len 20480 data: 2 2 2 2 2
3442023-09-22T23:28:42.506Z04/10 Read block 12 len 36864
3452023-09-22T23:28:42.509Z05/10 Read block 39 len 32768
3462023-09-22T23:28:42.513Z06/10 Flush
3472023-09-22T23:28:42.515Z07/10 Write block 23 len 16384 data: 2 2 2 2
3482023-09-22T23:28:42.518Z08/10 Write block 6 len 28672 data: 3 3 2 2 2 2 2
3492023-09-22T23:28:42.522Z09/10 Write block 7 len 12288 data: 4 3 3
3502023-09-22T23:28:42.525Z10/10 Read block 2 len 32768
3512023-09-22T23:28:42.528Z----------------------------------------------------------------
3522023-09-22T23:28:42.531Z Crucible gen:27 GIO:true work queues: Upstairs:0 downstairs:4
3532023-09-22T23:28:42.534ZGW_ID ACK DSID TYPE BLOCKS DS:0 DS:1 DS:2 REPLAY
3542023-09-22T23:28:42.537Z 7 Acked 1006 Write 4 Done Done Done false
3552023-09-22T23:28:42.540Z 8 Acked 1007 Write 7 Done Done Done false
3562023-09-22T23:28:42.543Z 9 Acked 1008 Write 3 Done Done Done false
3572023-09-22T23:28:42.546Z 10 Acked 1009 Read 8 Done Sent Sent false
3582023-09-22T23:28:42.549Z STATES DS:0 DS:1 DS:2 TOTAL
3592023-09-22T23:28:42.552Z New 0 0 0 0
3602023-09-22T23:28:42.555Z Sent 0 1 1 2
3612023-09-22T23:28:42.558Z Done 4 3 3 10
3622023-09-22T23:28:42.561Z Skipped 0 0 0 0
3632023-09-22T23:28:42.566Z Error 0 0 0 0
3642023-09-22T23:28:42.569ZLast Flush: 1005 1005 1005
3652023-09-22T23:28:42.572ZDownstairs last five completed: 1005 1004 1003 1002 1001 1000
3662023-09-22T23:28:42.575ZUpstairs last five completed: 10 9 8 7 6 5
3672023-09-22T23:28:42.578ZWrote out file "/var/tmp/test_up/verify_file"
3682023-09-22T23:28:42.581Z{"msg":"127.0.0.1:8820: proc: channel closed","v":0,"name":"crucible","level":50,"time":"2023-09-22T23:28:42.279187184Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1197,"looper":"1"}
3692023-09-22T23:28:42.584Z{"msg":"[2] pm_task rx.recv() is None","v":0,"name":"crucible","level":40,"time":"2023-09-22T23:28:42.287932847Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1197}
3702023-09-22T23:28:42.587ZRepair part 1 passed
3712023-09-22T23:28:42.590Z
3722023-09-22T23:28:42.593ZKill the current downstairs
3732023-09-22T23:28:43.006Zrm -rf /var/tmp/test_up/8830
3742023-09-22T23:28:43.009ZNow put back the original so we have a mismatch
3752023-09-22T23:28:43.012Zmv /var/tmp/test_up/previous /var/tmp/test_up/8830
3762023-09-22T23:28:43.015ZRestart downstairs with old directory
3772023-09-22T23:28:43.018Z/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
3782023-09-22T23:28:43.022Z{"msg":"current number of open files limit 65536 is already the maximum","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:42.63523064Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1203}
3792023-09-22T23:28:43.025Z{"msg":"Database read version 1","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:42.635634882Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1203}
3802023-09-22T23:28:43.029Z{"msg":"Database write version 1","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:42.635679699Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1203}
3812023-09-22T23:28:43.032Z{"msg":"current number of open files limit 65536 is already the maximum","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:42.645274511Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1203}
3822023-09-22T23:28:43.035Z{"msg":"Database read version 1","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:42.645338841Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1203}
3832023-09-22T23:28:43.039Z{"msg":"Database write version 1","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:42.645359983Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1203}
3842023-09-22T23:28:43.042Z{"msg":"current number of open files limit 65536 is already the maximum","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:42.65096226Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1203}
3852023-09-22T23:28:43.045Z{"msg":"Database read version 1","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:42.65101537Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1203}
3862023-09-22T23:28:43.053Z{"msg":"Database write version 1","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:42.651053965Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1203}
3872023-09-22T23:28:43.077ZEXT BLOCKS GEN0 GEN1 GEN2 FL0 FL1 FL2 D0 D1 D2 DIFF
3882023-09-22T23:28:43.081Z 0 000-009 27 27 26 1938 1938 1937 T T F <---
3892023-09-22T23:28:43.084Z 1 010-019 26 26 26 1937 1937 1937 T T F <---
3902023-09-22T23:28:43.089Z 2 020-029 26 26 26 1937 1937 1937 T T F <---
3912023-09-22T23:28:43.092Z 3 030-039 27 27 26 1938 1938 1937 F F F <---
3922023-09-22T23:28:43.095Z 4 040-049 27 27 26 1938 1938 1937 F F F <---
3932023-09-22T23:28:43.098ZMax gen: 27, Max flush: 1938
3942023-09-22T23:28:43.101ZError: Difference in extent metadata found!
3952023-09-22T23:28:43.105Zdump test found error as expected
3962023-09-22T23:28:43.108Z
3972023-09-22T23:28:43.111Z
3982023-09-22T23:28:43.114Z/var/tmp/bins/crutest deactivate --range -g 28 -q --key qGG0x4QYrGYwxtQQkXTfx0CabBUcjy4poXsgGc6mOEc= -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
3992023-09-22T23:28:43.118Z{"msg":"Upstairs starts","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:42.766283056Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1204}
4002023-09-22T23:28:43.121Z{"msg":"Crucible Version: BuildInfo {\n version: \"0.0.1\",\n git_sha: \"ed48f294784d46ea7d4bb99336918b74358eca46\",\n git_commit_timestamp: \"2023-09-22T22:51:18.000000000Z\",\n git_branch: \"main\",\n rustc_semver: \"1.70.0\",\n rustc_channel: \"stable\",\n rustc_host_triple: \"x86_64-unknown-illumos\",\n rustc_commit_sha: \"90c541806f23a127002de5b4038be731ba1458ca\",\n cargo_triple: \"x86_64-unknown-illumos\",\n debug: true,\n opt_level: 0,\n}","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:42.766718271Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1204}
4012023-09-22T23:28:43.124Z{"msg":"Upstairs <-> Downstairs Message Version: 4","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:42.766771898Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1204}
4022023-09-22T23:28:43.127Z{"msg":"Crucible stats registered with UUID: 4f5b30d9-884a-4acc-96a8-a0bb1b5e458c","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:42.766815031Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1204}
4032023-09-22T23:28:43.133Z{"msg":"Crucible 4f5b30d9-884a-4acc-96a8-a0bb1b5e458c has session id: 3fb725e8-e991-4720-a092-4a108049b840","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:42.766857101Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1204}
4042023-09-22T23:28:43.137ZCrucible runtime is spawned
4052023-09-22T23:28:43.141ZThe guest has requested activation with gen:28
4062023-09-22T23:28:43.144Z{"msg":"up_listen starts","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:42.767253553Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1204,"task":"up_listen"}
4072023-09-22T23:28:43.148Z{"msg":"Wait for all three downstairs to come online","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:42.767335356Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1204}
4082023-09-22T23:28:43.152Z{"msg":"Flush timeout: 0.5","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:42.767402402Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1204}
4092023-09-22T23:28:43.156Z{"msg":"[1] connecting to 127.0.0.1:8820","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:42.767466145Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1204,"looper":"1"}
4102023-09-22T23:28:43.160Z{"msg":"[1] 4f5b30d9-884a-4acc-96a8-a0bb1b5e458c looper connected","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:42.767719418Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1204,"looper":"1"}
4112023-09-22T23:28:43.165Z{"msg":"[2] connecting to 127.0.0.1:8830","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:42.767800165Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1204,"looper":"2"}
4122023-09-22T23:28:43.168Z{"msg":"[0] connecting to 127.0.0.1:8810","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:42.767946841Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1204,"looper":"0"}
4132023-09-22T23:28:43.171Z{"msg":"[0] 4f5b30d9-884a-4acc-96a8-a0bb1b5e458c looper connected","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:42.768113107Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1204,"looper":"0"}
4142023-09-22T23:28:43.175Z{"msg":"4f5b30d9-884a-4acc-96a8-a0bb1b5e458c active request set","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:42.768295914Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1204}
4152023-09-22T23:28:43.181Z{"msg":"Set desired generation to :28","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:42.768355648Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1204}
4162023-09-22T23:28:43.185Z{"msg":"[1] Proc runs for 127.0.0.1:8820 in state New","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:42.768492807Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1204}
4172023-09-22T23:28:43.193Z{"msg":"[0] Proc runs for 127.0.0.1:8810 in state New","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:42.768804079Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1204}
4182023-09-22T23:28:43.197Z{"msg":"[1] 4f5b30d9-884a-4acc-96a8-a0bb1b5e458c (ec0e7796-968e-44ad-bd3b-8c3c402f3ba3) New New New ds_transition to WaitActive","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:42.769121983Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1204}
4192023-09-22T23:28:43.200Z{"msg":"[1] Transition from New to WaitActive","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:42.769179543Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1204}
4202023-09-22T23:28:43.203Z{"msg":"[1] client is_active_req TRUE, promote! session ec0e7796-968e-44ad-bd3b-8c3c402f3ba3","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:42.769202216Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1204}
4212023-09-22T23:28:43.206Z{"msg":"[0] 4f5b30d9-884a-4acc-96a8-a0bb1b5e458c (ec0e7796-968e-44ad-bd3b-8c3c402f3ba3) New WaitActive New ds_transition to WaitActive","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:42.769378671Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1204}
4222023-09-22T23:28:43.210Z{"msg":"[0] Transition from New to WaitActive","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:42.769438187Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1204}
4232023-09-22T23:28:43.213Z{"msg":"[0] client is_active_req TRUE, promote! session ec0e7796-968e-44ad-bd3b-8c3c402f3ba3","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:42.76951325Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1204}
4242023-09-22T23:28:43.218Z{"msg":"[1] downstairs client at 127.0.0.1:8820 has UUID 12345678-0000-0000-0000-000000008820","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:42.769741508Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1204}
4252023-09-22T23:28:43.221Z{"msg":"[1] Got region def RegionDefinition { block_size: 4096, extent_size: Block { value: 10, shift: 12 }, extent_count: 5, uuid: 12345678-0000-0000-0000-000000008820, encrypted: true, database_read_version: 1, database_write_version: 1 }","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:42.769804028Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1204}
4262023-09-22T23:28:43.224Z{"msg":"4f5b30d9-884a-4acc-96a8-a0bb1b5e458c WaitActive WaitActive New","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:42.769856334Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1204}
4272023-09-22T23:28:43.227Z{"msg":"[0] downstairs client at 127.0.0.1:8810 has UUID 12345678-0000-0000-0000-000000008810","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:42.769921385Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1204}
4282023-09-22T23:28:43.230Z{"msg":"[0] Got region def RegionDefinition { block_size: 4096, extent_size: Block { value: 10, shift: 12 }, extent_count: 5, uuid: 12345678-0000-0000-0000-000000008810, encrypted: true, database_read_version: 1, database_write_version: 1 }","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:42.769975671Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1204}
4292023-09-22T23:28:43.233Z{"msg":"4f5b30d9-884a-4acc-96a8-a0bb1b5e458c WaitActive WaitActive New","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:42.770025965Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1204}
4302023-09-22T23:28:43.237Z{"msg":"[1] 4f5b30d9-884a-4acc-96a8-a0bb1b5e458c (ec0e7796-968e-44ad-bd3b-8c3c402f3ba3) WaitActive WaitActive New ds_transition to WaitQuorum","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:42.77048346Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1204}
4312023-09-22T23:28:43.240Z{"msg":"[1] Transition from WaitActive to WaitQuorum","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:42.770543222Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1204}
4322023-09-22T23:28:43.243Z{"msg":"[1] new RM replaced this: None","v":0,"name":"crucible","level":40,"time":"2023-09-22T23:28:42.770568825Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1204}
4332023-09-22T23:28:43.246Z{"msg":"[1] Starts reconcile loop","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:42.7706042Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1204}
4342023-09-22T23:28:43.249Z{"msg":"[1] 127.0.0.1:8820 task reports connection:true","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:42.770663129Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1204}
4352023-09-22T23:28:43.252Z{"msg":"4f5b30d9-884a-4acc-96a8-a0bb1b5e458c WaitActive WaitQuorum New","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:42.770705072Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1204}
4362023-09-22T23:28:43.255Z{"msg":"Waiting for 2 more clients to be ready","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:42.770743156Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1204}
4372023-09-22T23:28:43.258Z{"msg":"Set check for repair","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:42.770780968Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1204}
4382023-09-22T23:28:43.262Z{"msg":"[0] 4f5b30d9-884a-4acc-96a8-a0bb1b5e458c (ec0e7796-968e-44ad-bd3b-8c3c402f3ba3) WaitActive WaitQuorum New ds_transition to WaitQuorum","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:42.770821546Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1204}
4392023-09-22T23:28:43.265Z{"msg":"[0] Transition from WaitActive to WaitQuorum","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:42.77084179Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1204}
4402023-09-22T23:28:43.268Z{"msg":"[0] new RM replaced this: None","v":0,"name":"crucible","level":40,"time":"2023-09-22T23:28:42.77085947Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1204}
4412023-09-22T23:28:43.271Z{"msg":"[0] Starts reconcile loop","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:42.770877233Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1204}
4422023-09-22T23:28:43.274Z{"msg":"[0] 127.0.0.1:8810 task reports connection:true","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:42.770895495Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1204}
4432023-09-22T23:28:43.278Z{"msg":"4f5b30d9-884a-4acc-96a8-a0bb1b5e458c WaitQuorum WaitQuorum New","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:42.770913605Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1204}
4442023-09-22T23:28:43.281Z{"msg":"Waiting for 1 more clients to be ready","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:42.770930884Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1204}
4452023-09-22T23:28:43.284Z{"msg":"Set check for repair","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:42.770948075Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1204}
4462023-09-22T23:28:43.770Z{"msg":"Checking if live repair is needed","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:43.771874062Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1204}
4472023-09-22T23:28:46.770Z{"msg":"[2] 4f5b30d9-884a-4acc-96a8-a0bb1b5e458c looper connected","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:46.77157936Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1204,"looper":"2"}
4482023-09-22T23:28:46.774Z{"msg":"[2] Proc runs for 127.0.0.1:8830 in state New","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:46.771663716Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1204}
4492023-09-22T23:28:46.778Z{"msg":"[2] 4f5b30d9-884a-4acc-96a8-a0bb1b5e458c (ec0e7796-968e-44ad-bd3b-8c3c402f3ba3) WaitQuorum WaitQuorum New ds_transition to WaitActive","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:46.77249323Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1204}
4502023-09-22T23:28:46.783Z{"msg":"[2] Transition from New to WaitActive","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:46.772526311Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1204}
4512023-09-22T23:28:46.789Z{"msg":"[2] client is_active_req TRUE, promote! session ec0e7796-968e-44ad-bd3b-8c3c402f3ba3","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:46.772585342Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1204}
4522023-09-22T23:28:46.794Z{"msg":"[2] downstairs client at 127.0.0.1:8830 has UUID 12345678-0000-0000-0000-000000008830","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:46.773245824Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1204}
4532023-09-22T23:28:46.798Z{"msg":"[2] Got region def RegionDefinition { block_size: 4096, extent_size: Block { value: 10, shift: 12 }, extent_count: 5, uuid: 12345678-0000-0000-0000-000000008830, encrypted: true, database_read_version: 1, database_write_version: 1 }","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:46.77333913Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1204}
4542023-09-22T23:28:46.803Z{"msg":"4f5b30d9-884a-4acc-96a8-a0bb1b5e458c WaitQuorum WaitQuorum WaitActive","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:46.773395726Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1204}
4552023-09-22T23:28:46.806Z{"msg":"[2] 4f5b30d9-884a-4acc-96a8-a0bb1b5e458c (ec0e7796-968e-44ad-bd3b-8c3c402f3ba3) WaitQuorum WaitQuorum WaitActive ds_transition to WaitQuorum","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:46.77417965Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1204}
4562023-09-22T23:28:46.810Z{"msg":"[2] Transition from WaitActive to WaitQuorum","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:46.774244431Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1204}
4572023-09-22T23:28:46.815Z{"msg":"[2] new RM replaced this: None","v":0,"name":"crucible","level":40,"time":"2023-09-22T23:28:46.774304492Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1204}
4582023-09-22T23:28:46.819Z{"msg":"[2] Starts reconcile loop","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:46.774354334Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1204}
4592023-09-22T23:28:46.823Z{"msg":"[2] 127.0.0.1:8830 task reports connection:true","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:46.774395288Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1204}
4602023-09-22T23:28:46.827Z{"msg":"4f5b30d9-884a-4acc-96a8-a0bb1b5e458c WaitQuorum WaitQuorum WaitQuorum","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:46.774435463Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1204}
4612023-09-22T23:28:46.831Z{"msg":"[0]R flush_numbers: [1938, 1937, 1937, 1938, 1938]","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:46.774475063Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1204}
4622023-09-22T23:28:46.835Z{"msg":"[0]R generation: [27, 26, 26, 27, 27]","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:46.774513493Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1204}
4632023-09-22T23:28:46.838Z{"msg":"[0]R dirty: [true, true, true, false, false]","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:46.774552818Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1204}
4642023-09-22T23:28:46.841Z{"msg":"[1]R flush_numbers: [1938, 1937, 1937, 1938, 1938]","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:46.774591199Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1204}
4652023-09-22T23:28:46.844Z{"msg":"[1]R generation: [27, 26, 26, 27, 27]","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:46.774629883Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1204}
4662023-09-22T23:28:46.847Z{"msg":"[1]R dirty: [true, true, true, false, false]","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:46.774669014Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1204}
4672023-09-22T23:28:46.850Z{"msg":"[2]R flush_numbers: [1937, 1937, 1937, 1937, 1937]","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:46.774707614Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1204}
4682023-09-22T23:28:46.853Z{"msg":"[2]R generation: [26, 26, 26, 26, 26]","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:46.774746143Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1204}
4692023-09-22T23:28:46.856Z{"msg":"[2]R dirty: [false, false, false, false, false]","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:46.774784566Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1204}
4702023-09-22T23:28:46.859Z{"msg":"Max found gen is 28","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:46.774822658Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1204}
4712023-09-22T23:28:46.863Z{"msg":"Generation requested: 28 >= found:28","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:46.774842079Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1204}
4722023-09-22T23:28:46.866Z{"msg":"Next flush: 1939","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:46.774877984Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1204}
4732023-09-22T23:28:46.869Z{"msg":"Extents 0 dirty","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:46.774923663Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1204,"":"mend"}
4742023-09-22T23:28:46.872Z{"msg":"First source client ID for extent 0","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:46.77496319Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1204,"mrl":"dirty","":"mend"}
4752023-09-22T23:28:46.875Z{"msg":"extent:0 gens: 27 27 26","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:46.775007878Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1204,"mrl":"dirty","":"mend"}
4762023-09-22T23:28:46.878Z{"msg":"extent:0 flush: 1938 1938 1937 scs: [ClientId(0), ClientId(1)]","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:46.775060575Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1204,"mrl":"dirty","":"mend"}
4772023-09-22T23:28:46.881Z{"msg":"max_flush now has: [ClientId(0), ClientId(1)]","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:46.77510272Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1204,"mrl":"dirty","":"mend"}
4782023-09-22T23:28:46.884Z{"msg":"extent:0 dirty: true true false","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:46.775124435Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1204,"mrl":"dirty","":"mend"}
4792023-09-22T23:28:46.888Z{"msg":"find dest for source 0 for extent at index 0","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:46.775173772Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1204,"mrl":"dirty","":"mend"}
4802023-09-22T23:28:46.891Z{"msg":"source 0, add dest 1 source flush","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:46.775216258Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1204,"mrl":"dirty","":"mend"}
4812023-09-22T23:28:46.894Z{"msg":"source 0, add dest 2 gen","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:46.775257112Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1204,"mrl":"dirty","":"mend"}
4822023-09-22T23:28:46.897Z{"msg":"Extents 1 dirty","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:46.775298003Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1204,"":"mend"}
4832023-09-22T23:28:46.900Z{"msg":"First source client ID for extent 1","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:46.775343647Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1204,"mrl":"dirty","":"mend"}
4842023-09-22T23:28:46.903Z{"msg":"extent:1 gens: 26 26 26","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:46.775384141Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1204,"mrl":"dirty","":"mend"}
4852023-09-22T23:28:46.906Z{"msg":"extent:1 flush: 1937 1937 1937 scs: [ClientId(0), ClientId(1), ClientId(2)]","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:46.775425249Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1204,"mrl":"dirty","":"mend"}
4862023-09-22T23:28:46.910Z{"msg":"max_flush now has: [ClientId(0), ClientId(1), ClientId(2)]","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:46.77547387Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1204,"mrl":"dirty","":"mend"}
4872023-09-22T23:28:46.913Z{"msg":"extent:1 dirty: true true false","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:46.775513635Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1204,"mrl":"dirty","":"mend"}
4882023-09-22T23:28:46.917Z{"msg":"find dest for source 0 for extent at index 1","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:46.775553842Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1204,"mrl":"dirty","":"mend"}
4892023-09-22T23:28:46.920Z{"msg":"source 0, add dest 1 source flush","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:46.775593994Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1204,"mrl":"dirty","":"mend"}
4902023-09-22T23:28:46.923Z{"msg":"source 0, add dest 2 source flush","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:46.775632979Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1204,"mrl":"dirty","":"mend"}
4912023-09-22T23:28:46.926Z{"msg":"Extents 2 dirty","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:46.775672263Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1204,"":"mend"}
4922023-09-22T23:28:46.929Z{"msg":"First source client ID for extent 2","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:46.77571139Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1204,"mrl":"dirty","":"mend"}
4932023-09-22T23:28:46.932Z{"msg":"extent:2 gens: 26 26 26","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:46.775750653Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1204,"mrl":"dirty","":"mend"}
4942023-09-22T23:28:46.935Z{"msg":"extent:2 flush: 1937 1937 1937 scs: [ClientId(0), ClientId(1), ClientId(2)]","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:46.775791004Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1204,"mrl":"dirty","":"mend"}
4952023-09-22T23:28:46.938Z{"msg":"max_flush now has: [ClientId(0), ClientId(1), ClientId(2)]","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:46.775830827Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1204,"mrl":"dirty","":"mend"}
4962023-09-22T23:28:46.942Z{"msg":"extent:2 dirty: true true false","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:46.775852003Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1204,"mrl":"dirty","":"mend"}
4972023-09-22T23:28:46.945Z{"msg":"find dest for source 0 for extent at index 2","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:46.775898808Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1204,"mrl":"dirty","":"mend"}
4982023-09-22T23:28:46.948Z{"msg":"source 0, add dest 1 source flush","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:46.775938682Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1204,"mrl":"dirty","":"mend"}
4992023-09-22T23:28:46.951Z{"msg":"source 0, add dest 2 source flush","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:46.775977851Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1204,"mrl":"dirty","":"mend"}
5002023-09-22T23:28:46.954Z{"msg":"Extent 3 has flush number mismatch","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:46.776017502Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1204,"":"mend"}
5012023-09-22T23:28:46.957Z{"msg":"First source client ID for extent 3","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:46.776055569Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1204,"mrl":"flush_mismatch","":"mend"}
5022023-09-22T23:28:46.960Z{"msg":"extent:3 gens: 27 27 26","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:46.77609485Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1204,"mrl":"flush_mismatch","":"mend"}
5032023-09-22T23:28:46.964Z{"msg":"extent:3 flush: 1938 1938 1937 scs: [ClientId(0), ClientId(1)]","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:46.776134741Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1204,"mrl":"flush_mismatch","":"mend"}
5042023-09-22T23:28:46.969Z{"msg":"max_flush now has: [ClientId(0), ClientId(1)]","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:46.776174465Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1204,"mrl":"flush_mismatch","":"mend"}
5052023-09-22T23:28:46.985Z{"msg":"extent:3 dirty: false false false","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:46.776213852Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1204,"mrl":"flush_mismatch","":"mend"}
5062023-09-22T23:28:46.991Z{"msg":"No maxes found, left with: [ClientId(0), ClientId(1)]","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:46.776253772Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1204,"mrl":"flush_mismatch","":"mend"}
5072023-09-22T23:28:46.996Z{"msg":"find dest for source 0 for extent at index 3","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:46.776293301Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1204,"mrl":"flush_mismatch","":"mend"}
5082023-09-22T23:28:47.001Z{"msg":"source 0, add dest 2 gen","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:46.776332272Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1204,"mrl":"flush_mismatch","":"mend"}
5092023-09-22T23:28:47.004Z{"msg":"Extent 4 has flush number mismatch","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:46.776371953Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1204,"":"mend"}
5102023-09-22T23:28:47.007Z{"msg":"First source client ID for extent 4","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:46.776410013Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1204,"mrl":"flush_mismatch","":"mend"}
5112023-09-22T23:28:47.010Z{"msg":"extent:4 gens: 27 27 26","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:46.776449619Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1204,"mrl":"flush_mismatch","":"mend"}
5122023-09-22T23:28:47.013Z{"msg":"extent:4 flush: 1938 1938 1937 scs: [ClientId(0), ClientId(1)]","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:46.776489876Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1204,"mrl":"flush_mismatch","":"mend"}
5132023-09-22T23:28:47.017Z{"msg":"max_flush now has: [ClientId(0), ClientId(1)]","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:46.776570181Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1204,"mrl":"flush_mismatch","":"mend"}
5142023-09-22T23:28:47.020Z{"msg":"extent:4 dirty: false false false","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:46.776612968Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1204,"mrl":"flush_mismatch","":"mend"}
5152023-09-22T23:28:47.023Z{"msg":"No maxes found, left with: [ClientId(0), ClientId(1)]","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:46.776635079Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1204,"mrl":"flush_mismatch","":"mend"}
5162023-09-22T23:28:47.026Z{"msg":"find dest for source 0 for extent at index 4","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:46.776654594Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1204,"mrl":"flush_mismatch","":"mend"}
5172023-09-22T23:28:47.029Z{"msg":"source 0, add dest 2 gen","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:46.776673948Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1204,"mrl":"flush_mismatch","":"mend"}
5182023-09-22T23:28:47.032Z{"msg":"Transition from WaitQuorum to Repair","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:46.776694332Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1204}
5192023-09-22T23:28:47.035Z{"msg":"Transition from WaitQuorum to Repair","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:46.776722888Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1204}
5202023-09-22T23:28:47.039Z{"msg":"Transition from WaitQuorum to Repair","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:46.776755153Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1204}
5212023-09-22T23:28:47.042Z{"msg":"Found 5 extents that need repair","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:46.776775785Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1204}
5222023-09-22T23:28:47.045Z{"msg":"Full repair list: {0: ExtentFix { source: ClientId(0), dest: [ClientId(1), ClientId(2)] }, 4: ExtentFix { source: ClientId(0), dest: [ClientId(2)] }, 2: ExtentFix { source: ClientId(0), dest: [ClientId(1), ClientId(2)] }, 3: ExtentFix { source: ClientId(0), dest: [ClientId(2)] }, 1: ExtentFix { source: ClientId(0), dest: [ClientId(1), ClientId(2)] }}","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:46.776803012Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1204,"":"downstairs"}
5232023-09-22T23:28:47.048Z{"msg":"Task list: [ReconcileIO { id: ReconciliationId(0), op: ExtentFlush { repair_id: ReconciliationId(0), extent_id: 0, client_id: ClientId(0), flush_number: 1939, gen_number: 28 }, state: ClientData([New, New, New]) }, ReconcileIO { id: ReconciliationId(1), op: ExtentClose { repair_id: ReconciliationId(1), extent_id: 0 }, state: ClientData([New, New, New]) }, ReconcileIO { id: ReconciliationId(2), op: ExtentRepair { repair_id: ReconciliationId(2), 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(3), op: ExtentReopen { repair_id: ReconciliationId(3), extent_id: 0 }, state: ClientData([New, New, New]) }, ReconcileIO { id: ReconciliationId(4), op: ExtentFlush { repair_id: ReconciliationId(4), extent_id: 4, client_id: ClientId(0), flush_number: 1939, gen_number: 28 }, 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: 2, client_id: ClientId(0), flush_number: 1939, gen_number: 28 }, state: ClientData([New, New, New]) }, ReconcileIO { id: ReconciliationId(9), op: ExtentClose { repair_id: ReconciliationId(9), extent_id: 2 }, state: ClientData([New, New, New]) }, ReconcileIO { id: ReconciliationId(10), op: ExtentRepair { repair_id: ReconciliationId(10), extent_id: 2, 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(11), op: ExtentReopen { repair_id: ReconciliationId(11), extent_id: 2 }, state: ClientData([New, New, New]) }, ReconcileIO { id: ReconciliationId(12), op: ExtentFlush { repair_id: ReconciliationId(12), extent_id: 3, client_id: ClientId(0), flush_number: 1939, gen_number: 28 }, state: ClientData([New, New, New]) }, ReconcileIO { id: ReconciliationId(13), op: ExtentClose { repair_id: ReconciliationId(13), extent_id: 3 }, state: ClientData([New, New, New]) }, ReconcileIO { id: ReconciliationId(14), op: ExtentRepair { repair_id: ReconciliationId(14), 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(15), op: ExtentReopen { repair_id: ReconciliationId(15), extent_id: 3 }, state: ClientData([New, New, New]) }, ReconcileIO { id: ReconciliationId(16), op: ExtentFlush { repair_id: ReconciliationId(16), extent_id: 1, client_id: ClientId(0), flush_number: 1939, gen_number: 28 }, state: ClientData([New, New, New]) }, ReconcileIO { id: ReconciliationId(17), op: ExtentClose { repair_id: ReconciliationId(17), extent_id: 1 }, state: ClientData([New, New, New]) }, ReconcileIO { id: ReconciliationId(18), op: ExtentRepair { repair_id: ReconciliationId(18), extent_id: 1, 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(19), op: ExtentReopen { repair_id: ReconciliationId(19), extent_id: 1 }, state: ClientData([New, New, New]) }]","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:46.77693649Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1204,"":"downstairs"}
5242023-09-22T23:28:47.052Z{"msg":"Begin repair with 20 commands","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:46.776960572Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1204}
5252023-09-22T23:28:47.055Z{"msg":"Pop front: ReconcileIO { id: ReconciliationId(0), op: ExtentFlush { repair_id: ReconciliationId(0), extent_id: 0, client_id: ClientId(0), flush_number: 1939, gen_number: 28 }, state: ClientData([New, New, New]) }","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:46.776983754Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1204}
5262023-09-22T23:28:47.058Z{"msg":"Sent repair work, now wait for resp","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:46.777001654Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1204}
5272023-09-22T23:28:47.061Z{"msg":"[2] received reconcile message","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:46.777018976Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1204}
5282023-09-22T23:28:47.065Z{"msg":"[2] rep_in_progress: return ReconcileIO { id: ReconciliationId(0), op: ExtentFlush { repair_id: ReconciliationId(0), extent_id: 0, client_id: ClientId(0), flush_number: 1939, gen_number: 28 }, state: ClientData([New, New, InProgress]) }","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:46.777041606Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1204,"":"downstairs"}
5292023-09-22T23:28:47.068Z{"msg":"[2] client ExtentFlush { repair_id: ReconciliationId(0), extent_id: 0, client_id: ClientId(0), flush_number: 1939, gen_number: 28 }","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:46.777063281Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1204}
5302023-09-22T23:28:47.071Z{"msg":"[0] received reconcile message","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:46.777080994Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1204}
5312023-09-22T23:28:47.074Z{"msg":"[0] rep_in_progress: return ReconcileIO { id: ReconciliationId(0), op: ExtentFlush { repair_id: ReconciliationId(0), extent_id: 0, client_id: ClientId(0), flush_number: 1939, gen_number: 28 }, state: ClientData([InProgress, New, Done]) }","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:46.777103708Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1204,"":"downstairs"}
5322023-09-22T23:28:47.080Z{"msg":"[0] client ExtentFlush { repair_id: ReconciliationId(0), extent_id: 0, client_id: ClientId(0), flush_number: 1939, gen_number: 28 }","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:46.777124964Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1204}
5332023-09-22T23:28:47.083Z{"msg":"[1] received reconcile message","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:46.777142381Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1204}
5342023-09-22T23:28:47.086Z{"msg":"[1] rep_in_progress: return ReconcileIO { id: ReconciliationId(0), op: ExtentFlush { repair_id: ReconciliationId(0), extent_id: 0, client_id: ClientId(0), flush_number: 1939, gen_number: 28 }, state: ClientData([InProgress, InProgress, Done]) }","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:46.77716514Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1204,"":"downstairs"}
5352023-09-22T23:28:47.089Z{"msg":"[1] client ExtentFlush { repair_id: ReconciliationId(0), extent_id: 0, client_id: ClientId(0), flush_number: 1939, gen_number: 28 }","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:46.777186703Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1204}
5362023-09-22T23:28:47.093Z{"msg":"Completion from [0] id:0 status:true","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:46.778196384Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1204}
5372023-09-22T23:28:47.096Z{"msg":"[1/20] Repair commands completed","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:46.778227108Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1204}
5382023-09-22T23:28:47.099Z{"msg":"Pop front: ReconcileIO { id: ReconciliationId(1), op: ExtentClose { repair_id: ReconciliationId(1), extent_id: 0 }, state: ClientData([New, New, New]) }","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:46.778249144Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1204}
5392023-09-22T23:28:47.102Z{"msg":"Sent repair work, now wait for resp","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:46.778267306Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1204}
5402023-09-22T23:28:47.105Z{"msg":"[2] received reconcile message","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:46.778284839Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1204}
5412023-09-22T23:28:47.108Z{"msg":"[2] rep_in_progress: return ReconcileIO { id: ReconciliationId(1), op: ExtentClose { repair_id: ReconciliationId(1), extent_id: 0 }, state: ClientData([New, New, InProgress]) }","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:46.778306103Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1204,"":"downstairs"}
5422023-09-22T23:28:47.111Z{"msg":"[2] client ExtentClose { repair_id: ReconciliationId(1), extent_id: 0 }","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:46.778326408Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1204}
5432023-09-22T23:28:47.114Z{"msg":"[0] received reconcile message","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:46.778352642Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1204}
5442023-09-22T23:28:47.116Z{"msg":"[0] rep_in_progress: return ReconcileIO { id: ReconciliationId(1), op: ExtentClose { repair_id: ReconciliationId(1), extent_id: 0 }, state: ClientData([InProgress, New, InProgress]) }","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:46.778394554Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1204,"":"downstairs"}
5452023-09-22T23:28:47.120Z{"msg":"[0] client ExtentClose { repair_id: ReconciliationId(1), extent_id: 0 }","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:46.778436743Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1204}
5462023-09-22T23:28:47.123Z{"msg":"[1] received reconcile message","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:46.778473761Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1204}
5472023-09-22T23:28:47.126Z{"msg":"[1] rep_in_progress: return ReconcileIO { id: ReconciliationId(1), op: ExtentClose { repair_id: ReconciliationId(1), extent_id: 0 }, state: ClientData([InProgress, InProgress, InProgress]) }","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:46.778512825Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1204,"":"downstairs"}
5482023-09-22T23:28:47.128Z{"msg":"[1] client ExtentClose { repair_id: ReconciliationId(1), extent_id: 0 }","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:46.778555231Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1204}
5492023-09-22T23:28:47.131Z{"msg":"Completion from [1] id:1 status:true","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:46.781073694Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1204}
5502023-09-22T23:28:47.134Z{"msg":"[2/20] Repair commands completed","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:46.781106588Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1204}
5512023-09-22T23:28:47.137Z{"msg":"Pop front: ReconcileIO { id: ReconciliationId(2), op: ExtentRepair { repair_id: ReconciliationId(2), 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]) }","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:46.781131738Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1204}
5522023-09-22T23:28:47.141Z{"msg":"Sent repair work, now wait for resp","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:46.781149927Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1204}
5532023-09-22T23:28:47.165Z{"msg":"[2] received reconcile message","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:46.781167552Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1204}
5542023-09-22T23:28:47.168Z{"msg":"[2] rep_in_progress: return ReconcileIO { id: ReconciliationId(2), op: ExtentRepair { repair_id: ReconciliationId(2), 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, InProgress]) }","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:46.781191408Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1204,"":"downstairs"}
5552023-09-22T23:28:47.172Z{"msg":"[2] client ExtentRepair { repair_id: ReconciliationId(2), extent_id: 0, source_client_id: ClientId(0), source_repair_address: 0.0.0.0:12810, dest_clients: [ClientId(1), ClientId(2)] }","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:46.781214487Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1204}
5562023-09-22T23:28:47.175Z{"msg":"[2] Sending repair request ReconciliationId(2)","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:46.781232455Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1204}
5572023-09-22T23:28:47.178Z{"msg":"[0] received reconcile message","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:46.781249697Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1204}
5582023-09-22T23:28:47.181Z{"msg":"[0] rep_in_progress: return ReconcileIO { id: ReconciliationId(2), op: ExtentRepair { repair_id: ReconciliationId(2), extent_id: 0, source_client_id: ClientId(0), source_repair_address: 0.0.0.0:12810, dest_clients: [ClientId(1), ClientId(2)] }, state: ClientData([InProgress, New, InProgress]) }","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:46.781273824Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1204,"":"downstairs"}
5592023-09-22T23:28:47.184Z{"msg":"[0] client ExtentRepair { repair_id: ReconciliationId(2), extent_id: 0, source_client_id: ClientId(0), source_repair_address: 0.0.0.0:12810, dest_clients: [ClientId(1), ClientId(2)] }","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:46.781296645Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1204}
5602023-09-22T23:28:47.187Z{"msg":"[0] No action required ReconciliationId(2)","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:46.781314318Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1204}
5612023-09-22T23:28:47.192Z{"msg":"[1] received reconcile message","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:46.781331467Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1204}
5622023-09-22T23:28:47.195Z{"msg":"[1] rep_in_progress: return ReconcileIO { id: ReconciliationId(2), op: ExtentRepair { repair_id: ReconciliationId(2), extent_id: 0, source_client_id: ClientId(0), source_repair_address: 0.0.0.0:12810, dest_clients: [ClientId(1), ClientId(2)] }, state: ClientData([Done, InProgress, InProgress]) }","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:46.781355183Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1204,"":"downstairs"}
5632023-09-22T23:28:47.199Z{"msg":"[1] client ExtentRepair { repair_id: ReconciliationId(2), extent_id: 0, source_client_id: ClientId(0), source_repair_address: 0.0.0.0:12810, dest_clients: [ClientId(1), ClientId(2)] }","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:46.781377207Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1204}
5642023-09-22T23:28:47.202Z{"msg":"[1] Sending repair request ReconciliationId(2)","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:46.781394747Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1204}
5652023-09-22T23:28:47.204Z{"msg":"Completion from [2] id:2 status:true","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:46.901991961Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1204}
5662023-09-22T23:28:47.208Z{"msg":"[3/20] Repair commands completed","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:46.902048207Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1204}
5672023-09-22T23:28:47.211Z{"msg":"Pop front: ReconcileIO { id: ReconciliationId(3), op: ExtentReopen { repair_id: ReconciliationId(3), extent_id: 0 }, state: ClientData([New, New, New]) }","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:46.90207147Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1204}
5682023-09-22T23:28:47.214Z{"msg":"Sent repair work, now wait for resp","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:46.90209098Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1204}
5692023-09-22T23:28:47.217Z{"msg":"[2] received reconcile message","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:46.902108961Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1204}
5702023-09-22T23:28:47.220Z{"msg":"[2] rep_in_progress: return ReconcileIO { id: ReconciliationId(3), op: ExtentReopen { repair_id: ReconciliationId(3), extent_id: 0 }, state: ClientData([New, New, InProgress]) }","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:46.902131058Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1204,"":"downstairs"}
5712023-09-22T23:28:47.223Z{"msg":"[2] client ExtentReopen { repair_id: ReconciliationId(3), extent_id: 0 }","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:46.902152301Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1204}
5722023-09-22T23:28:47.226Z{"msg":"[0] received reconcile message","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:46.902170202Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1204}
5732023-09-22T23:28:47.229Z{"msg":"[0] rep_in_progress: return ReconcileIO { id: ReconciliationId(3), op: ExtentReopen { repair_id: ReconciliationId(3), extent_id: 0 }, state: ClientData([InProgress, New, InProgress]) }","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:46.902202903Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1204,"":"downstairs"}
5742023-09-22T23:28:47.232Z{"msg":"[0] client ExtentReopen { repair_id: ReconciliationId(3), extent_id: 0 }","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:46.902241723Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1204}
5752023-09-22T23:28:47.235Z{"msg":"[1] received reconcile message","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:46.902279709Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1204}
5762023-09-22T23:28:47.238Z{"msg":"[1] rep_in_progress: return ReconcileIO { id: ReconciliationId(3), op: ExtentReopen { repair_id: ReconciliationId(3), extent_id: 0 }, state: ClientData([InProgress, InProgress, InProgress]) }","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:46.902324077Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1204,"":"downstairs"}
5772023-09-22T23:28:47.241Z{"msg":"[1] client ExtentReopen { repair_id: ReconciliationId(3), extent_id: 0 }","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:46.902363196Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1204}
5782023-09-22T23:28:47.244Z{"msg":"Completion from [1] id:3 status:true","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:46.90343966Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1204}
5792023-09-22T23:28:47.247Z{"msg":"[4/20] Repair commands completed","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:46.903476033Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1204}
5802023-09-22T23:28:47.250Z{"msg":"Pop front: ReconcileIO { id: ReconciliationId(4), op: ExtentFlush { repair_id: ReconciliationId(4), extent_id: 4, client_id: ClientId(0), flush_number: 1939, gen_number: 28 }, state: ClientData([New, New, New]) }","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:46.903501105Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1204}
5812023-09-22T23:28:47.254Z{"msg":"Sent repair work, now wait for resp","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:46.903519556Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1204}
5822023-09-22T23:28:47.256Z{"msg":"[2] received reconcile message","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:46.90354487Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1204}
5832023-09-22T23:28:47.259Z{"msg":"[2] rep_in_progress: return ReconcileIO { id: ReconciliationId(4), op: ExtentFlush { repair_id: ReconciliationId(4), extent_id: 4, client_id: ClientId(0), flush_number: 1939, gen_number: 28 }, state: ClientData([New, New, InProgress]) }","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:46.903568798Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1204,"":"downstairs"}
5842023-09-22T23:28:47.263Z{"msg":"[2] client ExtentFlush { repair_id: ReconciliationId(4), extent_id: 4, client_id: ClientId(0), flush_number: 1939, gen_number: 28 }","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:46.903591156Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1204}
5852023-09-22T23:28:47.266Z{"msg":"[0] received reconcile message","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:46.903609785Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1204}
5862023-09-22T23:28:47.269Z{"msg":"[0] rep_in_progress: return ReconcileIO { id: ReconciliationId(4), op: ExtentFlush { repair_id: ReconciliationId(4), extent_id: 4, client_id: ClientId(0), flush_number: 1939, gen_number: 28 }, state: ClientData([InProgress, New, Done]) }","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:46.903632842Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1204,"":"downstairs"}
5872023-09-22T23:28:47.272Z{"msg":"[1] received reconcile message","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:46.903651831Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1204}
5882023-09-22T23:28:47.275Z{"msg":"[0] client ExtentFlush { repair_id: ReconciliationId(4), extent_id: 4, client_id: ClientId(0), flush_number: 1939, gen_number: 28 }","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:46.903672213Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1204}
5892023-09-22T23:28:47.278Z{"msg":"[1] rep_in_progress: return ReconcileIO { id: ReconciliationId(4), op: ExtentFlush { repair_id: ReconciliationId(4), extent_id: 4, client_id: ClientId(0), flush_number: 1939, gen_number: 28 }, state: ClientData([InProgress, InProgress, Done]) }","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:46.903695543Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1204,"":"downstairs"}
5902023-09-22T23:28:47.281Z{"msg":"[1] client ExtentFlush { repair_id: ReconciliationId(4), extent_id: 4, client_id: ClientId(0), flush_number: 1939, gen_number: 28 }","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:46.903717087Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1204}
5912023-09-22T23:28:47.292Z{"msg":"Completion from [0] id:4 status:true","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:46.903981173Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1204}
5922023-09-22T23:28:47.327Z{"msg":"[5/20] Repair commands completed","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:46.904007368Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1204}
5932023-09-22T23:28:47.453Z{"msg":"Pop front: ReconcileIO { id: ReconciliationId(5), op: ExtentClose { repair_id: ReconciliationId(5), extent_id: 4 }, state: ClientData([New, New, New]) }","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:46.904029333Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1204}
5942023-09-22T23:28:47.457Z{"msg":"Sent repair work, now wait for resp","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:46.904052164Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1204}
5952023-09-22T23:28:47.463Z{"msg":"[2] received reconcile message","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:46.904076329Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1204}
5962023-09-22T23:28:47.465Z{"msg":"[2] rep_in_progress: return ReconcileIO { id: ReconciliationId(5), op: ExtentClose { repair_id: ReconciliationId(5), extent_id: 4 }, state: ClientData([New, New, InProgress]) }","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:46.904098783Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1204,"":"downstairs"}
5972023-09-22T23:28:47.472Z{"msg":"[2] client ExtentClose { repair_id: ReconciliationId(5), extent_id: 4 }","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:46.904119382Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1204}
5982023-09-22T23:28:47.481Z{"msg":"[0] received reconcile message","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:46.904137373Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1204}
5992023-09-22T23:28:47.484Z{"msg":"[0] rep_in_progress: return ReconcileIO { id: ReconciliationId(5), op: ExtentClose { repair_id: ReconciliationId(5), extent_id: 4 }, state: ClientData([InProgress, New, InProgress]) }","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:46.904164288Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1204,"":"downstairs"}
6002023-09-22T23:28:47.490Z{"msg":"[0] client ExtentClose { repair_id: ReconciliationId(5), extent_id: 4 }","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:46.904200469Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1204}
6012023-09-22T23:28:47.496Z{"msg":"[1] received reconcile message","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:46.9042362Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1204}
6022023-09-22T23:28:47.500Z{"msg":"[1] rep_in_progress: return ReconcileIO { id: ReconciliationId(5), op: ExtentClose { repair_id: ReconciliationId(5), extent_id: 4 }, state: ClientData([InProgress, InProgress, InProgress]) }","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:46.904279796Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1204,"":"downstairs"}
6032023-09-22T23:28:47.504Z{"msg":"[1] client ExtentClose { repair_id: ReconciliationId(5), extent_id: 4 }","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:46.904321442Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1204}
6042023-09-22T23:28:47.510Z{"msg":"Completion from [1] id:5 status:true","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:46.906735855Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1204}
6052023-09-22T23:28:47.521Z{"msg":"[6/20] Repair commands completed","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:46.906771194Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1204}
6062023-09-22T23:28:47.526Z{"msg":"Pop front: 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]) }","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:46.906796817Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1204}
6072023-09-22T23:28:47.532Z{"msg":"Sent repair work, now wait for resp","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:46.906815653Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1204}
6082023-09-22T23:28:47.537Z{"msg":"[2] received reconcile message","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:46.906833311Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1204}
6092023-09-22T23:28:47.955Z{"msg":"[2] rep_in_progress: return 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, InProgress]) }","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:46.906856969Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1204,"":"downstairs"}
6102023-09-22T23:28:47.964Z{"msg":"[2] client 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)] }","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:46.906880188Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1204}
6112023-09-22T23:28:47.978Z{"msg":"[2] Sending repair request ReconciliationId(6)","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:46.90689858Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1204}
6122023-09-22T23:28:47.990Z{"msg":"[0] received reconcile message","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:46.906916552Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1204}
6132023-09-22T23:28:47.994Z{"msg":"[0] rep_in_progress: return 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([InProgress, New, InProgress]) }","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:46.906940447Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1204,"":"downstairs"}
6142023-09-22T23:28:47.997Z{"msg":"[0] client 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)] }","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:46.906962533Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1204}
6152023-09-22T23:28:48.001Z{"msg":"[0] No action required ReconciliationId(6)","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:46.90698049Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1204}
6162023-09-22T23:28:48.005Z{"msg":"[1] received reconcile message","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:46.906998034Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1204}
6172023-09-22T23:28:48.009Z{"msg":"[1] rep_in_progress: return 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([Done, InProgress, InProgress]) }","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:46.907021854Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1204,"":"downstairs"}
6182023-09-22T23:28:48.013Z{"msg":"[1] client 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)] }","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:46.9070437Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1204}
6192023-09-22T23:28:48.017Z{"msg":"[1] No action required ReconciliationId(6)","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:46.907061751Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1204}
6202023-09-22T23:28:48.020Z{"msg":"Completion from [2] id:6 status:true","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:46.983911414Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1204}
6212023-09-22T23:28:48.023Z{"msg":"[7/20] Repair commands completed","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:46.983967243Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1204}
6222023-09-22T23:28:48.026Z{"msg":"Pop front: ReconcileIO { id: ReconciliationId(7), op: ExtentReopen { repair_id: ReconciliationId(7), extent_id: 4 }, state: ClientData([New, New, New]) }","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:46.98399058Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1204}
6232023-09-22T23:28:48.029Z{"msg":"Sent repair work, now wait for resp","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:46.984009752Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1204}
6242023-09-22T23:28:48.033Z{"msg":"[2] received reconcile message","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:46.984027714Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1204}
6252023-09-22T23:28:48.038Z{"msg":"[2] rep_in_progress: return ReconcileIO { id: ReconciliationId(7), op: ExtentReopen { repair_id: ReconciliationId(7), extent_id: 4 }, state: ClientData([New, New, InProgress]) }","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:46.984049591Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1204,"":"downstairs"}
6262023-09-22T23:28:48.043Z{"msg":"[2] client ExtentReopen { repair_id: ReconciliationId(7), extent_id: 4 }","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:46.98407066Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1204}
6272023-09-22T23:28:48.048Z{"msg":"[0] received reconcile message","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:46.984088488Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1204}
6282023-09-22T23:28:48.052Z{"msg":"[0] rep_in_progress: return ReconcileIO { id: ReconciliationId(7), op: ExtentReopen { repair_id: ReconciliationId(7), extent_id: 4 }, state: ClientData([InProgress, New, InProgress]) }","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:46.984109953Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1204,"":"downstairs"}
6292023-09-22T23:28:48.057Z{"msg":"[0] client ExtentReopen { repair_id: ReconciliationId(7), extent_id: 4 }","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:46.984129835Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1204}
6302023-09-22T23:28:48.061Z{"msg":"[1] received reconcile message","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:46.984147358Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1204}
6312023-09-22T23:28:48.065Z{"msg":"[1] rep_in_progress: return ReconcileIO { id: ReconciliationId(7), op: ExtentReopen { repair_id: ReconciliationId(7), extent_id: 4 }, state: ClientData([InProgress, InProgress, InProgress]) }","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:46.984169149Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1204,"":"downstairs"}
6322023-09-22T23:28:48.069Z{"msg":"[1] client ExtentReopen { repair_id: ReconciliationId(7), extent_id: 4 }","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:46.984189001Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1204}
6332023-09-22T23:28:48.073Z{"msg":"Completion from [0] id:7 status:true","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:46.985167808Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1204}
6342023-09-22T23:28:48.076Z{"msg":"[8/20] Repair commands completed","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:46.985204594Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1204}
6352023-09-22T23:28:48.081Z{"msg":"Pop front: ReconcileIO { id: ReconciliationId(8), op: ExtentFlush { repair_id: ReconciliationId(8), extent_id: 2, client_id: ClientId(0), flush_number: 1939, gen_number: 28 }, state: ClientData([New, New, New]) }","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:46.985241139Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1204}
6362023-09-22T23:28:48.086Z{"msg":"Sent repair work, now wait for resp","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:46.98527802Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1204}
6372023-09-22T23:28:48.090Z{"msg":"[2] received reconcile message","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:46.985312028Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1204}
6382023-09-22T23:28:48.094Z{"msg":"[2] rep_in_progress: return ReconcileIO { id: ReconciliationId(8), op: ExtentFlush { repair_id: ReconciliationId(8), extent_id: 2, client_id: ClientId(0), flush_number: 1939, gen_number: 28 }, state: ClientData([New, New, InProgress]) }","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:46.985355612Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1204,"":"downstairs"}
6392023-09-22T23:28:48.098Z{"msg":"[2] client ExtentFlush { repair_id: ReconciliationId(8), extent_id: 2, client_id: ClientId(0), flush_number: 1939, gen_number: 28 }","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:46.985399615Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1204}
6402023-09-22T23:28:48.102Z{"msg":"[1] received reconcile message","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:46.985437676Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1204}
6412023-09-22T23:28:48.106Z{"msg":"[1] rep_in_progress: return ReconcileIO { id: ReconciliationId(8), op: ExtentFlush { repair_id: ReconciliationId(8), extent_id: 2, client_id: ClientId(0), flush_number: 1939, gen_number: 28 }, state: ClientData([New, InProgress, Done]) }","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:46.985471659Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1204,"":"downstairs"}
6422023-09-22T23:28:48.110Z{"msg":"[1] client ExtentFlush { repair_id: ReconciliationId(8), extent_id: 2, client_id: ClientId(0), flush_number: 1939, gen_number: 28 }","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:46.985494375Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1204}
6432023-09-22T23:28:48.114Z{"msg":"[0] received reconcile message","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:46.98551223Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1204}
6442023-09-22T23:28:48.118Z{"msg":"[0] rep_in_progress: return ReconcileIO { id: ReconciliationId(8), op: ExtentFlush { repair_id: ReconciliationId(8), extent_id: 2, client_id: ClientId(0), flush_number: 1939, gen_number: 28 }, state: ClientData([InProgress, Done, Done]) }","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:46.985535309Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1204,"":"downstairs"}
6452023-09-22T23:28:48.122Z{"msg":"[0] client ExtentFlush { repair_id: ReconciliationId(8), extent_id: 2, client_id: ClientId(0), flush_number: 1939, gen_number: 28 }","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:46.985556435Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1204}
6462023-09-22T23:28:48.127Z{"msg":"Completion from [0] id:8 status:true","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:46.987485639Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1204}
6472023-09-22T23:28:48.132Z{"msg":"[9/20] Repair commands completed","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:46.987522354Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1204}
6482023-09-22T23:28:48.138Z{"msg":"Pop front: ReconcileIO { id: ReconciliationId(9), op: ExtentClose { repair_id: ReconciliationId(9), extent_id: 2 }, state: ClientData([New, New, New]) }","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:46.987545659Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1204}
6492023-09-22T23:28:48.141Z{"msg":"Sent repair work, now wait for resp","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:46.987564485Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1204}
6502023-09-22T23:28:48.145Z{"msg":"[2] received reconcile message","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:46.987582359Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1204}
6512023-09-22T23:28:48.149Z{"msg":"[2] rep_in_progress: return ReconcileIO { id: ReconciliationId(9), op: ExtentClose { repair_id: ReconciliationId(9), extent_id: 2 }, state: ClientData([New, New, InProgress]) }","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:46.987603834Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1204,"":"downstairs"}
6522023-09-22T23:28:48.154Z{"msg":"[2] client ExtentClose { repair_id: ReconciliationId(9), extent_id: 2 }","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:46.987624237Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1204}
6532023-09-22T23:28:48.158Z{"msg":"[0] received reconcile message","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:46.987642091Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1204}
6542023-09-22T23:28:48.162Z{"msg":"[0] rep_in_progress: return ReconcileIO { id: ReconciliationId(9), op: ExtentClose { repair_id: ReconciliationId(9), extent_id: 2 }, state: ClientData([InProgress, New, InProgress]) }","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:46.987663677Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1204,"":"downstairs"}
6552023-09-22T23:28:48.188Z{"msg":"[0] client ExtentClose { repair_id: ReconciliationId(9), extent_id: 2 }","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:46.987683595Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1204}
6562023-09-22T23:28:48.193Z{"msg":"[1] received reconcile message","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:46.987701075Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1204}
6572023-09-22T23:28:48.197Z{"msg":"[1] rep_in_progress: return ReconcileIO { id: ReconciliationId(9), op: ExtentClose { repair_id: ReconciliationId(9), extent_id: 2 }, state: ClientData([InProgress, InProgress, InProgress]) }","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:46.987722487Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1204,"":"downstairs"}
6582023-09-22T23:28:48.201Z{"msg":"[1] client ExtentClose { repair_id: ReconciliationId(9), extent_id: 2 }","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:46.98774239Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1204}
6592023-09-22T23:28:48.205Z{"msg":"Completion from [1] id:9 status:true","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:46.990314203Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1204}
6602023-09-22T23:28:48.212Z{"msg":"[10/20] Repair commands completed","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:47.073042072Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1204}
6612023-09-22T23:28:48.216Z{"msg":"Pop front: ReconcileIO { id: ReconciliationId(10), op: ExtentRepair { repair_id: ReconciliationId(10), extent_id: 2, source_client_id: ClientId(0), source_repair_address: 0.0.0.0:12810, dest_clients: [ClientId(1), ClientId(2)] }, state: ClientData([New, New, New]) }","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:47.073123372Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1204}
6622023-09-22T23:28:48.220Z{"msg":"Sent repair work, now wait for resp","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:47.073163874Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1204}
6632023-09-22T23:28:48.225Z{"msg":"[2] received reconcile message","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:47.073201441Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1204}
6642023-09-22T23:28:48.229Z{"msg":"[2] rep_in_progress: return ReconcileIO { id: ReconciliationId(10), op: ExtentRepair { repair_id: ReconciliationId(10), extent_id: 2, source_client_id: ClientId(0), source_repair_address: 0.0.0.0:12810, dest_clients: [ClientId(1), ClientId(2)] }, state: ClientData([New, New, InProgress]) }","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:47.07324803Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1204,"":"downstairs"}
6652023-09-22T23:28:48.233Z{"msg":"[2] client ExtentRepair { repair_id: ReconciliationId(10), extent_id: 2, source_client_id: ClientId(0), source_repair_address: 0.0.0.0:12810, dest_clients: [ClientId(1), ClientId(2)] }","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:47.073295618Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1204}
6662023-09-22T23:28:48.237Z{"msg":"[2] Sending repair request ReconciliationId(10)","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:47.073335008Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1204}
6672023-09-22T23:28:48.241Z{"msg":"[0] received reconcile message","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:47.073371642Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1204}
6682023-09-22T23:28:48.245Z{"msg":"[0] rep_in_progress: return ReconcileIO { id: ReconciliationId(10), op: ExtentRepair { repair_id: ReconciliationId(10), extent_id: 2, source_client_id: ClientId(0), source_repair_address: 0.0.0.0:12810, dest_clients: [ClientId(1), ClientId(2)] }, state: ClientData([InProgress, New, InProgress]) }","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:47.07341265Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1204,"":"downstairs"}
6692023-09-22T23:28:48.249Z{"msg":"[0] client ExtentRepair { repair_id: ReconciliationId(10), extent_id: 2, source_client_id: ClientId(0), source_repair_address: 0.0.0.0:12810, dest_clients: [ClientId(1), ClientId(2)] }","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:47.073439228Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1204}
6702023-09-22T23:28:48.253Z{"msg":"[0] No action required ReconciliationId(10)","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:47.073457443Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1204}
6712023-09-22T23:28:48.257Z{"msg":"[1] received reconcile message","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:47.073474916Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1204}
6722023-09-22T23:28:48.261Z{"msg":"[1] rep_in_progress: return ReconcileIO { id: ReconciliationId(10), op: ExtentRepair { repair_id: ReconciliationId(10), extent_id: 2, source_client_id: ClientId(0), source_repair_address: 0.0.0.0:12810, dest_clients: [ClientId(1), ClientId(2)] }, state: ClientData([Done, InProgress, InProgress]) }","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:47.073499163Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1204,"":"downstairs"}
6732023-09-22T23:28:48.266Z{"msg":"[1] client ExtentRepair { repair_id: ReconciliationId(10), extent_id: 2, source_client_id: ClientId(0), source_repair_address: 0.0.0.0:12810, dest_clients: [ClientId(1), ClientId(2)] }","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:47.073522263Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1204}
6742023-09-22T23:28:48.270Z{"msg":"[1] Sending repair request ReconciliationId(10)","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:47.073540555Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1204}
6752023-09-22T23:28:48.274Z{"msg":"Completion from [1] id:10 status:true","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:47.073558173Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1204}
6762023-09-22T23:28:48.278Z{"msg":"[11/20] Repair commands completed","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:47.07357553Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1204}
6772023-09-22T23:28:48.283Z{"msg":"Pop front: ReconcileIO { id: ReconciliationId(11), op: ExtentReopen { repair_id: ReconciliationId(11), extent_id: 2 }, state: ClientData([New, New, New]) }","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:47.073606814Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1204}
6782023-09-22T23:28:48.288Z{"msg":"Sent repair work, now wait for resp","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:47.0736429Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1204}
6792023-09-22T23:28:48.292Z{"msg":"[2] received reconcile message","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:47.073680522Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1204}
6802023-09-22T23:28:48.296Z{"msg":"[2] rep_in_progress: return ReconcileIO { id: ReconciliationId(11), op: ExtentReopen { repair_id: ReconciliationId(11), extent_id: 2 }, state: ClientData([New, New, InProgress]) }","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:47.073722957Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1204,"":"downstairs"}
6812023-09-22T23:28:48.300Z{"msg":"[2] client ExtentReopen { repair_id: ReconciliationId(11), extent_id: 2 }","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:47.073763742Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1204}
6822023-09-22T23:28:48.305Z{"msg":"[0] received reconcile message","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:47.073800507Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1204}
6832023-09-22T23:28:48.309Z{"msg":"[0] rep_in_progress: return ReconcileIO { id: ReconciliationId(11), op: ExtentReopen { repair_id: ReconciliationId(11), extent_id: 2 }, state: ClientData([InProgress, New, InProgress]) }","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:47.073842574Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1204,"":"downstairs"}
6842023-09-22T23:28:48.313Z{"msg":"[0] client ExtentReopen { repair_id: ReconciliationId(11), extent_id: 2 }","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:47.07388401Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1204}
6852023-09-22T23:28:48.317Z{"msg":"[1] received reconcile message","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:47.073917939Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1204}
6862023-09-22T23:28:48.321Z{"msg":"[1] rep_in_progress: return ReconcileIO { id: ReconciliationId(11), op: ExtentReopen { repair_id: ReconciliationId(11), extent_id: 2 }, state: ClientData([InProgress, InProgress, InProgress]) }","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:47.073957738Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1204,"":"downstairs"}
6872023-09-22T23:28:48.325Z{"msg":"[1] client ExtentReopen { repair_id: ReconciliationId(11), extent_id: 2 }","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:47.073993213Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1204}
6882023-09-22T23:28:48.329Z{"msg":"Completion from [1] id:11 status:true","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:47.074013083Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1204}
6892023-09-22T23:28:48.334Z{"msg":"[12/20] Repair commands completed","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:47.074030683Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1204}
6902023-09-22T23:28:48.338Z{"msg":"Pop front: ReconcileIO { id: ReconciliationId(12), op: ExtentFlush { repair_id: ReconciliationId(12), extent_id: 3, client_id: ClientId(0), flush_number: 1939, gen_number: 28 }, state: ClientData([New, New, New]) }","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:47.074052858Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1204}
6912023-09-22T23:28:48.342Z{"msg":"Sent repair work, now wait for resp","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:47.07407034Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1204}
6922023-09-22T23:28:48.346Z{"msg":"[2] received reconcile message","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:47.192555466Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1204}
6932023-09-22T23:28:48.350Z{"msg":"[2] rep_in_progress: return ReconcileIO { id: ReconciliationId(12), op: ExtentFlush { repair_id: ReconciliationId(12), extent_id: 3, client_id: ClientId(0), flush_number: 1939, gen_number: 28 }, state: ClientData([New, New, InProgress]) }","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:47.192613981Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1204,"":"downstairs"}
6942023-09-22T23:28:48.355Z{"msg":"[2] client ExtentFlush { repair_id: ReconciliationId(12), extent_id: 3, client_id: ClientId(0), flush_number: 1939, gen_number: 28 }","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:47.192638726Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1204}
6952023-09-22T23:28:48.359Z{"msg":"[0] received reconcile message","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:47.192657576Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1204}
6962023-09-22T23:28:48.363Z{"msg":"[0] rep_in_progress: return ReconcileIO { id: ReconciliationId(12), op: ExtentFlush { repair_id: ReconciliationId(12), extent_id: 3, client_id: ClientId(0), flush_number: 1939, gen_number: 28 }, state: ClientData([InProgress, New, Done]) }","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:47.192680907Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1204,"":"downstairs"}
6972023-09-22T23:28:48.367Z{"msg":"[0] client ExtentFlush { repair_id: ReconciliationId(12), extent_id: 3, client_id: ClientId(0), flush_number: 1939, gen_number: 28 }","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:47.192702638Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1204}
6982023-09-22T23:28:48.370Z{"msg":"[1] received reconcile message","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:47.192720749Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1204}
6992023-09-22T23:28:48.374Z{"msg":"[1] rep_in_progress: return ReconcileIO { id: ReconciliationId(12), op: ExtentFlush { repair_id: ReconciliationId(12), extent_id: 3, client_id: ClientId(0), flush_number: 1939, gen_number: 28 }, state: ClientData([InProgress, InProgress, Done]) }","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:47.192744396Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1204,"":"downstairs"}
7002023-09-22T23:28:48.378Z{"msg":"[1] client ExtentFlush { repair_id: ReconciliationId(12), extent_id: 3, client_id: ClientId(0), flush_number: 1939, gen_number: 28 }","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:47.192765622Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1204}
7012023-09-22T23:28:48.383Z{"msg":"Completion from [0] id:12 status:true","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:47.192783366Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1204}
7022023-09-22T23:28:48.388Z{"msg":"[13/20] Repair commands completed","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:47.192801014Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1204}
7032023-09-22T23:28:48.392Z{"msg":"Pop front: ReconcileIO { id: ReconciliationId(13), op: ExtentClose { repair_id: ReconciliationId(13), extent_id: 3 }, state: ClientData([New, New, New]) }","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:47.192821582Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1204}
7042023-09-22T23:28:48.396Z{"msg":"Sent repair work, now wait for resp","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:47.192839272Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1204}
7052023-09-22T23:28:48.399Z{"msg":"[2] received reconcile message","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:47.192856343Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1204}
7062023-09-22T23:28:48.402Z{"msg":"[2] rep_in_progress: return ReconcileIO { id: ReconciliationId(13), op: ExtentClose { repair_id: ReconciliationId(13), extent_id: 3 }, state: ClientData([New, New, InProgress]) }","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:47.192877621Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1204,"":"downstairs"}
7072023-09-22T23:28:48.409Z{"msg":"[0] received reconcile message","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:47.192896329Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1204}
7082023-09-22T23:28:48.412Z{"msg":"[2] client ExtentClose { repair_id: ReconciliationId(13), extent_id: 3 }","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:47.192915068Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1204}
7092023-09-22T23:28:48.415Z{"msg":"[0] rep_in_progress: return ReconcileIO { id: ReconciliationId(13), op: ExtentClose { repair_id: ReconciliationId(13), extent_id: 3 }, state: ClientData([InProgress, New, InProgress]) }","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:47.192936749Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1204,"":"downstairs"}
7102023-09-22T23:28:48.418Z{"msg":"[0] client ExtentClose { repair_id: ReconciliationId(13), extent_id: 3 }","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:47.192956291Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1204}
7112023-09-22T23:28:48.423Z{"msg":"[1] received reconcile message","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:47.192973667Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1204}
7122023-09-22T23:28:48.426Z{"msg":"[1] rep_in_progress: return ReconcileIO { id: ReconciliationId(13), op: ExtentClose { repair_id: ReconciliationId(13), extent_id: 3 }, state: ClientData([InProgress, InProgress, InProgress]) }","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:47.192994897Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1204,"":"downstairs"}
7132023-09-22T23:28:48.429Z{"msg":"[1] client ExtentClose { repair_id: ReconciliationId(13), extent_id: 3 }","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:47.193014776Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1204}
7142023-09-22T23:28:48.432Z{"msg":"Completion from [1] id:13 status:true","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:47.193032311Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1204}
7152023-09-22T23:28:48.435Z{"msg":"[14/20] Repair commands completed","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:47.193049862Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1204}
7162023-09-22T23:28:48.438Z{"msg":"Pop front: ReconcileIO { id: ReconciliationId(14), op: ExtentRepair { repair_id: ReconciliationId(14), 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]) }","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:47.19307371Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1204}
7172023-09-22T23:28:48.442Z{"msg":"Sent repair work, now wait for resp","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:47.193092324Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1204}
7182023-09-22T23:28:48.445Z{"msg":"[2] received reconcile message","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:47.19310991Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1204}
7192023-09-22T23:28:48.447Z{"msg":"[2] rep_in_progress: return ReconcileIO { id: ReconciliationId(14), op: ExtentRepair { repair_id: ReconciliationId(14), extent_id: 3, source_client_id: ClientId(0), source_repair_address: 0.0.0.0:12810, dest_clients: [ClientId(2)] }, state: ClientData([New, New, InProgress]) }","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:47.193134055Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1204,"":"downstairs"}
7202023-09-22T23:28:48.450Z{"msg":"[2] client ExtentRepair { repair_id: ReconciliationId(14), extent_id: 3, source_client_id: ClientId(0), source_repair_address: 0.0.0.0:12810, dest_clients: [ClientId(2)] }","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:47.193156458Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1204}
7212023-09-22T23:28:48.453Z{"msg":"[2] Sending repair request ReconciliationId(14)","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:47.193174753Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1204}
7222023-09-22T23:28:48.456Z{"msg":"[0] received reconcile message","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:47.19319258Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1204}
7232023-09-22T23:28:48.459Z{The guest has finished waiting for activation with:28
7242023-09-22T23:28:48.462Z"msg":"[0] rep_in_progress: return ReconcileIO { id: ReconciliationId(14), op: ExtentRepair { repair_id: ReconciliationId(14), extent_id: 3, source_client_id: ClientId(0), source_repair_address: 0.0.0.0:12810, dest_clients: [ClientId(2)] }, state: ClientData([InProgress, New, InProgress]) }","v":0,Wait for a query_work_queue command to finish before sending IO
7252023-09-22T23:28:48.465Z"name":"crucible","level":30,"time":"2023-09-22T23:28:47.332101897Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1204,"":"downstairs"}
7262023-09-22T23:28:48.468Z{"msg":"[0] client ExtentRepair { repair_id: ReconciliationId(14), extent_id: 3, source_client_id: ClientId(0), source_repair_address: 0.0.0.0:12810, dest_clients: [ClientId(2)] }","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:47.332163232Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1204}
7272023-09-22T23:28:48.471Z{"msg":"[0] No action required ReconciliationId(14)","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:47.33218399Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1204}
7282023-09-22T23:28:48.474Z{"msg":"[1] received reconcile message","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:47.332202502Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1204}
7292023-09-22T23:28:48.477Z{"msg":"[1] rep_in_progress: return ReconcileIO { id: ReconciliationId(14), op: ExtentRepair { repair_id: ReconciliationId(14), extent_id: 3, source_client_id: ClientId(0), source_repair_address: 0.0.0.0:12810, dest_clients: [ClientId(2)] }, state: ClientData([Done, InProgress, InProgress]) }","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:47.332227224Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1204,"":"downstairs"}
7302023-09-22T23:28:48.480Z{"msg":"[1] client ExtentRepair { repair_id: ReconciliationId(14), extent_id: 3, source_client_id: ClientId(0), source_repair_address: 0.0.0.0:12810, dest_clients: [ClientId(2)] }","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:47.332250278Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1204}
7312023-09-22T23:28:48.485Z{"msg":"[1] No action required ReconciliationId(14)","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:47.332269156Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1204}
7322023-09-22T23:28:48.488Z{"msg":"Completion from [2] id:14 status:true","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:47.332286906Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1204}
7332023-09-22T23:28:48.491Z{"msg":"[15/20] Repair commands completed","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:47.332304348Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1204}
7342023-09-22T23:28:48.494Z{"msg":"Pop front: ReconcileIO { id: ReconciliationId(15), op: ExtentReopen { repair_id: ReconciliationId(15), extent_id: 3 }, state: ClientData([New, New, New]) }","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:47.33232495Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1204}
7352023-09-22T23:28:48.497Z{"msg":"Sent repair work, now wait for resp","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:47.332343242Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1204}
7362023-09-22T23:28:48.500Z{"msg":"[2] received reconcile message","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:47.332360624Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1204}
7372023-09-22T23:28:48.503Z{"msg":"[2] rep_in_progress: return ReconcileIO { id: ReconciliationId(15), op: ExtentReopen { repair_id: ReconciliationId(15), extent_id: 3 }, state: ClientData([New, New, InProgress]) }","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:47.332382224Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1204,"":"downstairs"}
7382023-09-22T23:28:48.510Z{"msg":"[2] client ExtentReopen { repair_id: ReconciliationId(15), extent_id: 3 }","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:47.332402541Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1204}
7392023-09-22T23:28:48.513Z{"msg":"[0] received reconcile message","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:47.332420477Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1204}
7402023-09-22T23:28:48.516Z{"msg":"[0] rep_in_progress: return ReconcileIO { id: ReconciliationId(15), op: ExtentReopen { repair_id: ReconciliationId(15), extent_id: 3 }, state: ClientData([InProgress, New, InProgress]) }","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:47.332441981Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1204,"":"downstairs"}
7412023-09-22T23:28:48.520Z{"msg":"[0] client ExtentReopen { repair_id: ReconciliationId(15), extent_id: 3 }","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:47.332461897Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1204}
7422023-09-22T23:28:48.523Z{"msg":"[1] received reconcile message","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:47.332479339Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1204}
7432023-09-22T23:28:48.525Z{"msg":"[1] rep_in_progress: return ReconcileIO { id: ReconciliationId(15), op: ExtentReopen { repair_id: ReconciliationId(15), extent_id: 3 }, state: ClientData([InProgress, InProgress, InProgress]) }","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:47.332500892Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1204,"":"downstairs"}
7442023-09-22T23:28:48.529Z{"msg":"[1] client ExtentReopen { repair_id: ReconciliationId(15), extent_id: 3 }","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:47.332520282Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1204}
7452023-09-22T23:28:48.532Z{"msg":"Completion from [1] id:15 status:true","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:47.332538282Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1204}
7462023-09-22T23:28:48.535Z{"msg":"[16/20] Repair commands completed","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:47.332556041Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1204}
7472023-09-22T23:28:48.538Z{"msg":"Pop front: ReconcileIO { id: ReconciliationId(16), op: ExtentFlush { repair_id: ReconciliationId(16), extent_id: 1, client_id: ClientId(0), flush_number: 1939, gen_number: 28 }, state: ClientData([New, New, New]) }","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:47.332578039Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1204}
7482023-09-22T23:28:48.541Z{"msg":"Sent repair work, now wait for resp","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:47.332595995Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1204}
7492023-09-22T23:28:48.544Z{"msg":"[2] received reconcile message","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:47.332613428Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1204}
7502023-09-22T23:28:48.547Z{"msg":"[2] rep_in_progress: return ReconcileIO { id: ReconciliationId(16), op: ExtentFlush { repair_id: ReconciliationId(16), extent_id: 1, client_id: ClientId(0), flush_number: 1939, gen_number: 28 }, state: ClientData([New, New, InProgress]) }","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:47.332636449Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1204,"":"downstairs"}
7512023-09-22T23:28:48.550Z{"msg":"[2] client ExtentFlush { repair_id: ReconciliationId(16), extent_id: 1, client_id: ClientId(0), flush_number: 1939, gen_number: 28 }","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:47.332657986Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1204}
7522023-09-22T23:28:48.554Z{"msg":"[0] received reconcile message","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:47.332675625Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1204}
7532023-09-22T23:28:48.556Z{"msg":"[1] received reconcile message","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:47.332693296Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1204}
7542023-09-22T23:28:48.559Z{"msg":"[1] rep_in_progress: return ReconcileIO { id: ReconciliationId(16), op: ExtentFlush { repair_id: ReconciliationId(16), extent_id: 1, client_id: ClientId(0), flush_number: 1939, gen_number: 28 }, state: ClientData([New, InProgress, Done]) }","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:47.332716324Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1204,"":"downstairs"}
7552023-09-22T23:28:48.562Z{"msg":"[1] client ExtentFlush { repair_id: ReconciliationId(16), extent_id: 1, client_id: ClientId(0), flush_number: 1939, gen_number: 28 }","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:47.332737867Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1204}
7562023-09-22T23:28:48.565Z{Region: es:10 ec:5 bs:4096 ts:204800 tb:50 max_io:50 or 204800
7572023-09-22T23:28:48.569Z"msg":"[0] rep_in_progress: return ReconcileIO { id: ReconciliationId(16), op: ExtentFlush { repair_id: ReconciliationId(16), extent_id: 1, client_id: ClientId(0), flush_number: 1939, gen_number: 28 }, state: ClientData([InProgress, InProgress, Done]) }","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:48.038991953Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1204,"":"downstairs"}
7582023-09-22T23:28:48.572Z{"msg":"[0] client ExtentFlush { repair_id: ReconciliationId(16), extent_id: 1, client_id: ClientId(0), flush_number: 1939, gen_number: 28 }","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:48.039050362Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1204}
7592023-09-22T23:28:48.575Z{"msg":"Completion from [0] id:16 status:true","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:48.039070881Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1204}
7602023-09-22T23:28:48.579Z{"msg":"[17/20] Repair commands completed","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:48.039089601Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1204}
7612023-09-22T23:28:48.582Z{"msg":"Pop front: ReconcileIO { id: ReconciliationId(17), op: ExtentClose { repair_id: ReconciliationId(17), extent_id: 1 }, state: ClientData([New, New, New]) }","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:48.039110508Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1204}
7622023-09-22T23:28:48.585Z{"msg":"Sent repair work, now wait for resp","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:48.039128869Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1204}
7632023-09-22T23:28:48.588Z{"msg":"[2] received reconcile message","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:48.039146447Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1204}
7642023-09-22T23:28:48.591Z{"msg":"[2] rep_in_progress: return ReconcileIO { id: ReconciliationId(17), op: ExtentClose { repair_id: ReconciliationId(17), extent_id: 1 }, state: ClientData([New, New, InProgress]) }","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:48.039168288Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1204,"":"downstairs"}
7652023-09-22T23:28:48.597Z{"msg":"[2] client ExtentClose { repair_id: ReconciliationId(17), extent_id: 1 }","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:48.039189115Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1204}
7662023-09-22T23:28:48.600Z{"msg":"[0] received reconcile message","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:48.039207851Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1204}
7672023-09-22T23:28:48.603Z{"msg":"[0] rep_in_progress: return ReconcileIO { id: ReconciliationId(17), op: ExtentClose { repair_id: ReconciliationId(17), extent_id: 1 }, state: ClientData([InProgress, New, InProgress]) }","v":0,"name":"crucible","level":30Loading write count information from file "/var/tmp/test_up/verify_file"
7682023-09-22T23:28:48.606Z,"time":"2023-09-22T23:28:48.039229576Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1204,"":"downstairs"}
7692023-09-22T23:28:48.611Z{"msg":"[0] client ExtentClose { repair_id: ReconciliationId(17), extent_id: 1 }","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:48.03925377Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1204}
7702023-09-22T23:28:48.614ZRead and Verify all blocks (0..50 range:true)
7712023-09-22T23:28:48.617Z{"msg":"[1] received reconcile message","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:48.039274717Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1204}
7722023-09-22T23:28:48.620Z{"msg":"[1] rep_in_progress: return ReconcileIO { id: ReconciliationId(17), op: ExtentClose { repair_id: ReconciliationId(17), extent_id: 1 }, state: ClientData([InProgress, InProgress, InProgress]) }","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:48.039296829Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1204,"":"downstairs"}
7732023-09-22T23:28:48.623Z{"msg":"[1] client ExtentClose { repair_id: ReconciliationId(17), extent_id: 1 }","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:48.039316925Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1204}
7742023-09-22T23:28:48.626Z{"msg":"Completion from [1] id:17 status:true","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:48.039334802Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1204}
7752023-09-22T23:28:48.629Z{"msg":"[18/20] Repair commands completed","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:48.039352537Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1204}
7762023-09-22T23:28:48.632Z{"msg":"Pop front: ReconcileIO { id: ReconciliationId(18), op: ExtentRepair { repair_id: ReconciliationId(18), extent_id: 1, source_client_id: ClientId(0), source_repair_address: 0.0.0.0:12810, dest_clients: [ClientId(1), ClientId(2)] }, state: ClientData([New, New, New]) }","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:48.039376176Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1204}
7772023-09-22T23:28:48.635Z{"msg":"Sent repair work, now wait for resp","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:48.039394767Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1204}
7782023-09-22T23:28:48.638Z{"msg":"[2] received reconcile message","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:48.039412518Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1204}
7792023-09-22T23:28:48.641Z{"msg":"[2] rep_in_progress: return ReconcileIO { id: ReconciliationId(18), op: ExtentRepair { repair_id: ReconciliationId(18), extent_id: 1, source_client_id: ClientId(0), source_repair_address: 0.0.0.0:12810, dest_clients: [ClientId(1), ClientId(2)] }, state: ClientData([New, New, InProgress]) }","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:48.039448515Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1204,"":"downstairs"}
7802023-09-22T23:28:48.644Z{"msg":"[2] client ExtentRepair { repair_id: ReconciliationId(18), extent_id: 1, source_client_id: ClientId(0), source_repair_address: 0.0.0.0:12810, dest_clients: [ClientId(1), ClientId(2)] }","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:48.039476063Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1204}
7812023-09-22T23:28:48.647Z{"msg":"[2] Sending repair request ReconciliationId(18)","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:48.039494606Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1204}
7822023-09-22T23:28:48.650Z{"msg":"[0] received reconcile message","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:48.03951233Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1204}
7832023-09-22T23:28:48.653Z{"msg":"[0] rep_in_progress: return ReconcileIO { id: ReconciliationId(18), op: ExtentRepair { repair_id: ReconciliationId(18), extent_id: 1, source_client_id: ClientId(0), source_repair_address: 0.0.0.0:12810, dest_clients: [ClientId(1), ClientId(2)] }, state: ClientData([InProgress, New, InProgress]) }","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:48.039537187Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1204,"":"downstairs"}
7842023-09-22T23:28:48.656Z{"msg":"[0] client ExtentRepair { repair_id: ReconciliationId(18), extent_id: 1, source_client_id: ClientId(0), source_repair_address: 0.0.0.0:12810, dest_clients: [ClientId(1), ClientId(2)] }","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:48.039560469Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1204}
7852023-09-22T23:28:48.659Z{"msg":"[0] No action required ReconciliationId(18)","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:48.039578417Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1204}
7862023-09-22T23:28:48.662Z{"msg":"[1] received reconcile message","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:48.039596342Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1204}
7872023-09-22T23:28:48.665Z{"msg":"[1] rep_in_progress: return ReconcileIO { id: ReconciliationId(18), op: ExtentRepair { repair_id: ReconciliationId(18), extent_id: 1, source_client_id: ClientId(0), source_repair_address: 0.0.0.0:12810, dest_clients: [ClientId(1), ClientId(2)] }, state: ClientData([Done, InProgress, InProgress]) }","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:48.039620455Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1204,"":"downstairs"}
7882023-09-22T23:28:48.668Z{"msg":"[1] client ExtentRepair { repair_id: ReconciliationId(18), extent_id: 1, source_client_id: ClientId(0), source_repair_address: 0.0.0.0:12810, dest_clients: [ClientId(1), ClientId(2)] }","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:48.039643037Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1204}
7892023-09-22T23:28:48.671Z{Wrote out file "/var/tmp/test_up/verify_file"
7902023-09-22T23:28:48.674Z"msg":"[1] Sending repair request ReconciliationId(18)","v":0Verify test completed
7912023-09-22T23:28:48.677Z,"name":"crucible","level":30,"time":"2023-09-22T23:28:48.19371707Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1204}
7922023-09-22T23:28:48.680Z{"msg":"Completion from [1] id:18 status:true","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:48.19376847Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1204}
7932023-09-22T23:28:48.683Z{"msg":"[19/20] Repair commands completed","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:48.193788433Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1204}
7942023-09-22T23:28:48.686Z{"msg":"Pop front: ReconcileIO { id: ReconciliationId(19), op: ExtentReopen { repair_id: ReconciliationId(19), extent_id: 1 }, state: ClientData([New, New, New]) }","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:48.193810544Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1204}
7952023-09-22T23:28:48.689Z{"msg":"Sent repair work, now wait for resp","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:48.193828977Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1204}
7962023-09-22T23:28:48.692Z{"msg":"[2] received reconcile message","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:48.193846938Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1204}
7972023-09-22T23:28:48.696Z{"msg":"[2] rep_in_progress: return ReconcileIO { id: ReconciliationId(19), op: ExtentReopen { repair_id: ReconciliationId(19), extent_id: 1 }, state: ClientData([New, New, InProgress]) }","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:48.193868871Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1204,"":"downstairs"}
7982023-09-22T23:28:48.699Z{"msg":"[2] client ExtentReopen { repair_id: ReconciliationId(19), extent_id: 1 }","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:48.193890231Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1204}
7992023-09-22T23:28:48.702Z{"msg":"[0] received reconcile message","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:48.193908194Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1204}
8002023-09-22T23:28:48.705Z{"msg":"[0] rep_in_progress: return ReconcileIO { id: ReconciliationId(19), op: ExtentReopen { repair_id: ReconciliationId(19), extent_id: 1 }, state: ClientData([InProgress, New, InProgress]) }","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:48.193929944Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1204,"":"downstairs"}
8012023-09-22T23:28:48.708Z{"msg":"[0] client ExtentReopen { repair_id: ReconciliationId(19), extent_id: 1 }","v":0,"name"Wrote out file "/var/tmp/test_up/verify_file"
8022023-09-22T23:28:48.711Z:"CLIENT: Tests done. All submitted work has been ACK'd
8032023-09-22T23:28:48.714Zcrucible","level":30,"time":"2023-09-22T23:28:48.193955362Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1204}
8042023-09-22T23:28:48.717Z{"msg":"[1] received reconcile message","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:48.193973429Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1204}
8052023-09-22T23:28:48.720Z{"msg":"[1] rep_in_progress: return ReconcileIO { id: ReconciliationId(19), op: ExtentReopen { repair_id: ReconciliationId(19), extent_id: 1 }, state: ClientData([InProgress, InProgress, InProgress]) }","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:48.193994968Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1204,"":"downstairs"}
8062023-09-22T23:28:48.724Z{"msg":"[1] client ExtentReopen { repair_id: ReconciliationId(19), extent_id: 1 }","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:48.194014887Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1204}
8072023-09-22T23:28:48.727Z{"msg":"Completion from [1] id:19 status:true","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:48.1940327Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1204}
8082023-09-22T23:28:48.730Z{"msg":"[20/20] Repair commands completed","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:48.194050387Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1204}
8092023-09-22T23:28:48.733Z{"msg":"5 extents repaired in 0.466 ave:0.0931","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:48.194067795Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1204}
8102023-09-22T23:28:48.737Z{"msg":"All required repair work is completed","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:48.194085422Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1204}
8112023-09-22T23:28:48.742Z{"msg":"Set Downstairs and Upstairs active after repairs","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:48.194103195Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1204}
8122023-09-22T23:28:48.745Z{"msg":"4f5b30d9-884a-4acc-96a8-a0bb1b5e458c is now active with session: ec0e7796-968e-44ad-bd3b-8c3c402f3ba3","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:48.194122423Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1204}
8132023-09-22T23:28:48.748Z{"msg":"Notify all downstairs, region set compare is done.","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:48.194140363Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1204}
8142023-09-22T23:28:48.751Z{"msg":"Set check for repair","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:48.194157855Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1204}
8152023-09-22T23:28:48.754Z{"msg":"[0] received reconcile message","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:48.194174907Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1204}
8162023-09-22T23:28:48.757Z{"msg":"[0] All repairs completed, exit","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:48.194192044Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1204}
8172023-09-22T23:28:48.760Z{"msg":"[0] Starts cmd_loop","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:48.194209029Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1204}
8182023-09-22T23:28:48.763Z{"msg":"[2] received reconcile message","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:48.194226607Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1204}
8192023-09-22T23:28:48.766Z{"msg":"[2] All repairs completed, exit","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:48.194243962Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1204}
8202023-09-22T23:28:48.769Z{"msg":"[2] Starts cmd_loop","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:48.194260925Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1204}
8212023-09-22T23:28:48.772Z{"msg":"[1] received reconcile message","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:48.194278164Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1204}
8222023-09-22T23:28:48.775Z{"msg":"[1] All repairs completed, exit","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:48.194295332Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1204}
8232023-09-22T23:28:48.781Z{"msg":"[1] Starts cmd_loop","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:48.194312678Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1204}
8242023-09-22T23:28:48.790Z----------------------------------------------------------------
8252023-09-22T23:28:48.808Z Crucible gen:28 GIO:true work queues: Upstairs:0 downstairs:1
8262023-09-22T23:28:48.811ZGW_ID ACK DSID TYPE BLOCKS DS:0 DS:1 DS:2 REPLAY
8272023-09-22T23:28:48.814Z 1 Acked 1000 Read 50 Done Done Done false
8282023-09-22T23:28:48.817Z STATES DS:0 DS:1 DS:2 TOTAL
8292023-09-22T23:28:48.820Z New 0 0 0 0
8302023-09-22T23:28:48.824Z Sent 0 0 0 0
8312023-09-22T23:28:48.827Z Done 1 1 1 3
8322023-09-22T23:28:48.831Z Skipped 0 0 0 0
8332023-09-22T23:28:48.834Z Error 0 0 0 0
8342023-09-22T23:28:48.838ZLast Flush: 0 0 0
8352023-09-22T23:28:48.841ZDownstairs last five completed:
8362023-09-22T23:28:48.844ZUpstairs last five completed: 1
8372023-09-22T23:28:48.848ZCLIENT: Up:0 ds:1 act:3
8382023-09-22T23:28:48.851Z{"msg":"Checking if live repair is needed","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:48.242453787Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1204}
8392023-09-22T23:28:48.854Z{"msg":"No Live Repair required at this time","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:48.24249495Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1204}
8402023-09-22T23:28:52.230Z----------------------------------------------------------------
8412023-09-22T23:28:52.233Z Crucible gen:28 GIO:true work queues: Upstairs:0 downstairs:0
8422023-09-22T23:28:52.236ZDownstairs last five completed: 1001 1000
8432023-09-22T23:28:52.239ZUpstairs last five completed: 2 1
8442023-09-22T23:28:52.243ZCLIENT: Up:0 ds:0 act:3
8452023-09-22T23:28:52.246ZCLIENT: All crucible jobs finished, exiting program
8462023-09-22T23:28:52.248ZRepair part 2 passed
8472023-09-22T23:28:52.251Z/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
8482023-09-22T23:28:52.257Z{"msg":"current number of open files limit 65536 is already the maximum","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:52.259089604Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1206}
8492023-09-22T23:28:52.260Z{"msg":"Database read version 1","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:52.259493047Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1206}
8502023-09-22T23:28:52.263Z{"msg":"Database write version 1","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:52.259517804Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1206}
8512023-09-22T23:28:52.266Z{"msg":"current number of open files limit 65536 is already the maximum","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:52.263551967Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1206}
8522023-09-22T23:28:52.292Z{"msg":"Database read version 1","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:52.263604057Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1206}
8532023-09-22T23:28:52.295Z{"msg":"Database write version 1","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:52.263642297Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1206}
8542023-09-22T23:28:52.298Z{"msg":"current number of open files limit 65536 is already the maximum","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:52.265616624Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1206}
8552023-09-22T23:28:52.301Z{"msg":"Database read version 1","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:52.265744069Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1206}
8562023-09-22T23:28:52.304Z{"msg":"Database write version 1","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:52.265787575Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1206}
8572023-09-22T23:28:52.307ZEXT BLOCKS GEN0 GEN1 GEN2 FL0 FL1 FL2 D0 D1 D2 DIFF
8582023-09-22T23:28:52.310Z 0 000-009 28 28 28 1939 1939 1939 F F F
8592023-09-22T23:28:52.313Z 1 010-019 28 28 28 1939 1939 1939 F F F
8602023-09-22T23:28:52.316Z 2 020-029 28 28 28 1939 1939 1939 F F F
8612023-09-22T23:28:52.319Z 3 030-039 27 27 27 1938 1938 1938 F F F
8622023-09-22T23:28:52.323Z 4 040-049 27 27 27 1938 1938 1938 F F F
8632023-09-22T23:28:52.326ZMax gen: 28, Max flush: 1939
8642023-09-22T23:28:52.329Zdump test passed
8652023-09-22T23:28:52.332Z/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
8662023-09-22T23:28:52.335Z{"msg":"current number of open files limit 65536 is already the maximum","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:52.289526725Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1207}
8672023-09-22T23:28:52.338Z{"msg":"Database read version 1","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:52.289948755Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1207}
8682023-09-22T23:28:52.341Z{"msg":"Database write version 1","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:52.289992136Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1207}
8692023-09-22T23:28:52.344Z{"msg":"current number of open files limit 65536 is already the maximum","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:52.29359563Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1207}
8702023-09-22T23:28:52.347Z{"msg":"Database read version 1","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:52.293644655Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1207}
8712023-09-22T23:28:52.350Z{"msg":"Database write version 1","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:52.293682255Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1207}
8722023-09-22T23:28:52.354Z{"msg":"current number of open files limit 65536 is already the maximum","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:52.295391953Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1207}
8732023-09-22T23:28:52.357Z{"msg":"Database read version 1","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:52.295447842Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1207}
8742023-09-22T23:28:52.360Z{"msg":"Database write version 1","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:52.295488905Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1207}
8752023-09-22T23:28:52.363Z Extent 1
8762023-09-22T23:28:52.366ZGEN 28 28 28
8772023-09-22T23:28:52.369ZFLUSH_ID 1939 1939 1939
8782023-09-22T23:28:52.372ZDIRTY
8792023-09-22T23:28:52.375Z
8802023-09-22T23:28:52.378ZBLOCK D0 D1 D2 C0 C1 C2 DIFF
8812023-09-22T23:28:52.381Z{"msg":"current number of open files limit 65536 is already the maximum","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:52.297334272Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1207}
8822023-09-22T23:28:52.384Z{"msg":"Database read version 1","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:52.297384666Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1207}
8832023-09-22T23:28:52.387Z{"msg":"Database write version 1","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:52.297422923Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1207}
8842023-09-22T23:28:52.390Z{"msg":"current number of open files limit 65536 is already the maximum","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:52.299346665Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1207}
8852023-09-22T23:28:52.393Z{"msg":"Database read version 1","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:52.29939499Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1207}
8862023-09-22T23:28:52.396Z{"msg":"Database write version 1","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:52.299441286Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1207}
8872023-09-22T23:28:52.399Z{"msg":"current number of open files limit 65536 is already the maximum","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:52.301141427Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1207}
8882023-09-22T23:28:52.402Z{"msg":"Database read version 1","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:52.301191416Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1207}
8892023-09-22T23:28:52.406Z{"msg":"Database write version 1","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:52.30122936Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1207}
8902023-09-22T23:28:52.411Z010 A A A A A A
8912023-09-22T23:28:52.415Z{"msg":"current number of open files limit 65536 is already the maximum","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:52.303066485Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1207}
8922023-09-22T23:28:52.418Z{"msg":"Database read version 1","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:52.303113566Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1207}
8932023-09-22T23:28:52.421Z{"msg":"Database write version 1","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:52.303150827Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1207}
8942023-09-22T23:28:52.424Z{"msg":"current number of open files limit 65536 is already the maximum","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:52.304946413Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1207}
8952023-09-22T23:28:52.427Z{"msg":"Database read version 1","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:52.304996257Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1207}
8962023-09-22T23:28:52.430Z{"msg":"Database write version 1","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:52.305034182Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1207}
8972023-09-22T23:28:52.433Z{"msg":"current number of open files limit 65536 is already the maximum","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:52.306729253Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1207}
8982023-09-22T23:28:52.436Z{"msg":"Database read version 1","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:52.306778695Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1207}
8992023-09-22T23:28:52.439Z{"msg":"Database write version 1","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:52.306816539Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1207}
9002023-09-22T23:28:52.442Z011 A A A A A A
9012023-09-22T23:28:52.447Z{"msg":"current number of open files limit 65536 is already the maximum","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:52.308533403Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1207}
9022023-09-22T23:28:52.451Z{"msg":"Database read version 1","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:52.308580362Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1207}
9032023-09-22T23:28:52.454Z{"msg":"Database write version 1","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:52.308600065Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1207}
9042023-09-22T23:28:52.457Z{"msg":"current number of open files limit 65536 is already the maximum","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:52.310307241Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1207}
9052023-09-22T23:28:52.459Z{"msg":"Database read version 1","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:52.310356705Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1207}
9062023-09-22T23:28:52.462Z{"msg":"Database write version 1","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:52.310394321Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1207}
9072023-09-22T23:28:52.466Z{"msg":"current number of open files limit 65536 is already the maximum","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:52.312060596Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1207}
9082023-09-22T23:28:52.469Z{"msg":"Database read version 1","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:52.312107286Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1207}
9092023-09-22T23:28:52.477Z{"msg":"Database write version 1","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:52.312144918Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1207}
9102023-09-22T23:28:52.480Z012 A A A A A A
9112023-09-22T23:28:52.483Z{"msg":"current number of open files limit 65536 is already the maximum","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:52.313870662Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1207}
9122023-09-22T23:28:52.486Z{"msg":"Database read version 1","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:52.313920598Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1207}
9132023-09-22T23:28:52.489Z{"msg":"Database write version 1","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:52.313957758Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1207}
9142023-09-22T23:28:52.492Z{"msg":"current number of open files limit 65536 is already the maximum","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:52.315647372Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1207}
9152023-09-22T23:28:52.495Z{"msg":"Database read version 1","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:52.315725545Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1207}
9162023-09-22T23:28:52.498Z{"msg":"Database write version 1","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:52.315782214Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1207}
9172023-09-22T23:28:52.501Z{"msg":"current number of open files limit 65536 is already the maximum","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:52.317393237Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1207}
9182023-09-22T23:28:52.504Z{"msg":"Database read version 1","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:52.317440579Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1207}
9192023-09-22T23:28:52.507Z{"msg":"Database write version 1","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:52.31747888Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1207}
9202023-09-22T23:28:52.510Z013 A A A A A A
9212023-09-22T23:28:52.513Z{"msg":"current number of open files limit 65536 is already the maximum","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:52.319240327Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1207}
9222023-09-22T23:28:52.516Z{"msg":"Database read version 1","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:52.319287773Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1207}
9232023-09-22T23:28:52.519Z{"msg":"Database write version 1","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:52.319325778Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1207}
9242023-09-22T23:28:52.522Z{"msg":"current number of open files limit 65536 is already the maximum","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:52.321016542Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1207}
9252023-09-22T23:28:52.525Z{"msg":"Database read version 1","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:52.321062441Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1207}
9262023-09-22T23:28:52.528Z{"msg":"Database write version 1","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:52.321099763Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1207}
9272023-09-22T23:28:52.531Z{"msg":"current number of open files limit 65536 is already the maximum","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:52.322795493Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1207}
9282023-09-22T23:28:52.534Z{"msg":"Database read version 1","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:52.322820073Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1207}
9292023-09-22T23:28:52.538Z{"msg":"Database write version 1","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:52.322838399Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1207}
9302023-09-22T23:28:52.541Z014 A A A A A A
9312023-09-22T23:28:52.544Z{"msg":"current number of open files limit 65536 is already the maximum","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:52.324575624Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1207}
9322023-09-22T23:28:52.547Z{"msg":"Database read version 1","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:52.32459979Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1207}
9332023-09-22T23:28:52.770Z{"msg":"Database write version 1","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:52.324618323Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1207}
9342023-09-22T23:28:52.774Z{"msg":"current number of open files limit 65536 is already the maximum","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:52.326334812Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1207}
9352023-09-22T23:28:52.776Z{"msg":"Database read version 1","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:52.32635908Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1207}
9362023-09-22T23:28:52.779Z{"msg":"Database write version 1","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:52.326377332Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1207}
9372023-09-22T23:28:52.783Z{"msg":"current number of open files limit 65536 is already the maximum","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:52.328092053Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1207}
9382023-09-22T23:28:52.786Z{"msg":"Database read version 1","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:52.328116411Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1207}
9392023-09-22T23:28:52.788Z{"msg":"Database write version 1","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:52.328134504Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1207}
9402023-09-22T23:28:52.792Z015 A A A A A A
9412023-09-22T23:28:52.795Z{"msg":"current number of open files limit 65536 is already the maximum","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:52.329901936Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1207}
9422023-09-22T23:28:52.798Z{"msg":"Database read version 1","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:52.329925941Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1207}
9432023-09-22T23:28:52.800Z{"msg":"Database write version 1","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:52.329944226Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1207}
9442023-09-22T23:28:52.804Z{"msg":"current number of open files limit 65536 is already the maximum","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:52.331676424Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1207}
9452023-09-22T23:28:52.806Z{"msg":"Database read version 1","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:52.331701012Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1207}
9462023-09-22T23:28:52.810Z{"msg":"Database write version 1","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:52.331719188Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1207}
9472023-09-22T23:28:52.813Z{"msg":"current number of open files limit 65536 is already the maximum","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:52.333469327Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1207}
9482023-09-22T23:28:52.816Z{"msg":"Database read version 1","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:52.333493497Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1207}
9492023-09-22T23:28:52.819Z{"msg":"Database write version 1","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:52.333511685Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1207}
9502023-09-22T23:28:52.822Z016 A A A A A A
9512023-09-22T23:28:52.825Z{"msg":"current number of open files limit 65536 is already the maximum","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:52.335272477Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1207}
9522023-09-22T23:28:52.828Z{"msg":"Database read version 1","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:52.335296822Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1207}
9532023-09-22T23:28:52.831Z{"msg":"Database write version 1","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:52.335315269Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1207}
9542023-09-22T23:28:52.834Z{"msg":"current number of open files limit 65536 is already the maximum","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:52.33705026Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1207}
9552023-09-22T23:28:52.837Z{"msg":"Database read version 1","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:52.337075412Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1207}
9562023-09-22T23:28:52.840Z{"msg":"Database write version 1","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:52.337093726Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1207}
9572023-09-22T23:28:52.843Z{"msg":"current number of open files limit 65536 is already the maximum","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:52.338808897Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1207}
9582023-09-22T23:28:52.846Z{"msg":"Database read version 1","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:52.338835289Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1207}
9592023-09-22T23:28:52.849Z{"msg":"Database write version 1","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:52.338853549Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1207}
9602023-09-22T23:28:52.852Z017 A A A A A A
9612023-09-22T23:28:52.855Z{"msg":"current number of open files limit 65536 is already the maximum","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:52.340599289Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1207}
9622023-09-22T23:28:52.857Z{"msg":"Database read version 1","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:52.340623891Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1207}
9632023-09-22T23:28:52.860Z{"msg":"Database write version 1","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:52.340642262Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1207}
9642023-09-22T23:28:52.863Z{"msg":"current number of open files limit 65536 is already the maximum","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:52.342360187Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1207}
9652023-09-22T23:28:52.866Z{"msg":"Database read version 1","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:52.342386209Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1207}
9662023-09-22T23:28:52.870Z{"msg":"Database write version 1","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:52.342404892Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1207}
9672023-09-22T23:28:52.873Z{"msg":"current number of open files limit 65536 is already the maximum","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:52.344142704Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1207}
9682023-09-22T23:28:52.875Z{"msg":"Database read version 1","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:52.344177011Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1207}
9692023-09-22T23:28:52.878Z{"msg":"Database write version 1","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:52.344196784Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1207}
9702023-09-22T23:28:52.881Z018 A A A A A A
9712023-09-22T23:28:52.885Z{"msg":"current number of open files limit 65536 is already the maximum","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:52.345977097Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1207}
9722023-09-22T23:28:52.888Z{"msg":"Database read version 1","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:52.346020856Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1207}
9732023-09-22T23:28:52.891Z{"msg":"Database write version 1","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:52.346043456Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1207}
9742023-09-22T23:28:52.894Z{"msg":"current number of open files limit 65536 is already the maximum","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:52.347730741Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1207}
9752023-09-22T23:28:52.897Z{"msg":"Database read version 1","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:52.347757074Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1207}
9762023-09-22T23:28:52.900Z{"msg":"Database write version 1","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:52.347775706Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1207}
9772023-09-22T23:28:52.903Z{"msg":"current number of open files limit 65536 is already the maximum","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:52.349492341Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1207}
9782023-09-22T23:28:52.906Z{"msg":"Database read version 1","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:52.349522302Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1207}
9792023-09-22T23:28:52.909Z{"msg":"Database write version 1","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:52.349540843Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1207}
9802023-09-22T23:28:52.912Z019 A A A A A A
9812023-09-22T23:28:52.915Zdump extent test passed
9822023-09-22T23:28:52.919Z
9832023-09-22T23:28:52.922Z/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
9842023-09-22T23:28:52.925Zreal 5:16.235576654
9852023-09-22T23:28:52.928Z{"msg":"current number of open files limit 65536 is already the maximum","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:52.376366781Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1208}
9862023-09-22T23:28:52.931Zuser 4:34.220862192
9872023-09-22T23:28:52.934Z{"msg":"Database read version 1","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:52.376711878Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1208}
9882023-09-22T23:28:52.937Zsys 21.802254449
9892023-09-22T23:28:52.940Z{"msg":"Database write version 1","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:52.376734965Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1208}
9902023-09-22T23:28:52.943Ztrap 0.306314243
9912023-09-22T23:28:52.946Z{"msg":"current number of open files limit 65536 is already the maximum","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:52.380184475Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1208}
9922023-09-22T23:28:52.949Ztflt 0.145881211
9932023-09-22T23:28:52.952Z{"msg":"Database read version 1","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:52.380215206Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1208}
9942023-09-22T23:28:52.955Zdflt 0.035699045
9952023-09-22T23:28:52.958Z{"msg":"Database write version 1","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:52.380233892Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1208}
9962023-09-22T23:28:52.961Zkflt 0.003714260
9972023-09-22T23:28:52.964Z{"msg":"current number of open files limit 65536 is already the maximum","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:52.381957186Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1208}
9982023-09-22T23:28:52.967Zlock 48:33.422890844
9992023-09-22T23:28:52.970Z{"msg":"Database read version 1","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:52.381985572Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1208}
10002023-09-22T23:28:52.973Zslp 9:55.911358043
10012023-09-22T23:28:52.976Z{"msg":"Database write version 1","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:52.382003895Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1208}
10022023-09-22T23:28:52.979Zlat 17.731011962
10032023-09-22T23:28:52.982ZExtent 2 Block in extent 0 Actual block 20
10042023-09-22T23:28:52.986Zstop 0.027794844
10052023-09-22T23:28:52.989Z
10062023-09-22T23:28:52.992Z{"msg":"current number of open files limit 65536 is already the maximum","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:52.383725268Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1208}
10072023-09-22T23:28:52.995Z{"msg":"Database read version 1","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:52.383755645Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1208}
10082023-09-22T23:28:52.998Z{"msg":"Database write version 1","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:52.383774692Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1208}
10092023-09-22T23:28:53.001Z{"msg":"current number of open files limit 65536 is already the maximum","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:52.385630824Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1208}
10102023-09-22T23:28:53.004Z{"msg":"Database read version 1","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:52.385656651Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1208}
10112023-09-22T23:28:53.007Z{"msg":"Database write version 1","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:52.385675054Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1208}
10122023-09-22T23:28:53.010Z{"msg":"current number of open files limit 65536 is already the maximum","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:52.387372767Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1208}
10132023-09-22T23:28:53.013Z{"msg":"Database read version 1","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:52.387400978Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1208}
10142023-09-22T23:28:53.016Z{"msg":"Database write version 1","v":0,"name":"crucible","level":30,"time":"2023-09-22T23:28:52.387419214Z","hostname":"ip-10-150-1-92.us-west-2.compute.internal","pid":1208}
10152023-09-22T23:28:53.019Z DATA SHA256 VER
10162023-09-22T23:28:53.022Z------ ---------------------------------------------------------------- ---
10172023-09-22T23:28:53.025Z 0 83926fd78acd93a70cbadd18af30bfb6b791b5ab051a895191bc5a525babcb92 A
10182023-09-22T23:28:53.028Z 1 83926fd78acd93a70cbadd18af30bfb6b791b5ab051a895191bc5a525babcb92 A
10192023-09-22T23:28:53.031Z 2 83926fd78acd93a70cbadd18af30bfb6b791b5ab051a895191bc5a525babcb92 A
10202023-09-22T23:28:53.034Z
10212023-09-22T23:28:53.037ZNONCES 0 1 2 DIFF
10222023-09-22T23:28:53.040Z------ ------------------------ ------------------------ ------------------------ -----
10232023-09-22T23:28:53.043Z 0 5883d8492fac89f025879a06 5883d8492fac89f025879a06 5883d8492fac89f025879a06
10242023-09-22T23:28:53.047Z
10252023-09-22T23:28:53.050Z TAGS 0 1 2 DIFF
10262023-09-22T23:28:53.052Z------ -------------------------------- -------------------------------- -------------------------------- -----
10272023-09-22T23:28:53.056Z 0 fb0ef75e854bf4527c8755d7944300da fb0ef75e854bf4527c8755d7944300da fb0ef75e854bf4527c8755d7944300da
10282023-09-22T23:28:53.058Z
10292023-09-22T23:28:53.061ZHASHES 0 1 2 DIFF
10302023-09-22T23:28:53.065Z------ ---------------- ---------------- ---------------- -----
10312023-09-22T23:28:53.068Z 0 42cb005a7b78516a 42cb005a7b78516a 42cb005a7b78516a
10322023-09-22T23:28:53.071Z
10332023-09-22T23:28:53.074Zdump block test passed
10342023-09-22T23:28:53.077ZUpstairs tests have completed, stopping all downstairs
10352023-09-22T23:28:53.080Z
10362023-09-22T23:28:53.083ZAll Tests have passed
10372023-09-22T23:28:53.087Z5:17 Test duration
10382023-09-22T23:28:53.090Zprocess exited: duration 328806 ms, exit code 0
 
10392023-09-22T23:28:53.097Zfound 5 output files
10402023-09-22T23:28:53.103Zuploading: /tmp/test_up/dsc-out.txt (4481 bytes)
10412023-09-22T23:28:54.122Zuploaded: /tmp/test_up/dsc-out.txt
10422023-09-22T23:28:54.129Zuploading: /tmp/test_up/test_up_out.txt (3408303 bytes)
10432023-09-22T23:28:56.474Zuploaded: /tmp/test_up/test_up_out.txt
10442023-09-22T23:28:56.478Zuploading: /tmp/test_up/dsc/downstairs-8810.txt (65982 bytes)
10452023-09-22T23:28:57.498Zuploaded: /tmp/test_up/dsc/downstairs-8810.txt
10462023-09-22T23:28:57.503Zuploading: /tmp/test_up/dsc/downstairs-8820.txt (58661 bytes)
10472023-09-22T23:28:58.520Zuploaded: /tmp/test_up/dsc/downstairs-8820.txt
10482023-09-22T23:28:58.524Zuploading: /tmp/test_up/dsc/downstairs-8830.txt (11337 bytes)
10492023-09-22T23:28:59.579Zuploaded: /tmp/test_up/dsc/downstairs-8830.txt