01HCN263AVYWKNWCXBWHD6ZRDJ: 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: 01HCN26KRQ20M7TNVB88FC7E0V

Tags:

Artefacts:

Output:

SEQ GLOBAL TIME DETAILS
12023-10-13T18:06:08.036Zjob dependencies complete; ready to run (waiting for 22 m 9 s)
22023-10-13T18:07:30.072Zjob assigned to worker 01HCN3FAAAH29VJE2N12V4P2V1 (queued for 1 m 22 s)
32023-10-13T18:07:30.507Zdownloading input: /input/build/work/bins/crucible-downstairs.gz
42023-10-13T18:07:48.139Zdownloaded input: /input/build/work/bins/crucible-downstairs.gz
52023-10-13T18:07:48.565Zdownloading input: /input/build/work/bins/crucible-hammer.gz
62023-10-13T18:08:14.516Zdownloaded input: /input/build/work/bins/crucible-hammer.gz
72023-10-13T18:08:14.521Zdownloading input: /input/build/work/bins/crutest.gz
82023-10-13T18:08:34.836Zdownloaded input: /input/build/work/bins/crutest.gz
92023-10-13T18:08:34.847Zdownloading input: /input/build/work/bins/dsc.gz
102023-10-13T18:08:46.986Zdownloaded input: /input/build/work/bins/dsc.gz
112023-10-13T18:08:47.252Zdownloading input: /input/build/work/scripts/test_ds.sh
122023-10-13T18:08:47.258Zdownloaded input: /input/build/work/scripts/test_ds.sh
132023-10-13T18:08:47.280Zdownloading input: /input/build/work/scripts/test_live_repair.sh
142023-10-13T18:08:47.335Zdownloaded input: /input/build/work/scripts/test_live_repair.sh
152023-10-13T18:08:47.548Zdownloading input: /input/build/work/scripts/test_repair.sh
162023-10-13T18:08:47.658Zdownloaded input: /input/build/work/scripts/test_repair.sh
172023-10-13T18:08:47.807Zdownloading input: /input/build/work/scripts/test_replay.sh
182023-10-13T18:08:47.923Zdownloaded input: /input/build/work/scripts/test_replay.sh
192023-10-13T18:08:48.084Zdownloading input: /input/build/work/scripts/test_up.sh
202023-10-13T18:08:48.206Zdownloaded input: /input/build/work/scripts/test_up.sh
212023-10-13T18:08:48.314Zdownloading input: /input/build/tmp/cargo-test-out.log
222023-10-13T18:08:48.465Zdownloaded input: /input/build/tmp/cargo-test-out.log
 
232023-10-13T18:08:48.526Zstarting task 0: "setup"
242023-10-13T18:08:48.801Z++ uname -s
252023-10-13T18:08:48.897Z+ kern=SunOS
262023-10-13T18:08:48.964Z+ case "$kern" in
272023-10-13T18:08:49.050Z+ groupadd -g 12345 build
282023-10-13T18:08:49.070Z+ useradd -u 12345 -g build -d /home/build -s /bin/bash -c build -P 'Primary Administrator' build
292023-10-13T18:08:50.685Z+ zfs create -o mountpoint=/work rpool/work
302023-10-13T18:08:50.875Z++ awk '$2 == "/home" { print $3 }' /etc/mnttab
312023-10-13T18:08:50.878Z+ home_fs=zfs
322023-10-13T18:08:50.881Z+ [[ zfs == autofs ]]
332023-10-13T18:08:50.884Z+ mkdir -p /home/build
342023-10-13T18:08:50.887Z+ chown build:build /home/build /work
352023-10-13T18:08:52.884Z+ chmod 0700 /home/build /work
362023-10-13T18:08:52.887Zprocess exited: duration 4356 ms, exit code 0
 
372023-10-13T18:08:52.895Zstarting task 1: "authentication"
382023-10-13T18:08:52.924Zprocess exited: duration 25 ms, exit code 0
 
392023-10-13T18:08:52.933Zstarting task 2: "build"
402023-10-13T18:08:52.945Z+ banner cores
412023-10-13T18:08:53.000Z
422023-10-13T18:08:53.004Z #### #### ##### ###### ####
432023-10-13T18:08:53.007Z # # # # # # # #
442023-10-13T18:08:53.011Z # # # # # ##### ####
452023-10-13T18:08:53.014Z # # # ##### # #
462023-10-13T18:08:53.018Z # # # # # # # # #
472023-10-13T18:08:53.021Z #### #### # # ###### ####
482023-10-13T18:08:53.025Z
492023-10-13T18:08:53.028Z+ pfexec coreadm -i /tmp/core.%f.%p -g /tmp/core.%f.%p -e global -e log -e proc-setid -e global-setid
502023-10-13T18:08:53.031Z+ echo 'input bins dir contains:'
512023-10-13T18:08:53.036Zinput bins dir contains:
522023-10-13T18:08:53.040Z+ ls -ltr /input/build/work/bins
532023-10-13T18:08:53.044Ztotal 697463
542023-10-13T18:08:53.048Z-rw-r--r-- 1 root root 107725127 Oct 13 18:07 crucible-downstairs.gz
552023-10-13T18:08:53.052Z-rw-r--r-- 1 root root 85722423 Oct 13 18:08 crucible-hammer.gz
562023-10-13T18:08:53.055Z-rw-r--r-- 1 root root 95189135 Oct 13 18:08 crutest.gz
572023-10-13T18:08:53.058Z-rw-r--r-- 1 root root 68233986 Oct 13 18:08 dsc.gz
582023-10-13T18:08:53.061Z+ banner unpack
592023-10-13T18:08:53.091Z
602023-10-13T18:08:53.135Z # # # # ##### ## #### # #
612023-10-13T18:08:53.141Z # # ## # # # # # # # # #
622023-10-13T18:08:53.176Z # # # # # # # # # # ####
632023-10-13T18:08:53.186Z # # # # # ##### ###### # # #
642023-10-13T18:08:53.192Z # # # ## # # # # # # #
652023-10-13T18:08:53.218Z #### # # # # # #### # #
662023-10-13T18:08:53.223Z
672023-10-13T18:08:53.226Z+ mkdir -p /var/tmp/bins
682023-10-13T18:08:53.230Z+ for t in "$input/bins/"*.gz
692023-10-13T18:08:53.233Z++ basename /input/build/work/bins/crucible-downstairs.gz
702023-10-13T18:08:53.236Z+ b=crucible-downstairs.gz
712023-10-13T18:08:53.240Z+ b=crucible-downstairs
722023-10-13T18:08:53.244Z+ gunzip
732023-10-13T18:08:56.823Z+ chmod +x /var/tmp/bins/crucible-downstairs
742023-10-13T18:08:56.826Z+ for t in "$input/bins/"*.gz
752023-10-13T18:08:56.830Z++ basename /input/build/work/bins/crucible-hammer.gz
762023-10-13T18:08:56.833Z+ b=crucible-hammer.gz
772023-10-13T18:08:56.836Z+ b=crucible-hammer
782023-10-13T18:08:56.839Z+ gunzip
792023-10-13T18:08:59.720Z+ chmod +x /var/tmp/bins/crucible-hammer
802023-10-13T18:08:59.723Z+ for t in "$input/bins/"*.gz
812023-10-13T18:08:59.725Z++ basename /input/build/work/bins/crutest.gz
822023-10-13T18:08:59.728Z+ b=crutest.gz
832023-10-13T18:08:59.731Z+ b=crutest
842023-10-13T18:08:59.734Z+ gunzip
852023-10-13T18:09:02.933Z+ chmod +x /var/tmp/bins/crutest
862023-10-13T18:09:02.937Z+ for t in "$input/bins/"*.gz
872023-10-13T18:09:02.944Z++ basename /input/build/work/bins/dsc.gz
882023-10-13T18:09:02.954Z+ b=dsc.gz
892023-10-13T18:09:02.958Z+ b=dsc
902023-10-13T18:09:02.961Z+ gunzip
912023-10-13T18:09:05.274Z+ chmod +x /var/tmp/bins/dsc
922023-10-13T18:09:05.278Z+ export BINDIR=/var/tmp/bins
932023-10-13T18:09:05.285Z+ BINDIR=/var/tmp/bins
942023-10-13T18:09:05.289Z+ banner test_up_encrypted
952023-10-13T18:09:05.293Z
962023-10-13T18:09:05.296Z ##### ###### #### ##### # # ##### ###### # #
972023-10-13T18:09:05.301Z # # # # # # # # # ## #
982023-10-13T18:09:05.305Z # ##### #### # # # # # ##### # # #
992023-10-13T18:09:05.309Z # # # # # # ##### # # # #
1002023-10-13T18:09:05.312Z # # # # # # # # # # ##
1012023-10-13T18:09:05.316Z # ###### #### # ####### #### # ####### ###### # #
1022023-10-13T18:09:05.321Z
1032023-10-13T18:09:05.329Z+ ptime -m bash /input/build/work/scripts/test_up.sh -N encrypted
1042023-10-13T18:09:05.334Z/input/build/work
1052023-10-13T18:09:05.339ZTurn off color for downstairs dump
1062023-10-13T18:09:05.473ZUpstairs using key: UOBOdL4rB9zWyXSm7tXhwALvFAnImPvzQyQvgvFRdtM=
1072023-10-13T18:09:05.480Zdsc output goes to /tmp/test_up/dsc-out.txt
1082023-10-13T18:09:05.485ZCreating three downstairs regions
1092023-10-13T18:09:06.152ZStarting three downstairs
1102023-10-13T18:09:11.160ZDisable automatic restart on all downstairs
1112023-10-13T18:09:11.281Z
1122023-10-13T18:09:11.290ZBegin tests, output goes to /tmp/test_up/test_up_out.txt
1132023-10-13T18:09:11.296ZRunning test: span
1142023-10-13T18:09:15.458ZCompleted test: span
1152023-10-13T18:09:15.467ZRunning test: big
1162023-10-13T18:09:20.208ZCompleted test: big
1172023-10-13T18:09:20.225ZRunning test: dep
1182023-10-13T18:11:05.707ZCompleted test: dep
1192023-10-13T18:11:05.717ZRunning test: balloon
1202023-10-13T18:13:19.238ZCompleted test: balloon
1212023-10-13T18:13:19.387ZRunning test: deactivate
1222023-10-13T18:13:28.740ZCompleted test: deactivate
1232023-10-13T18:13:28.745ZRunning hammer
1242023-10-13T18:13:54.395ZRun repair tests
1252023-10-13T18:13:54.399Z/var/tmp/bins/crutest fill -g 26 -q --key UOBOdL4rB9zWyXSm7tXhwALvFAnImPvzQyQvgvFRdtM= -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-10-13T18:13:54.421Z{"msg":"Upstairs starts","v":0,"name":"crucible","level":30,"time":"2023-10-13T18:13:54.42987971Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1191}
1272023-10-13T18:13:54.424Z{"msg":"Crucible Version: BuildInfo {\n version: \"0.0.1\",\n git_sha: \"a730f3b26afaf115f27149ef849470fd85caef41\",\n git_commit_timestamp: \"2023-10-13T17:42:12.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-10-13T18:13:54.430337286Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1191}
1282023-10-13T18:13:54.428Z{"msg":"Upstairs <-> Downstairs Message Version: 4","v":0,"name":"crucible","level":30,"time":"2023-10-13T18:13:54.430399007Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1191}
1292023-10-13T18:13:54.432Z{"msg":"Upstairs opts: Upstairs UUID: eb6a9987-15f2-4a32-b8d0-4f74fbee0394, Targets: [127.0.0.1:8810, 127.0.0.1:8820, 127.0.0.1:8830], lossy: false, flush_timeout: None, key populated: true, cert_pem populated: false, key_pem populated: false, root_cert_pem populated: false, Control: None, read_only: false","v":0,"name":"crucible","level":30,"time":"2023-10-13T18:13:54.430471581Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1191}
1302023-10-13T18:13:54.436Z{"msg":"Crucible stats registered with UUID: eb6a9987-15f2-4a32-b8d0-4f74fbee0394","v":0,"name":"crucible","level":30,"time":"2023-10-13T18:13:54.430527355Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1191}
1312023-10-13T18:13:54.448Z{"msg":"Crucible eb6a9987-15f2-4a32-b8d0-4f74fbee0394 has session id: 9cc05f40-5f5e-4171-a590-fce787bd90ac","v":0,"name":"crucible","level":30,"time":"2023-10-13T18:13:54.430590579Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1191}
1322023-10-13T18:13:54.451ZCrucible runtime is spawned
1332023-10-13T18:13:54.454ZThe guest has requested activation with gen:26
1342023-10-13T18:13:54.458Z{"msg":"up_listen starts","v":0,"name":"crucible","level":30,"time":"2023-10-13T18:13:54.430940022Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1191,"task":"up_listen"}
1352023-10-13T18:13:54.463Z{"msg":"Wait for all three downstairs to come online","v":0,"name":"crucible","level":30,"time":"2023-10-13T18:13:54.431012297Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1191}
1362023-10-13T18:13:54.476Z{"msg":"Flush timeout: 0.5","v":0,"name":"crucible","level":30,"time":"2023-10-13T18:13:54.431067706Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1191}
1372023-10-13T18:13:54.481Z{"msg":"[2] connecting to 127.0.0.1:8830","v":0,"name":"crucible","level":30,"time":"2023-10-13T18:13:54.43112114Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1191,"looper":"2"}
1382023-10-13T18:13:54.485Z{"msg":"[2] eb6a9987-15f2-4a32-b8d0-4f74fbee0394 looper connected","v":0,"name":"crucible","level":30,"time":"2023-10-13T18:13:54.431390632Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1191,"looper":"2"}
1392023-10-13T18:13:54.489Z{"msg":"[0] connecting to 127.0.0.1:8810","v":0,"name":"crucible","level":30,"time":"2023-10-13T18:13:54.431511598Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1191,"looper":"0"}
1402023-10-13T18:13:54.498Z{"msg":"[1] connecting to 127.0.0.1:8820","v":0,"name":"crucible","level":30,"time":"2023-10-13T18:13:54.431772117Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1191,"looper":"1"}
1412023-10-13T18:13:54.512Z{"msg":"[0] eb6a9987-15f2-4a32-b8d0-4f74fbee0394 looper connected","v":0,"name":"crucible","level":30,"time":"2023-10-13T18:13:54.431884759Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1191,"looper":"0"}
1422023-10-13T18:13:54.519Z{"msg":"[1] eb6a9987-15f2-4a32-b8d0-4f74fbee0394 looper connected","v":0,"name":"crucible","level":30,"time":"2023-10-13T18:13:54.431942895Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1191,"looper":"1"}
1432023-10-13T18:13:54.530Z{"msg":"eb6a9987-15f2-4a32-b8d0-4f74fbee0394 active request set","v":0,"name":"crucible","level":30,"time":"2023-10-13T18:13:54.432105522Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1191}
1442023-10-13T18:13:54.536Z{"msg":"Set desired generation to :26","v":0,"name":"crucible","level":30,"time":"2023-10-13T18:13:54.432164107Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1191}
1452023-10-13T18:13:54.540Z{"msg":"[2] Proc runs for 127.0.0.1:8830 in state New","v":0,"name":"crucible","level":30,"time":"2023-10-13T18:13:54.432348315Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1191}
1462023-10-13T18:13:54.544Z{"msg":"[0] Proc runs for 127.0.0.1:8810 in state New","v":0,"name":"crucible","level":30,"time":"2023-10-13T18:13:54.432788416Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1191}
1472023-10-13T18:13:54.558Z{"msg":"[1] Proc runs for 127.0.0.1:8820 in state New","v":0,"name":"crucible","level":30,"time":"2023-10-13T18:13:54.432872407Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1191}
1482023-10-13T18:13:54.571Z{"msg":"[2] eb6a9987-15f2-4a32-b8d0-4f74fbee0394 (8a5325f0-0b60-43e3-8483-1bd13db363ce) New New New ds_transition to WaitActive","v":0,"name":"crucible","level":30,"time":"2023-10-13T18:13:54.432936474Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1191}
1492023-10-13T18:13:54.577Z{"msg":"[2] Transition from New to WaitActive","v":0,"name":"crucible","level":30,"time":"2023-10-13T18:13:54.433046364Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1191}
1502023-10-13T18:13:54.581Z{"msg":"[2] client is_active_req TRUE, promote! session 8a5325f0-0b60-43e3-8483-1bd13db363ce","v":0,"name":"crucible","level":30,"time":"2023-10-13T18:13:54.433110838Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1191}
1512023-10-13T18:13:54.587Z{"msg":"[0] eb6a9987-15f2-4a32-b8d0-4f74fbee0394 (8a5325f0-0b60-43e3-8483-1bd13db363ce) New New WaitActive ds_transition to WaitActive","v":0,"name":"crucible","level":30,"time":"2023-10-13T18:13:54.433155827Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1191}
1522023-10-13T18:13:54.590Z{"msg":"[0] Transition from New to WaitActive","v":0,"name":"crucible","level":30,"time":"2023-10-13T18:13:54.433247572Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1191}
1532023-10-13T18:13:54.600Z{"msg":"[0] client is_active_req TRUE, promote! session 8a5325f0-0b60-43e3-8483-1bd13db363ce","v":0,"name":"crucible","level":30,"time":"2023-10-13T18:13:54.4332683Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1191}
1542023-10-13T18:13:54.603Z{"msg":"[1] eb6a9987-15f2-4a32-b8d0-4f74fbee0394 (8a5325f0-0b60-43e3-8483-1bd13db363ce) WaitActive New WaitActive ds_transition to WaitActive","v":0,"name":"crucible","level":30,"time":"2023-10-13T18:13:54.433301628Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1191}
1552023-10-13T18:13:54.607Z{"msg":"[1] Transition from New to WaitActive","v":0,"name":"crucible","level":30,"time":"2023-10-13T18:13:54.433399376Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1191}
1562023-10-13T18:13:54.621Z{"msg":"[1] client is_active_req TRUE, promote! session 8a5325f0-0b60-43e3-8483-1bd13db363ce","v":0,"name":"crucible","level":30,"time":"2023-10-13T18:13:54.433480792Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1191}
1572023-10-13T18:13:54.626Z{"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-10-13T18:13:54.433715779Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1191}
1582023-10-13T18:13:54.633Z{"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-10-13T18:13:54.433773618Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1191}
1592023-10-13T18:13:54.645Z{"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-10-13T18:13:54.433818152Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1191}
1602023-10-13T18:13:54.651Z{"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-10-13T18:13:54.433855236Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1191}
1612023-10-13T18:13:54.654Z{"msg":"eb6a9987-15f2-4a32-b8d0-4f74fbee0394 WaitActive WaitActive WaitActive","v":0,"name":"crucible","level":30,"time":"2023-10-13T18:13:54.43393622Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1191}
1622023-10-13T18:13:54.658Z{"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-10-13T18:13:54.433982466Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1191}
1632023-10-13T18:13:54.663Z{"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-10-13T18:13:54.434027539Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1191}
1642023-10-13T18:13:54.677Z{"msg":"eb6a9987-15f2-4a32-b8d0-4f74fbee0394 WaitActive WaitActive WaitActive","v":0,"name":"crucible","level":30,"time":"2023-10-13T18:13:54.434071471Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1191}
1652023-10-13T18:13:54.686Z{"msg":"eb6a9987-15f2-4a32-b8d0-4f74fbee0394 WaitActive WaitActive WaitActive","v":0,"name":"crucible","level":30,"time":"2023-10-13T18:13:54.434092041Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1191}
1662023-10-13T18:13:54.692Z{"msg":"[1] eb6a9987-15f2-4a32-b8d0-4f74fbee0394 (8a5325f0-0b60-43e3-8483-1bd13db363ce) WaitActive WaitActive WaitActive ds_transition to WaitQuorum","v":0,"name":"crucible","level":30,"time":"2023-10-13T18:13:54.434576852Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1191}
1672023-10-13T18:13:54.696Z{"msg":"[1] Transition from WaitActive to WaitQuorum","v":0,"name":"crucible","level":30,"time":"2023-10-13T18:13:54.434665547Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1191}
1682023-10-13T18:13:54.701Z{"msg":"[1] new RM replaced this: None","v":0,"name":"crucible","level":40,"time":"2023-10-13T18:13:54.434716876Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1191}
1692023-10-13T18:13:54.713Z{"msg":"[1] 127.0.0.1:8820 task reports connection:true","v":0,"name":"crucible","level":30,"time":"2023-10-13T18:13:54.434781402Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1191}
1702023-10-13T18:13:54.717Z{"msg":"eb6a9987-15f2-4a32-b8d0-4f74fbee0394 WaitActive WaitQuorum WaitActive","v":0,"name":"crucible","level":30,"time":"2023-10-13T18:13:54.434850538Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1191}
1712023-10-13T18:13:54.724Z{"msg":"[2] eb6a9987-15f2-4a32-b8d0-4f74fbee0394 (8a5325f0-0b60-43e3-8483-1bd13db363ce) WaitActive WaitQuorum WaitActive ds_transition to WaitQuorum","v":0,"name":"crucible","level":30,"time":"2023-10-13T18:13:54.43491819Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1191}
1722023-10-13T18:13:54.773Z{"msg":"[2] Transition from WaitActive to WaitQuorum","v":0,"name":"crucible","level":30,"time":"2023-10-13T18:13:54.434972863Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1191}
1732023-10-13T18:13:54.776Z{"msg":"[2] new RM replaced this: None","v":0,"name":"crucible","level":40,"time":"2023-10-13T18:13:54.43504121Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1191}
1742023-10-13T18:13:54.786Z{"msg":"[1] Starts reconcile loop","v":0,"name":"crucible","level":30,"time":"2023-10-13T18:13:54.435098595Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1191}
1752023-10-13T18:13:54.791Z{"msg":"[0] eb6a9987-15f2-4a32-b8d0-4f74fbee0394 (8a5325f0-0b60-43e3-8483-1bd13db363ce) WaitActive WaitQuorum WaitQuorum ds_transition to WaitQuorum","v":0,"name":"crucible","level":30The guest has finished waiting for activation with:26
1762023-10-13T18:13:54.799ZWait for a query_work_queue command to finish before sending IO
1772023-10-13T18:13:54.814Z,"time":"2023-10-13T18:13:54.435164531Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1191}
1782023-10-13T18:13:54.821Z{"msg":"[0] Transition from WaitActive to WaitQuorum","v":0,"name":"crucible","level":30,"time":"2023-10-13T18:13:54.435433073Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1191}
1792023-10-13T18:13:54.825Z{"msg":"[0] new RM replaced this: None","v":0,"name":"crucible","level":40,"time":"2023-10-13T18:13:54.435492768Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1191}
1802023-10-13T18:13:54.829Z{"msg":"[0]R flush_numbers: [1947, 1947, 1947, 1947, 1947]","v":0,"name":"crucible","level":30,"time":"2023-10-13T18:13:54.435554866Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1191}
1812023-10-13T18:13:54.833Z{"msg":"[0]R generation: [20, 20, 20, 20, 20]","v":0,"name":"crucible","level":30,"time":"2023-10-13T18:13:54.435622894Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1191}
1822023-10-13T18:13:54.841Z{"msg":"[0]R dirty: [false, false, false, false, false]","v":0,"name":"crucible","level":30,"time":"2023-10-13T18:13:54.435688792Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1191}
1832023-10-13T18:13:54.844Z{"msg":"[1]R flush_numbers: [1947, 1947, 1947, 1947, 1947]","v":0,"name":"crucible","level":30,"time":"2023-10-13T18:13:54.435742313Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1191}
1842023-10-13T18:13:54.849Z{"msg":"[1]R generation: [20, 20, 20, 20, 20]","v":0,"name":"crucible","level":30,"time":"2023-10-13T18:13:54.435786918Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1191}
1852023-10-13T18:13:54.854Z{"msg":"[1]R dirty: [false, false, false, false, false]","v":0,"name":"crucible","level":30,"time":"2023-10-13T18:13:54.435826206Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1191}
1862023-10-13T18:13:54.863Z{"msg":"[2]R flush_numbers: [1947, 1947, 1947, 1947, 1947]","v":0,"name":"crucible","level":30,"time":"2023-10-13T18:13:54.435847481Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1191}
1872023-10-13T18:13:54.867Z{"msg":"[2]R generation: [20, 20, 20, 20, 20]","v":0,"name":"crucible","level":30,"time":"2023-10-13T18:13:54.435865068Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1191}
1882023-10-13T18:13:54.873Z{"msg":"[2]R dirty: [false, false, false, false, false]","v":0,"name":"crucible","level":30,"time":"2023-10-13T18:13:54.435908989Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1191}
1892023-10-13T18:13:54.882Z{"msg":"Max found gen is 21","v":0,"name":"crucible","level":30,"time":"2023-10-13T18:13:54.435935683Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1191}
1902023-10-13T18:13:54.887Z{"msg":"Generation requested: 26 >= found:21","v":0,"name":"crucible","level":30,"time":"2023-10-13T18:13:54.435998028Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1191}
1912023-10-13T18:13:54.891Z{"msg":"Next flush: 1948","v":0,"name":"crucible","level":30,"time":"2023-10-13T18:13:54.436065601Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1191}
1922023-10-13T18:13:54.896Z{"msg":"All extents match","v":0,"name":"crucible","level":30,"time":"2023-10-13T18:13:54.436133892Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1191}
1932023-10-13T18:13:54.900Z{"msg":"No downstairs repair required","v":0,"name":"crucible","level":30,"time":"2023-10-13T18:13:54.436203426Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1191}
1942023-10-13T18:13:54.904Z{"msg":"[2] Starts reconcile loop","v":0,"name":"crucible","level":30,"time":"2023-10-13T18:13:54.436241718Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1191}
1952023-10-13T18:13:54.908Z{"msg":"[0] Starts reconcile loop","v":0,"name":"crucible","level":30,"time":"2023-10-13T18:13:54.436275839Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1191}
1962023-10-13T18:13:54.911Z{"msg":"No initial repair work was required","v":0,"name":"crucible","level":30,"time":"2023-10-13T18:13:54.436312379Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1191}Region: es:10 ec:5 bs:4096 ts:204800 tb:50 max_io:50 or 204800
1972023-10-13T18:13:54.917Z
1982023-10-13T18:13:54.921Z{"msg":"Set Downstairs and Upstairs active","v":0,"name":"crucible","level":30,"time":"2023-10-13T18:13:54.436357036Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1191}
1992023-10-13T18:13:54.926ZFill test
2002023-10-13T18:13:54.929Z{"msg":"eb6a9987-15f2-4a32-b8d0-4f74fbee0394 is now active with session: 8a5325f0-0b60-43e3-8483-1bd13db363ce","v":0,"name":"crucible","level":30,"time":"2023-10-13T18:13:54.436390694Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1191}
2012023-10-13T18:13:54.933Z{"msg":"eb6a9987-15f2-4a32-b8d0-4f74fbee0394 Set Active after no repair","v":0,"name":"crucible","level":30,"time":"2023-10-13T18:13:54.436410155Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1191}
2022023-10-13T18:13:54.937Z{"msg":"Notify all downstairs, region set compare is done.","v":0,"name":"crucible","level":30,"time":"2023-10-13T18:13:54.436427685Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1191}
2032023-10-13T18:13:54.940Z{"msg":"Set check for repair","v":0,"name":"crucible","level":30,"time":"2023-10-13T18:13:54.4364443Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1191}
2042023-10-13T18:13:54.944Z{"msg":"[2] 127.0.0.1:8830 task reports connection:true","v":0,"name":"crucible","level":30,"time":"2023-10-13T18:13:54.436461833Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1191}
2052023-10-13T18:13:54.948Z{"msg":"eb6a9987-15f2-4a32-b8d0-4f74fbee0394 Active Active Active","v":0,"name":"crucible","level":30,"time":"2023-10-13T18:13:54.436479842Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1191}
2062023-10-13T18:13:54.952Z{"msg":"Set check for repair","v":0,"name":"crucible","level":30,"time":"2023-10-13T18:13:54.436496676Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1191}
2072023-10-13T18:13:54.955Z{"msg":"[0] 127.0.0.1:8810 task reports connection:true","v":0,"name":"crucible","level":30,"time":"2023-10-13T18:13:54.436514145Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1191}
2082023-10-13T18:13:54.959Z{"msg":"eb6a9987-15f2-4a32-b8d0-4f74fbee0394 Active Active Active","v":0,"name":"crucible","level":30,"time":"2023-10-13T18:13:54.43653176Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1191}
2092023-10-13T18:13:54.963Z{"msg":"Set check for repair","v":0,"name":"crucible","level":30,"time":"2023-10-13T18:13:54.436548656Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1191}
2102023-10-13T18:13:54.967Z{"msg":"[1] received reconcile message","v":0,"name":"crucible","level":30,"time":"2023-10-13T18:13:54.436565523Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1191}
2112023-10-13T18:13:54.971Z{"msg":"[1] All repairs completed, exit","v":0,"name":"crucible","level":30,"time":"2023-10-13T18:13:54.436582046Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1191}
2122023-10-13T18:13:54.975Z{"msg":"[0] received reconcile message","v":0,"name":"crucible","level":30,"time":"2023-10-13T18:13:54.436598702Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1191}
2132023-10-13T18:13:54.979Z{"msg":"[1] Starts cmd_loop","v":0,"name":"crucible","level":30,"time":"2023-10-13T18:13:54.436615437Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1191}
2142023-10-13T18:13:54.983Z{"msg":"[0] All repairs completed, exit","v":0,"name":"crucible","level":30,"time":"2023-10-13T18:13:54.436632229Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1191}
2152023-10-13T18:13:54.987Z{"msg":"[0] Starts cmd_loop","v":0,"name":"crucible","level":30,"time":"2023-10-13T18:13:54.436648818Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1191}
2162023-10-13T18:13:54.992Z{"msg":"[2] received reconcile message","v":0,"name":"crucible","level":30,"time":"2023-10-13T18:13:54.436665845Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1191}
2172023-10-13T18:13:54.996Z{"msg":"[2] All repairs completed, exit","v":0,"name":"crucible","level":30,"time":"2023-10-13T18:13:54.436682501Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1191}
2182023-10-13T18:13:55.001Z{"msg":"[2] Starts cmd_loop","v":0,"name":"crucible","level":30,"time":"2023-10-13T18:13:54.436698984Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1191}
2192023-10-13T18:13:55.004ZRead and Verify all blocks (0..50 range:false)
2202023-10-13T18:13:55.008ZWrote out file "/var/tmp/test_up/verify_file"
2212023-10-13T18:13:55.012ZCLIENT: Tests done. All submitted work has been ACK'd
2222023-10-13T18:13:55.017Z----------------------------------------------------------------
2232023-10-13T18:13:55.021Z Crucible gen:26 GIO:true work queues: Upstairs:0 downstairs:1
2242023-10-13T18:13:55.025ZGW_ID ACK DSID TYPE BLOCKS DS:0 DS:1 DS:2 REPLAY
2252023-10-13T18:13:55.029Z 3 Acked 1002 Read 50 Done Done Done false
2262023-10-13T18:13:55.033Z STATES DS:0 DS:1 DS:2 TOTAL
2272023-10-13T18:13:55.037Z New 0 0 0 0
2282023-10-13T18:13:55.040Z Sent 0 0 0 0
2292023-10-13T18:13:55.044Z Done 1 1 1 3
2302023-10-13T18:13:55.047Z Skipped 0 0 0 0
2312023-10-13T18:13:55.051Z Error 0 0 0 0
2322023-10-13T18:13:55.055ZLast Flush: 1001 1001 1001
2332023-10-13T18:13:55.059ZDownstairs last five completed: 1001 1000
2342023-10-13T18:13:55.064ZUpstairs last five completed: 3 2 1
2352023-10-13T18:13:55.072ZCLIENT: Up:0 ds:1 act:3
2362023-10-13T18:13:55.426Z{"msg":"Checking if live repair is needed","v":0,"name":"crucible","level":30,"time":"2023-10-13T18:13:55.436616644Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1191}
2372023-10-13T18:13:55.430Z{"msg":"No Live Repair required at this time","v":0,"name":"crucible","level":30,"time":"2023-10-13T18:13:55.436693809Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1191}
2382023-10-13T18:13:58.693Z----------------------------------------------------------------
2392023-10-13T18:13:58.696Z Crucible gen:26 GIO:true work queues: Upstairs:0 downstairs:0
2402023-10-13T18:13:58.700ZDownstairs last five completed: 1003 1002 1001 1000
2412023-10-13T18:13:58.703ZUpstairs last five completed: 4 3 2 1
2422023-10-13T18:13:58.706ZCLIENT: Up:0 ds:0 act:3
2432023-10-13T18:13:58.709ZCLIENT: All crucible jobs finished, exiting program
2442023-10-13T18:13:58.712ZRepair setup passed
2452023-10-13T18:13:58.715ZCopy the 8830 file
2462023-10-13T18:13:58.717Zcp -r /var/tmp/test_up/8830 /var/tmp/test_up/previous
2472023-10-13T18:13:58.742Z/var/tmp/bins/crutest repair -g 27 -q --key UOBOdL4rB9zWyXSm7tXhwALvFAnImPvzQyQvgvFRdtM= -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
2482023-10-13T18:13:58.762Z{"msg":"Upstairs starts","v":0,"name":"crucible","level":30,"time":"2023-10-13T18:13:58.772453605Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1197}
2492023-10-13T18:13:58.765Z{"msg":"Crucible Version: BuildInfo {\n version: \"0.0.1\",\n git_sha: \"a730f3b26afaf115f27149ef849470fd85caef41\",\n git_commit_timestamp: \"2023-10-13T17:42:12.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-10-13T18:13:58.772885548Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1197}
2502023-10-13T18:13:58.768Z{"msg":"Upstairs <-> Downstairs Message Version: 4","v":0,"name":"crucible","level":30,"time":"2023-10-13T18:13:58.772936802Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1197}
2512023-10-13T18:13:58.772Z{"msg":"Upstairs opts: Upstairs UUID: 8e2a8fb2-0ccc-4121-8e50-662f2c4e9b88, Targets: [127.0.0.1:8810, 127.0.0.1:8820, 127.0.0.1:8830], lossy: false, flush_timeout: None, key populated: true, cert_pem populated: false, key_pem populated: false, root_cert_pem populated: false, Control: None, read_only: false","v":0,"name":"crucible","level":30,"time":"2023-10-13T18:13:58.772965702Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1197}
2522023-10-13T18:13:58.778Z{"msg":"Crucible stats registered with UUID: 8e2a8fb2-0ccc-4121-8e50-662f2c4e9b88","v":0,"name":"crucible","level":30,"time":"2023-10-13T18:13:58.772986438Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1197}
2532023-10-13T18:13:58.781Z{"msg":"Crucible 8e2a8fb2-0ccc-4121-8e50-662f2c4e9b88 has session id: 4e8875bc-aa7f-4f93-a571-2e98553ef400","v":0,"name":"crucible","level":30,"time":"2023-10-13T18:13:58.773007369Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1197}
2542023-10-13T18:13:58.785ZCrucible runtime is spawned
2552023-10-13T18:13:58.788ZThe guest has requested activation with gen:27
2562023-10-13T18:13:58.792Z{"msg":"up_listen starts","v":0,"name":"crucible","level":30,"time":"2023-10-13T18:13:58.773411002Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1197,"task":"up_listen"}
2572023-10-13T18:13:58.796Z{"msg":"Wait for all three downstairs to come online","v":0,"name":"crucible","level":30,"time":"2023-10-13T18:13:58.773652684Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1197}
2582023-10-13T18:13:58.799Z{"msg":"Flush timeout: 0.5","v":0,"name":"crucible","level":30,"time":"2023-10-13T18:13:58.77370062Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1197}
2592023-10-13T18:13:58.803Z{"msg":"[2] connecting to 127.0.0.1:8830","v":0,"name":"crucible","level":30,"time":"2023-10-13T18:13:58.773748904Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1197,"looper":"2"}
2602023-10-13T18:13:58.806Z{"msg":"[0] connecting to 127.0.0.1:8810","v":0,"name":"crucible","level":30,"time":"2023-10-13T18:13:58.773998133Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1197,"looper":"0"}
2612023-10-13T18:13:58.810Z{"msg":"[2] 8e2a8fb2-0ccc-4121-8e50-662f2c4e9b88 looper connected","v":0,"name":"crucible","level":30,"time":"2023-10-13T18:13:58.774084389Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1197,"looper":"2"}
2622023-10-13T18:13:58.813Z{"msg":"[1] connecting to 127.0.0.1:8820","v":0,"name":"crucible","level":30,"time":"2023-10-13T18:13:58.774142667Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1197,"looper":"1"}
2632023-10-13T18:13:58.817Z{"msg":"[0] 8e2a8fb2-0ccc-4121-8e50-662f2c4e9b88 looper connected","v":0,"name":"crucible","level":30,"time":"2023-10-13T18:13:58.774199457Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1197,"looper":"0"}
2642023-10-13T18:13:58.821Z{"msg":"[1] 8e2a8fb2-0ccc-4121-8e50-662f2c4e9b88 looper connected","v":0,"name":"crucible","level":30,"time":"2023-10-13T18:13:58.774370403Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1197,"looper":"1"}
2652023-10-13T18:13:58.825Z{"msg":"8e2a8fb2-0ccc-4121-8e50-662f2c4e9b88 active request set","v":0,"name":"crucible","level":30,"time":"2023-10-13T18:13:58.774753637Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1197}
2662023-10-13T18:13:58.831Z{"msg":"Set desired generation to :27","v":0,"name":"crucible","level":30,"time":"2023-10-13T18:13:58.774809897Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1197}
2672023-10-13T18:13:58.834Z{"msg":"[2] Proc runs for 127.0.0.1:8830 in state New","v":0,"name":"crucible","level":30,"time":"2023-10-13T18:13:58.775030798Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1197}
2682023-10-13T18:13:58.838Z{"msg":"[0] Proc runs for 127.0.0.1:8810 in state New","v":0,"name":"crucible","level":30,"time":"2023-10-13T18:13:58.775387263Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1197}
2692023-10-13T18:13:58.842Z{"msg":"[1] Proc runs for 127.0.0.1:8820 in state New","v":0,"name":"crucible","level":30,"time":"2023-10-13T18:13:58.775522975Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1197}
2702023-10-13T18:13:58.845Z{"msg":"[2] 8e2a8fb2-0ccc-4121-8e50-662f2c4e9b88 (4f6ac5fe-c1f4-4582-9b62-7b728d8acad6) New New New ds_transition to WaitActive","v":0,"name":"crucible","level":30,"time":"2023-10-13T18:13:58.775635027Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1197}
2712023-10-13T18:13:58.849Z{"msg":"[2] Transition from New to WaitActive","v":0,"name":"crucible","level":30,"time":"2023-10-13T18:13:58.775742969Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1197}
2722023-10-13T18:13:58.853Z{"msg":"[2] client is_active_req TRUE, promote! session 4f6ac5fe-c1f4-4582-9b62-7b728d8acad6","v":0,"name":"crucible","level":30,"time":"2023-10-13T18:13:58.775836964Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1197}
2732023-10-13T18:13:58.856Z{"msg":"[0] 8e2a8fb2-0ccc-4121-8e50-662f2c4e9b88 (4f6ac5fe-c1f4-4582-9b62-7b728d8acad6) New New WaitActive ds_transition to WaitActive","v":0,"name":"crucible","level":30,"time":"2023-10-13T18:13:58.775891399Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1197}
2742023-10-13T18:13:58.859Z{"msg":"[0] Transition from New to WaitActive","v":0,"name":"crucible","level":30,"time":"2023-10-13T18:13:58.775985795Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1197}
2752023-10-13T18:13:58.862Z{"msg":"[0] client is_active_req TRUE, promote! session 4f6ac5fe-c1f4-4582-9b62-7b728d8acad6","v":0,"name":"crucible","level":30,"time":"2023-10-13T18:13:58.776030103Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1197}
2762023-10-13T18:13:58.866Z{"msg":"[1] 8e2a8fb2-0ccc-4121-8e50-662f2c4e9b88 (4f6ac5fe-c1f4-4582-9b62-7b728d8acad6) WaitActive New WaitActive ds_transition to WaitActive","v":0,"name":"crucible","level":30,"time":"2023-10-13T18:13:58.776071379Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1197}
2772023-10-13T18:13:58.869Z{"msg":"[1] Transition from New to WaitActive","v":0,"name":"crucible","level":30,"time":"2023-10-13T18:13:58.776154992Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1197}
2782023-10-13T18:13:58.872Z{"msg":"[1] client is_active_req TRUE, promote! session 4f6ac5fe-c1f4-4582-9b62-7b728d8acad6","v":0,"name":"crucible","level":30,"time":"2023-10-13T18:13:58.776225987Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1197}
2792023-10-13T18:13:58.876Z{"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-10-13T18:13:58.776303794Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1197}
2802023-10-13T18:13:58.879Z{"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-10-13T18:13:58.776353727Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1197}
2812023-10-13T18:13:58.883Z{"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-10-13T18:13:58.776378921Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1197}
2822023-10-13T18:13:58.886Z{"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-10-13T18:13:58.7764322Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1197}
2832023-10-13T18:13:58.891Z{"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-10-13T18:13:58.776455282Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1197}
2842023-10-13T18:13:58.896Z{"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-10-13T18:13:58.776514526Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1197}
2852023-10-13T18:13:58.901Z{"msg":"8e2a8fb2-0ccc-4121-8e50-662f2c4e9b88 WaitActive WaitActive WaitActive","v":0,"name":"crucible","level":30,"time":"2023-10-13T18:13:58.776602979Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1197}
2862023-10-13T18:13:58.904Z{"msg":"8e2a8fb2-0ccc-4121-8e50-662f2c4e9b88 WaitActive WaitActive WaitActive","v":0,"name":"crucible","level":30,"time":"2023-10-13T18:13:58.776674211Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1197}
2872023-10-13T18:13:58.907Z{"msg":"8e2a8fb2-0ccc-4121-8e50-662f2c4e9b88 WaitActive WaitActive WaitActive","v":0,"name":"crucible","level":30,"time":"2023-10-13T18:13:58.776716449Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1197}
2882023-10-13T18:13:58.911Z{"msg":"[2] 8e2a8fb2-0ccc-4121-8e50-662f2c4e9b88 (4f6ac5fe-c1f4-4582-9b62-7b728d8acad6) WaitActive WaitActive WaitActive ds_transition to WaitQuorum","v":0,"name":"crucible","level":30,"time":"2023-10-13T18:13:58.777003795Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1197}
2892023-10-13T18:13:58.914Z{"msg":"[2] Transition from WaitActive to WaitQuorum","v":0,"name":"crucible","level":30,"time":"2023-10-13T18:13:58.777133859Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1197}
2902023-10-13T18:13:58.946Z{"msg":"[2] new RM replaced this: None","v":0,"name":"crucible","level":40,"time":"2023-10-13T18:13:58.777178301Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1197}
2912023-10-13T18:13:58.955Z{"msg":"[2] Starts reconcile loop","v":0,"name":"crucible","level":30,"time":"2023-10-13T18:13:58.777217239Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1197}
2922023-10-13T18:13:58.959Z{"msg":"[2] 127.0.0.1:8830 task reports connection:true","v":0,"name":"crucible","level":30,"time":"2023-10-13T18:13:58.777256657Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1197}
2932023-10-13T18:13:58.963Z{"msg":"8e2a8fb2-0ccc-4121-8e50-662f2c4e9b88 WaitActive WaitActive WaitQuorum","v":0,"name":"crucible","level":30,"time":"2023-10-13T18:13:58.77729618Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1197}
2942023-10-13T18:13:58.966Z{"msg":"Waiting for 2 more clients to be ready","v":0,"name":"crucible","level":30,"time":"2023-10-13T18:13:58.77733926Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1197}
2952023-10-13T18:13:58.970Z{"msg":"Set check for repair","v":0,"name":"crucible","level":30,"time":"2023-10-13T18:13:58.777391716Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1197}
2962023-10-13T18:13:58.974Z{"msg":"[1] 8e2a8fb2-0ccc-4121-8e50-662f2c4e9b88 (4f6ac5fe-c1f4-4582-9b62-7b728d8acad6) WaitActive WaitActive WaitQuorum ds_transition to WaitQuorum","v":0,"name":"crucible","level":30,"time":"2023-10-13T18:13:58.777454414Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1197}
2972023-10-13T18:13:58.978Z{"msg":"[1] Transition from WaitActive to WaitQuorum","v":0,"name":"crucible","level":30,"time":"2023-10-13T18:13:58.777477896Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1197}
2982023-10-13T18:13:58.983Z{"msg":"[1] new RM replaced this: None","v":0,"name":"crucible","level":40,"time":"2023-10-13T18:13:58.777496808Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1197}
2992023-10-13T18:13:58.986Z{"msg":"[1] Starts reconcile loop","v":0,"name":"crucible","level":30,"time":"2023-10-13T18:13:58.777534592Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1197}
3002023-10-13T18:13:58.990Z{"msg":"[1] 127.0.0.1:8820 task reports connection:true","v":0,"name":"crucible","level":30,"time":"2023-10-13T18:13:58.777573753Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1197}
3012023-10-13T18:13:58.993Z{"msg":"8e2a8fb2-0ccc-4121-8e50-662f2c4e9b88 WaitActive WaitQuorum WaitQuorum","v":0,"name":"crucible","level":30,"time":"2023-10-13T18:13:58.777613141Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1197}
3022023-10-13T18:13:58.997Z{"msg":"[0] 8e2a8fb2-0ccc-4121-8e50-662f2c4e9b88 (4f6ac5fe-c1f4-4582-9b62-7b728d8acad6) WaitActive WaitQuorum WaitQuorum ds_transition to WaitQuorum","v":0,"name":"crucible","level":30,"time":"2023-10-13T18:13:58.777655021Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1197}
3032023-10-13T18:13:59.001Z{"msg":"[0] Transition from WaitActive to WaitQuorum","v":0,"name":"crucible","level":30,"time":"2023-10-13T18:13:58.777694143Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1197}
3042023-10-13T18:13:59.006Z{"msg":"[0] new RM replaced this: None","v":0,"name":"crucible","level":40The guest has finished waiting for activation with:27
3052023-10-13T18:13:59.009ZWait for a query_work_queue command to finish before sending IO
3062023-10-13T18:13:59.013Z,"time":"2023-10-13T18:13:58.777733388Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1197}
3072023-10-13T18:13:59.017Z{"msg":"[0]R flush_numbers: [1948, 1948, 1948, 1948, 1948]","v":0,"name":"crucible","level":30,"time":"2023-10-13T18:13:58.777862418Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1197}
3082023-10-13T18:13:59.036Z{"msg":"[0]R generation: [26, 26, 26, 26, 26]","v":0,"name":"crucible","level":30,"time":"2023-10-13T18:13:58.777904086Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1197}
3092023-10-13T18:13:59.040Z{"msg":"[0]R dirty: [false, false, false, false, false]","v":0,"name":"crucible","level":30,"time":"2023-10-13T18:13:58.77796725Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1197}
3102023-10-13T18:13:59.043Z{"msg":"[1]R flush_numbers: [1948, 1948, 1948, 1948, 1948]","v":0,"name":"crucible","level":30,"time":"2023-10-13T18:13:58.777987737Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1197}
3112023-10-13T18:13:59.048Z{"msg":"[1]R generation: [26, 26, 26, 26, 26]","v":0,"name":"crucible","level":30,"time":"2023-10-13T18:13:58.778005349Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1197}
3122023-10-13T18:13:59.052Z{"msg":"[1]R dirty: [false, false, false, false, false]","v":0,"name":"crucible","level":30,"time":"2023-10-13T18:13:58.778022918Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1197}
3132023-10-13T18:13:59.057Z{"msg":"[2]R flush_numbers: [1948, 1948, 1948, 1948, 1948]","v":0,"name":"crucible","level":30,"time":"2023-10-13T18:13:58.778061252Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1197}
3142023-10-13T18:13:59.070Z{"msg":"[2]R generation: [26, 26, 26, 26, 26]","v":0,"name":"crucible","level":30,"time":"2023-10-13T18:13:58.778081023Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1197}
3152023-10-13T18:13:59.074Z{"msg":"[2]R dirty: [false, false, false, false, false]","v":0,"name":"crucible","level":30,"time":"2023-10-13T18:13:58.778135675Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1197}
3162023-10-13T18:13:59.078Z{"msg":"Max found gen is 27","v":0,"name":"crucible","level":30,"time":"2023-10-13T18:13:58.778154477Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1197}
3172023-10-13T18:13:59.083Z{"msg":"Generation requested: 27 >= found:27","v":0,"name":"crucible","level":30,"time":"2023-10-13T18:13:58.778171725Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1197}
3182023-10-13T18:13:59.086Z{"msg":"Next flush: 1949","v":0,"name":"crucible","level":30,"time":"2023-10-13T18:13:58.778188186Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1197}
3192023-10-13T18:13:59.091Z{"msg":"All extents match","v":0,"name":"crucible","level":30,"time":"2023-10-13T18:13:58.778204441Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1197}
3202023-10-13T18:13:59.102Z{"msg":"No downstairs repair required","v":0,"name":"crucible","level":30,"time":"2023-10-13T18:13:58.778221218Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1197}
3212023-10-13T18:13:59.106Z{"msg":"[0] Starts reconcile loop","v":0,"name":"crucible","level":30,"time":"2023-10-13T18:13:58.778237803Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1197}
3222023-10-13T18:13:59.112Z{"msg":"No initial repair work was required","v":0,"name":"crucible","level":30,"time":"2023-10-13T18:13:58.77825469Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1197}
3232023-10-13T18:13:59.116Z{"msg":"Set Downstairs and Upstairs active","v":0,"name":"crucible","level":30,"time":"2023-10-13T18:13:58.778271773Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1197}
3242023-10-13T18:13:59.120Z{"msg":"8e2a8fb2-0ccc-4121-8e50-662f2c4e9b88 is now active with session: 4f6ac5fe-c1f4-4582-9b62-7b728d8acad6","v":0,"name":"crucible","level":30,"time":"2023-10-13T18:13:58.778290768Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1197}
3252023-10-13T18:13:59.129Z{"msg":"8e2a8fb2-0ccc-4121-8e50-662f2c4e9b88 Set Active after no repair","v":0,"name":"crucible","level":30,"time":"2023-10-13T18:13:58.778308944Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1197}
3262023-10-13T18:13:59.135Z{"msg":"Notify all downstairs, region set compare is done.","v":0,"name":"crucible","level":30,"time":"2023-10-13T18:13:58.778326559Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1197}
3272023-10-13T18:13:59.139Z{"msg":"Set check for repair","v":0,"name":"crucible","level":30,"time":"2023-10-13T18:13:58.778343348Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1197}
3282023-10-13T18:13:59.144Z{"msg":"[0] 127.0.0.1:8810 task reports connection:true","v":0,"name":"crucible","level":30,"time":"2023-10-13T18:13:58.778360961Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1197}
3292023-10-13T18:13:59.148Z{"msg":"8e2a8fb2-0ccc-4121-8e50-662f2c4e9b88 Active Active Active","v":0,"name":"crucible","level":30,"time":"2023-10-13T18:13:58.778378786Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1197}
3302023-10-13T18:13:59.151Z{"msg":"Set check for repair","v":0,"name":"crucible","level":30,"time":"2023-10-13T18:13:58.778395543Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1197}
3312023-10-13T18:13:59.169Z{"msg":"[1] received reconcile message","v":0,"name":"crucible","level":30,"time":"2023-10-13T18:13:58.778412704Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1197}
3322023-10-13T18:13:59.174Z{"msg":"[2] received reconcile message","v":0,"name":"crucible","level":30,"time":"2023-10-13T18:13:58.77842949Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1197}
3332023-10-13T18:13:59.185Z{"msg":"[0] received reconcile message","v":0,"name":"crucible","level":30,"time":"2023-10-13T18:13:58.77844655Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1197}
3342023-10-13T18:13:59.189Z{"msg":"[1] All repairs completed, exit","v":0,"name":"crucible","level":30,"time":"2023-10-13T18:13:58.778463537Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1197}
3352023-10-13T18:13:59.194Z{"msg":"[1] Starts cmd_loop","v":0,"name":"crucible","level":30,"time":"2023-10-13T18:13:58.778480057Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1197}
3362023-10-13T18:13:59.198Z{"msg":"[2] All repairs completed, exit","v":0,"name":"crucible","level":30,"time":"2023-10-13T18:13:58.778497193Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1197}
3372023-10-13T18:13:59.204Z{"msg":"[2] Starts cmd_loop","v":0,"name":"crucible","level":30,"time":"2023-10-13T18:13:58.778513647Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1197}
3382023-10-13T18:13:59.208Z{"msg":"[0] All repairs completed, exit","v":0,"name":"crucible","level":30,"time":"2023-10-13T18:13:58.778530687Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1197}
3392023-10-13T18:13:59.214Z{"msg":"[0] Starts cmd_loop","v":0,"name":"crucible","level":30,"time":"2023-10-13T18:13:58.778547406Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1197}
3402023-10-13T18:13:59.219ZRegion: es:10 ec:5 bs:4096 ts:204800 tb:50 max_io:50 or 204800
3412023-10-13T18:13:59.223ZLoading write count information from file "/var/tmp/test_up/verify_file"
3422023-10-13T18:13:59.227ZRun Repair workload
3432023-10-13T18:13:59.230Z01/10 Write block 12 len 40960 data: 2 2 2 2 2 2 2 2 2 2
3442023-10-13T18:13:59.234Z02/10 Read block 28 len 28672
3452023-10-13T18:13:59.239Z03/10 Flush
3462023-10-13T18:13:59.242Z04/10 Flush
3472023-10-13T18:13:59.248Z05/10 Write block 14 len 32768 data: 3 3 3 3 3 3 3 3
3482023-10-13T18:13:59.253Z06/10 Write block 36 len 20480 data: 2 2 2 2 2
3492023-10-13T18:13:59.256Z07/10 Write block 15 len 4096 data: 4
3502023-10-13T18:13:59.262Z08/10 Write block 2 len 28672 data: 2 2 2 2 2 2 2
3512023-10-13T18:13:59.265Z09/10 Write block 5 len 4096 data: 3
3522023-10-13T18:13:59.284Z10/10 Read block 9 len 32768
3532023-10-13T18:13:59.288Z----------------------------------------------------------------
3542023-10-13T18:13:59.293Z Crucible gen:27 GIO:true work queues: Upstairs:0 downstairs:6
3552023-10-13T18:13:59.297ZGW_ID ACK DSID TYPE BLOCKS DS:0 DS:1 DS:2 REPLAY
3562023-10-13T18:13:59.299Z 5 Acked 1004 Write 8 Done Done Done false
3572023-10-13T18:13:59.310Z 6 Acked 1005 Write 5 Done Done Done false
3582023-10-13T18:13:59.313Z 7 Acked 1006 Write 1 Done Done Done false
3592023-10-13T18:13:59.318Z 8 Acked 1007 Write 7 Done Done Done false
3602023-10-13T18:13:59.322Z 9 Acked 1008 Write 1 Done Done Done false
3612023-10-13T18:13:59.326Z 10 Acked 1009 Read 8 Done Sent Sent false
3622023-10-13T18:13:59.329Z STATES DS:0 DS:1 DS:2 TOTAL
3632023-10-13T18:13:59.332Z New 0 0 0 0
3642023-10-13T18:13:59.336Z Sent 0 1 1 2
3652023-10-13T18:13:59.344Z Done 6 5 5 16
3662023-10-13T18:13:59.347Z Skipped 0 0 0 0
3672023-10-13T18:13:59.352Z Error 0 0 0 0
3682023-10-13T18:13:59.356ZLast Flush: 1003 1003 1003
3692023-10-13T18:13:59.359ZDownstairs last five completed: 1003 1002 1001 1000
3702023-10-13T18:13:59.363ZUpstairs last five completed: 10 9 8 7 6 5
3712023-10-13T18:13:59.366ZWrote out file "/var/tmp/test_up/verify_file"
3722023-10-13T18:13:59.370Z{"msg":"127.0.0.1:8830: proc: channel closed","v":0,"name":"crucible","level":50,"time":"2023-10-13T18:13:58.877164989Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1197,"looper":"2"}
3732023-10-13T18:13:59.374Z{"msg":"[1] pm_task rx.recv() is None","v":0,"name":"crucible","level":40,"time":"2023-10-13T18:13:58.885381197Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1197}
3742023-10-13T18:13:59.377ZRepair part 1 passed
3752023-10-13T18:13:59.380Z
3762023-10-13T18:13:59.384ZKill the current downstairs
3772023-10-13T18:13:59.388Zrm -rf /var/tmp/test_up/8830
3782023-10-13T18:13:59.392ZNow put back the original so we have a mismatch
3792023-10-13T18:13:59.395Zmv /var/tmp/test_up/previous /var/tmp/test_up/8830
3802023-10-13T18:13:59.398ZRestart downstairs with old directory
3812023-10-13T18:13:59.402Z/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
3822023-10-13T18:13:59.406ZEXT BLOCKS GEN0 GEN1 GEN2 FL0 FL1 FL2 D0 D1 D2 DIFF
3832023-10-13T18:13:59.411Z 0 000-009 26 26 26 1948 1948 1948 T T F <---
3842023-10-13T18:13:59.414Z 1 010-019 27 27 26 1949 1949 1948 T T F <---
3852023-10-13T18:13:59.417Z 2 020-029 27 27 26 1949 1949 1948 T T F <---
3862023-10-13T18:13:59.421Z 3 030-039 26 26 26 1948 1948 1948 T T F <---
3872023-10-13T18:13:59.424Z 4 040-049 26 26 26 1948 1948 1948 T T F <---
3882023-10-13T18:13:59.427ZMax gen: 27, Max flush: 1949
3892023-10-13T18:13:59.431ZError: Difference in extent metadata found!
3902023-10-13T18:13:59.434Zdump test found error as expected
3912023-10-13T18:13:59.437Z
3922023-10-13T18:13:59.440Z
3932023-10-13T18:13:59.444Z/var/tmp/bins/crutest deactivate --range -g 28 -q --key UOBOdL4rB9zWyXSm7tXhwALvFAnImPvzQyQvgvFRdtM= -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
3942023-10-13T18:13:59.447Z{"msg":"Upstairs starts","v":0,"name":"crucible","level":30,"time":"2023-10-13T18:13:59.289834352Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1204}
3952023-10-13T18:13:59.450Z{"msg":"Crucible Version: BuildInfo {\n version: \"0.0.1\",\n git_sha: \"a730f3b26afaf115f27149ef849470fd85caef41\",\n git_commit_timestamp: \"2023-10-13T17:42:12.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-10-13T18:13:59.290278521Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1204}
3962023-10-13T18:13:59.454Z{"msg":"Upstairs <-> Downstairs Message Version: 4","v":0,"name":"crucible","level":30,"time":"2023-10-13T18:13:59.290330705Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1204}
3972023-10-13T18:13:59.458Z{"msg":"Upstairs opts: Upstairs UUID: f231106b-141e-4f7e-aae5-1762578fb505, Targets: [127.0.0.1:8810, 127.0.0.1:8820, 127.0.0.1:8830], lossy: false, flush_timeout: None, key populated: true, cert_pem populated: false, key_pem populated: false, root_cert_pem populated: false, Control: None, read_only: false","v":0,"name":"crucible","level":30,"time":"2023-10-13T18:13:59.290380038Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1204}
3982023-10-13T18:13:59.461Z{"msg":"Crucible stats registered with UUID: f231106b-141e-4f7e-aae5-1762578fb505","v":0,"name":"crucible","level":30,"time":"2023-10-13T18:13:59.29042251Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1204}
3992023-10-13T18:13:59.465Z{"msg":"Crucible f231106b-141e-4f7e-aae5-1762578fb505 has session id: 3f7a2995-b6c5-4f83-a6f2-cce4fedfe6f7","v":0,"name":"crucible","level":30,"time":"2023-10-13T18:13:59.290465191Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1204}
4002023-10-13T18:13:59.469ZCrucible runtime is spawned
4012023-10-13T18:13:59.474Z{"msg":"up_listen starts","v":0,"name":"crucible","level":30,"time":"2023-10-13T18:13:59.290825851Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1204,"task":"up_listen"}
4022023-10-13T18:13:59.477Z{"The guest has requested activation with gen:28
4032023-10-13T18:13:59.483Zmsg":"Wait for all three downstairs to come online","v":0,"name":"crucible","level":30,"time":"2023-10-13T18:13:59.291043894Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1204}
4042023-10-13T18:13:59.488Z{"msg":"Flush timeout: 0.5","v":0,"name":"crucible","level":30,"time":"2023-10-13T18:13:59.291116118Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1204}
4052023-10-13T18:13:59.491Z{"msg":"[0] connecting to 127.0.0.1:8810","v":0,"name":"crucible","level":30,"time":"2023-10-13T18:13:59.291163848Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1204,"looper":"0"}
4062023-10-13T18:13:59.498Z{"msg":"[0] f231106b-141e-4f7e-aae5-1762578fb505 looper connected","v":0,"name":"crucible","level":30,"time":"2023-10-13T18:13:59.291489819Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1204,"looper":"0"}
4072023-10-13T18:13:59.501Z{"msg":"[2] connecting to 127.0.0.1:8830","v":0,"name":"crucible","level":30,"time":"2023-10-13T18:13:59.291704673Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1204,"looper":"2"}
4082023-10-13T18:13:59.504Z{"msg":"[1] connecting to 127.0.0.1:8820","v":0,"name":"crucible","level":30,"time":"2023-10-13T18:13:59.291770061Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1204,"looper":"1"}
4092023-10-13T18:13:59.509Z{"msg":"[1] f231106b-141e-4f7e-aae5-1762578fb505 looper connected","v":0,"name":"crucible","level":30,"time":"2023-10-13T18:13:59.29192938Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1204,"looper":"1"}
4102023-10-13T18:13:59.513Z{"msg":"f231106b-141e-4f7e-aae5-1762578fb505 active request set","v":0,"name":"crucible","level":30,"time":"2023-10-13T18:13:59.29221156Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1204}
4112023-10-13T18:13:59.517Z{"msg":"Set desired generation to :28","v":0,"name":"crucible","level":30,"time":"2023-10-13T18:13:59.292261594Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1204}
4122023-10-13T18:13:59.521Z{"msg":"[0] Proc runs for 127.0.0.1:8810 in state New","v":0,"name":"crucible","level":30,"time":"2023-10-13T18:13:59.292303441Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1204}
4132023-10-13T18:13:59.524Z{"msg":"[1] Proc runs for 127.0.0.1:8820 in state New","v":0,"name":"crucible","level":30,"time":"2023-10-13T18:13:59.292668897Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1204}
4142023-10-13T18:13:59.528Z{"msg":"[1] f231106b-141e-4f7e-aae5-1762578fb505 (ab49641b-96ea-4185-9698-f085775a74ab) New New New ds_transition to WaitActive","v":0,"name":"crucible","level":30,"time":"2023-10-13T18:13:59.293087661Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1204}
4152023-10-13T18:13:59.532Z{"msg":"[1] Transition from New to WaitActive","v":0,"name":"crucible","level":30,"time":"2023-10-13T18:13:59.293145443Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1204}
4162023-10-13T18:13:59.535Z{"msg":"[1] client is_active_req TRUE, promote! session ab49641b-96ea-4185-9698-f085775a74ab","v":0,"name":"crucible","level":30,"time":"2023-10-13T18:13:59.293188684Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1204}
4172023-10-13T18:13:59.540Z{"msg":"[0] f231106b-141e-4f7e-aae5-1762578fb505 (ab49641b-96ea-4185-9698-f085775a74ab) New WaitActive New ds_transition to WaitActive","v":0,"name":"crucible","level":30,"time":"2023-10-13T18:13:59.2932644Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1204}
4182023-10-13T18:13:59.544Z{"msg":"[0] Transition from New to WaitActive","v":0,"name":"crucible","level":30,"time":"2023-10-13T18:13:59.293285304Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1204}
4192023-10-13T18:13:59.547Z{"msg":"[0] client is_active_req TRUE, promote! session ab49641b-96ea-4185-9698-f085775a74ab","v":0,"name":"crucible","level":30,"time":"2023-10-13T18:13:59.293320592Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1204}
4202023-10-13T18:13:59.551Z{"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-10-13T18:13:59.293726694Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1204}
4212023-10-13T18:13:59.555Z{"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-10-13T18:13:59.293764494Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1204}
4222023-10-13T18:13:59.559Z{"msg":"f231106b-141e-4f7e-aae5-1762578fb505 WaitActive WaitActive New","v":0,"name":"crucible","level":30,"time":"2023-10-13T18:13:59.293803789Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1204}
4232023-10-13T18:13:59.562Z{"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-10-13T18:13:59.293913016Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1204}
4242023-10-13T18:13:59.566Z{"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-10-13T18:13:59.293942664Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1204}
4252023-10-13T18:13:59.569Z{"msg":"f231106b-141e-4f7e-aae5-1762578fb505 WaitActive WaitActive New","v":0,"name":"crucible","level":30,"time":"2023-10-13T18:13:59.293961536Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1204}
4262023-10-13T18:13:59.573Z{"msg":"[1] f231106b-141e-4f7e-aae5-1762578fb505 (ab49641b-96ea-4185-9698-f085775a74ab) WaitActive WaitActive New ds_transition to WaitQuorum","v":0,"name":"crucible","level":30,"time":"2023-10-13T18:13:59.294363302Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1204}
4272023-10-13T18:13:59.577Z{"msg":"[1] Transition from WaitActive to WaitQuorum","v":0,"name":"crucible","level":30,"time":"2023-10-13T18:13:59.294394127Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1204}
4282023-10-13T18:13:59.581Z{"msg":"[1] new RM replaced this: None","v":0,"name":"crucible","level":40,"time":"2023-10-13T18:13:59.294411831Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1204}
4292023-10-13T18:13:59.584Z{"msg":"[1] Starts reconcile loop","v":0,"name":"crucible","level":30,"time":"2023-10-13T18:13:59.294428556Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1204}
4302023-10-13T18:13:59.587Z{"msg":"[1] 127.0.0.1:8820 task reports connection:true","v":0,"name":"crucible","level":30,"time":"2023-10-13T18:13:59.29446397Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1204}
4312023-10-13T18:13:59.591Z{"msg":"f231106b-141e-4f7e-aae5-1762578fb505 WaitActive WaitQuorum New","v":0,"name":"crucible","level":30,"time":"2023-10-13T18:13:59.294483413Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1204}
4322023-10-13T18:13:59.594Z{"msg":"Waiting for 2 more clients to be ready","v":0,"name":"crucible","level":30,"time":"2023-10-13T18:13:59.294511632Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1204}
4332023-10-13T18:13:59.598Z{"msg":"Set check for repair","v":0,"name":"crucible","level":30,"time":"2023-10-13T18:13:59.294529066Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1204}
4342023-10-13T18:13:59.602Z{"msg":"[0] f231106b-141e-4f7e-aae5-1762578fb505 (ab49641b-96ea-4185-9698-f085775a74ab) WaitActive WaitQuorum New ds_transition to WaitQuorum","v":0,"name":"crucible","level":30,"time":"2023-10-13T18:13:59.294652384Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1204}
4352023-10-13T18:13:59.606Z{"msg":"[0] Transition from WaitActive to WaitQuorum","v":0,"name":"crucible","level":30,"time":"2023-10-13T18:13:59.294676714Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1204}
4362023-10-13T18:13:59.609Z{"msg":"[0] new RM replaced this: None","v":0,"name":"crucible","level":40,"time":"2023-10-13T18:13:59.294694068Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1204}
4372023-10-13T18:13:59.613Z{"msg":"[0] Starts reconcile loop","v":0,"name":"crucible","level":30,"time":"2023-10-13T18:13:59.294711115Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1204}
4382023-10-13T18:13:59.617Z{"msg":"[0] 127.0.0.1:8810 task reports connection:true","v":0,"name":"crucible","level":30,"time":"2023-10-13T18:13:59.294729709Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1204}
4392023-10-13T18:13:59.620Z{"msg":"f231106b-141e-4f7e-aae5-1762578fb505 WaitQuorum WaitQuorum New","v":0,"name":"crucible","level":30,"time":"2023-10-13T18:13:59.294747391Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1204}
4402023-10-13T18:13:59.624Z{"msg":"Waiting for 1 more clients to be ready","v":0,"name":"crucible","level":30,"time":"2023-10-13T18:13:59.2947648Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1204}
4412023-10-13T18:13:59.628Z{"msg":"Set check for repair","v":0,"name":"crucible","level":30,"time":"2023-10-13T18:13:59.294781857Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1204}
4422023-10-13T18:14:00.285Z{"msg":"Checking if live repair is needed","v":0,"name":"crucible","level":30,"time":"2023-10-13T18:14:00.295553497Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1204}
4432023-10-13T18:14:04.291Z{"msg":"[0] Received Imok","v":0,"name":"crucible","level":30,"time":"2023-10-13T18:14:04.296451935Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1204}
4442023-10-13T18:14:04.301Z{"msg":"[1] Received Imok","v":0,"name":"crucible","level":30,"time":"2023-10-13T18:14:04.296531885Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1204}
4452023-10-13T18:14:09.288Z{"msg":"[1] Received Imok","v":0,"name":"crucible","level":30,"time":"2023-10-13T18:14:09.29864451Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1204}
4462023-10-13T18:14:09.291Z{"msg":"[0] Received Imok","v":0,"name":"crucible","level":30,"time":"2023-10-13T18:14:09.298724068Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1204}
4472023-10-13T18:14:09.295Z{"msg":"[2] connecting to 127.0.0.1:8830","v":0,"name":"crucible","level":30,"time":"2023-10-13T18:14:09.307024102Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1204,"looper":"2"}
4482023-10-13T18:14:13.301Z{"msg":"[2] f231106b-141e-4f7e-aae5-1762578fb505 looper connected","v":0,"name":"crucible","level":30,"time":"2023-10-13T18:14:13.311086999Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1204,"looper":"2"}
4492023-10-13T18:14:13.304Z{"msg":"[2] Proc runs for 127.0.0.1:8830 in state New","v":0,"name":"crucible","level":30,"time":"2023-10-13T18:14:13.311167578Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1204}
4502023-10-13T18:14:13.309Z{"msg":"[2] f231106b-141e-4f7e-aae5-1762578fb505 (ab49641b-96ea-4185-9698-f085775a74ab) WaitQuorum WaitQuorum New ds_transition to WaitActive","v":0,"name":"crucible","level":30,"time":"2023-10-13T18:14:13.311878664Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1204}
4512023-10-13T18:14:13.312Z{"msg":"[2] Transition from New to WaitActive","v":0,"name":"crucible","level":30,"time":"2023-10-13T18:14:13.311928557Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1204}
4522023-10-13T18:14:13.316Z{"msg":"[2] client is_active_req TRUE, promote! session ab49641b-96ea-4185-9698-f085775a74ab","v":0,"name":"crucible","level":30,"time":"2023-10-13T18:14:13.311950629Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1204}
4532023-10-13T18:14:13.320Z{"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-10-13T18:14:13.312502736Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1204}
4542023-10-13T18:14:13.324Z{"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-10-13T18:14:13.31255985Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1204}
4552023-10-13T18:14:13.328Z{"msg":"f231106b-141e-4f7e-aae5-1762578fb505 WaitQuorum WaitQuorum WaitActive","v":0,"name":"crucible","level":30,"time":"2023-10-13T18:14:13.312583673Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1204}
4562023-10-13T18:14:13.332Z{"msg":"[2] f231106b-141e-4f7e-aae5-1762578fb505 (ab49641b-96ea-4185-9698-f085775a74ab) WaitQuorum WaitQuorum WaitActive ds_transition to WaitQuorum","v":0,"name":"crucible","level":30,"time":"2023-10-13T18:14:13.313160452Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1204}
4572023-10-13T18:14:13.336Z{"msg":"[2] Transition from WaitActive to WaitQuorum","v":0,"name":"crucible","level":30,"time":"2023-10-13T18:14:13.31320857Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1204}
4582023-10-13T18:14:13.340Z{"msg":"[2] new RM replaced this: None","v":0,"name":"crucible","level":40,"time":"2023-10-13T18:14:13.313229031Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1204}
4592023-10-13T18:14:13.343Z{"msg":"[2] Starts reconcile loop","v":0,"name":"crucible","level":30,"time":"2023-10-13T18:14:13.313273373Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1204}
4602023-10-13T18:14:13.347Z{"msg":"[2] 127.0.0.1:8830 task reports connection:true","v":0,"name":"crucible","level":30,"time":"2023-10-13T18:14:13.313334101Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1204}
4612023-10-13T18:14:13.350Z{"msg":"f231106b-141e-4f7e-aae5-1762578fb505 WaitQuorum WaitQuorum WaitQuorum","v":0,"name":"crucible","level":30,"time":"2023-10-13T18:14:13.31337865Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1204}
4622023-10-13T18:14:13.354Z{"msg":"[0]R flush_numbers: [1948, 1949, 1949, 1948, 1948]","v":0,"name":"crucible","level":30,"time":"2023-10-13T18:14:13.313419254Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1204}
4632023-10-13T18:14:13.357Z{"msg":"[0]R generation: [26, 27, 27, 26, 26]","v":0,"name":"crucible","level":30,"time":"2023-10-13T18:14:13.31344107Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1204}
4642023-10-13T18:14:13.360Z{"msg":"[0]R dirty: [true, true, true, true, true]","v":0,"name":"crucible","level":30,"time":"2023-10-13T18:14:13.313479118Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1204}
4652023-10-13T18:14:13.364Z{"msg":"[1]R flush_numbers: [1948, 1949, 1949, 1948, 1948]","v":0,"name":"crucible","level":30,"time":"2023-10-13T18:14:13.313500234Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1204}
4662023-10-13T18:14:13.371Z{"msg":"[1]R generation: [26, 27, 27, 26, 26]","v":0,"name":"crucible","level":30,"time":"2023-10-13T18:14:13.313537319Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1204}
4672023-10-13T18:14:13.375Z{"msg":"[1]R dirty: [true, true, true, true, true]","v":0,"name":"crucible","level":30,"time":"2023-10-13T18:14:13.313575972Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1204}
4682023-10-13T18:14:13.379Z{"msg":"[2]R flush_numbers: [1948, 1948, 1948, 1948, 1948]","v":0,"name":"crucible","level":30,"time":"2023-10-13T18:14:13.313597028Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1204}
4692023-10-13T18:14:13.383Z{"msg":"[2]R generation: [26, 26, 26, 26, 26]","v":0,"name":"crucible","level":30,"time":"2023-10-13T18:14:13.313634082Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1204}
4702023-10-13T18:14:13.388Z{"msg":"[2]R dirty: [false, false, false, false, false]","v":0,"name":"crucible","level":30,"time":"2023-10-13T18:14:13.313653379Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1204}
4712023-10-13T18:14:13.391Z{"msg":"Max found gen is 28","v":0,"name":"crucible","level":30,"time":"2023-10-13T18:14:13.313671262Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1204}
4722023-10-13T18:14:13.396Z{"msg":"Generation requested: 28 >= found:28","v":0,"name":"crucible","level":30,"time":"2023-10-13T18:14:13.313707769Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1204}
4732023-10-13T18:14:13.406Z{"msg":"Next flush: 1950","v":0,"name":"crucible","level":30,"time":"2023-10-13T18:14:13.313746181Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1204}
4742023-10-13T18:14:13.415Z{"msg":"Extents 0 dirty","v":0,"name":"crucible","level":30,"time":"2023-10-13T18:14:13.313765581Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1204,"":"mend"}
4752023-10-13T18:14:13.840Z{"msg":"First source client ID for extent 0","v":0,"name":"crucible","level":30,"time":"2023-10-13T18:14:13.313803597Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1204,"mrl":"dirty","":"mend"}
4762023-10-13T18:14:13.846Z{"msg":"extent:0 gens: 26 26 26","v":0,"name":"crucible","level":30,"time":"2023-10-13T18:14:13.313843874Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1204,"mrl":"dirty","":"mend"}
4772023-10-13T18:14:13.849Z{"msg":"extent:0 flush: 1948 1948 1948 scs: [ClientId(0), ClientId(1), ClientId(2)]","v":0,"name":"crucible","level":30,"time":"2023-10-13T18:14:13.313948953Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1204,"mrl":"dirty","":"mend"}
4782023-10-13T18:14:13.853Z{"msg":"max_flush now has: [ClientId(0), ClientId(1), ClientId(2)]","v":0,"name":"crucible","level":30,"time":"2023-10-13T18:14:13.313974875Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1204,"mrl":"dirty","":"mend"}
4792023-10-13T18:14:13.874Z{"msg":"extent:0 dirty: true true false","v":0,"name":"crucible","level":30,"time":"2023-10-13T18:14:13.314014824Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1204,"mrl":"dirty","":"mend"}
4802023-10-13T18:14:13.880Z{"msg":"find dest for source 0 for extent at index 0","v":0,"name":"crucible","level":30,"time":"2023-10-13T18:14:13.314037916Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1204,"mrl":"dirty","":"mend"}
4812023-10-13T18:14:13.884Z{"msg":"source 0, add dest 1 source flush","v":0,"name":"crucible","level":30,"time":"2023-10-13T18:14:13.31407619Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1204,"mrl":"dirty","":"mend"}
4822023-10-13T18:14:13.902Z{"msg":"source 0, add dest 2 source flush","v":0,"name":"crucible","level":30,"time":"2023-10-13T18:14:13.314115439Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1204,"mrl":"dirty","":"mend"}
4832023-10-13T18:14:13.907Z{"msg":"Extents 1 dirty","v":0,"name":"crucible","level":30,"time":"2023-10-13T18:14:13.314156133Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1204,"":"mend"}
4842023-10-13T18:14:13.913Z{"msg":"First source client ID for extent 1","v":0,"name":"crucible","level":30,"time":"2023-10-13T18:14:13.314195459Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1204,"mrl":"dirty","":"mend"}
4852023-10-13T18:14:13.916Z{"msg":"extent:1 gens: 27 27 26","v":0,"name":"crucible","level":30,"time":"2023-10-13T18:14:13.31421754Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1204,"mrl":"dirty","":"mend"}
4862023-10-13T18:14:13.920Z{"msg":"extent:1 flush: 1949 1949 1948 scs: [ClientId(0), ClientId(1)]","v":0,"name":"crucible","level":30,"time":"2023-10-13T18:14:13.314237418Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1204,"mrl":"dirty","":"mend"}
4872023-10-13T18:14:13.923Z{"msg":"max_flush now has: [ClientId(0), ClientId(1)]","v":0,"name":"crucible","level":30,"time":"2023-10-13T18:14:13.314275123Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1204,"mrl":"dirty","":"mend"}
4882023-10-13T18:14:13.939Z{"msg":"extent:1 dirty: true true false","v":0,"name":"crucible","level":30,"time":"2023-10-13T18:14:13.314297316Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1204,"mrl":"dirty","":"mend"}
4892023-10-13T18:14:13.943Z{"msg":"find dest for source 0 for extent at index 1","v":0,"name":"crucible","level":30,"time":"2023-10-13T18:14:13.314335894Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1204,"mrl":"dirty","":"mend"}
4902023-10-13T18:14:13.948Z{"msg":"source 0, add dest 1 source flush","v":0,"name":"crucible","level":30,"time":"2023-10-13T18:14:13.314376527Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1204,"mrl":"dirty","":"mend"}
4912023-10-13T18:14:13.952Z{"msg":"source 0, add dest 2 gen","v":0,"name":"crucible","level":30,"time":"2023-10-13T18:14:13.314424006Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1204,"mrl":"dirty","":"mend"}
4922023-10-13T18:14:13.968Z{"msg":"Extents 2 dirty","v":0,"name":"crucible","level":30,"time":"2023-10-13T18:14:13.314446298Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1204,"":"mend"}
4932023-10-13T18:14:13.973Z{"msg":"First source client ID for extent 2","v":0,"name":"crucible","level":30,"time":"2023-10-13T18:14:13.314491409Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1204,"mrl":"dirty","":"mend"}
4942023-10-13T18:14:13.980Z{"msg":"extent:2 gens: 27 27 26","v":0,"name":"crucible","level":30,"time":"2023-10-13T18:14:13.314511859Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1204,"mrl":"dirty","":"mend"}
4952023-10-13T18:14:13.983Z{"msg":"extent:2 flush: 1949 1949 1948 scs: [ClientId(0), ClientId(1)]","v":0,"name":"crucible","level":30,"time":"2023-10-13T18:14:13.314557719Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1204,"mrl":"dirty","":"mend"}
4962023-10-13T18:14:13.994Z{"msg":"max_flush now has: [ClientId(0), ClientId(1)]","v":0,"name":"crucible","level":30,"time":"2023-10-13T18:14:13.314597885Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1204,"mrl":"dirty","":"mend"}
4972023-10-13T18:14:13.999Z{"msg":"extent:2 dirty: true true false","v":0,"name":"crucible","level":30,"time":"2023-10-13T18:14:13.314651034Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1204,"mrl":"dirty","":"mend"}
4982023-10-13T18:14:14.004Z{"msg":"find dest for source 0 for extent at index 2","v":0,"name":"crucible","level":30,"time":"2023-10-13T18:14:13.314720913Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1204,"mrl":"dirty","":"mend"}
4992023-10-13T18:14:14.009Z{"msg":"source 0, add dest 1 source flush","v":0,"name":"crucible","level":30,"time":"2023-10-13T18:14:13.314794673Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1204,"mrl":"dirty","":"mend"}
5002023-10-13T18:14:14.016Z{"msg":"source 0, add dest 2 gen","v":0,"name":"crucible","level":30,"time":"2023-10-13T18:14:13.314847497Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1204,"mrl":"dirty","":"mend"}
5012023-10-13T18:14:14.433Z{"msg":"Extents 3 dirty","v":0,"name":"crucible","level":30,"time":"2023-10-13T18:14:13.31488964Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1204,"":"mend"}
5022023-10-13T18:14:14.436Z{"msg":"First source client ID for extent 3","v":0,"name":"crucible","level":30,"time":"2023-10-13T18:14:13.314942497Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1204,"mrl":"dirty","":"mend"}
5032023-10-13T18:14:14.439Z{"msg":"extent:3 gens: 26 26 26","v":0,"name":"crucible","level":30,"time":"2023-10-13T18:14:13.315006589Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1204,"mrl":"dirty","":"mend"}
5042023-10-13T18:14:14.442Z{"msg":"extent:3 flush: 1948 1948 1948 scs: [ClientId(0), ClientId(1), ClientId(2)]","v":0,"name":"crucible","level":30,"time":"2023-10-13T18:14:13.315052277Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1204,"mrl":"dirty","":"mend"}
5052023-10-13T18:14:14.445Z{"msg":"max_flush now has: [ClientId(0), ClientId(1), ClientId(2)]","v":0,"name":"crucible","level":30,"time":"2023-10-13T18:14:13.315093804Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1204,"mrl":"dirty","":"mend"}
5062023-10-13T18:14:14.448Z{"msg":"extent:3 dirty: true true false","v":0,"name":"crucible","level":30,"time":"2023-10-13T18:14:13.315133733Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1204,"mrl":"dirty","":"mend"}
5072023-10-13T18:14:14.451Z{"msg":"find dest for source 0 for extent at index 3","v":0,"name":"crucible","level":30,"time":"2023-10-13T18:14:13.315173868Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1204,"mrl":"dirty","":"mend"}
5082023-10-13T18:14:14.507Z{"msg":"source 0, add dest 1 source flush","v":0,"name":"crucible","level":30,"time":"2023-10-13T18:14:13.315213619Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1204,"mrl":"dirty","":"mend"}
5092023-10-13T18:14:14.511Z{"msg":"source 0, add dest 2 source flush","v":0,"name":"crucible","level":30,"time":"2023-10-13T18:14:13.31525342Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1204,"mrl":"dirty","":"mend"}
5102023-10-13T18:14:14.519Z{"msg":"Extents 4 dirty","v":0,"name":"crucible","level":30,"time":"2023-10-13T18:14:13.315293782Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1204,"":"mend"}
5112023-10-13T18:14:14.526Z{"msg":"First source client ID for extent 4","v":0,"name":"crucible","level":30,"time":"2023-10-13T18:14:13.315313465Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1204,"mrl":"dirty","":"mend"}
5122023-10-13T18:14:14.532Z{"msg":"extent:4 gens: 26 26 26","v":0,"name":"crucible","level":30,"time":"2023-10-13T18:14:13.315350927Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1204,"mrl":"dirty","":"mend"}
5132023-10-13T18:14:14.537Z{"msg":"extent:4 flush: 1948 1948 1948 scs: [ClientId(0), ClientId(1), ClientId(2)]","v":0,"name":"crucible","level":30,"time":"2023-10-13T18:14:13.315392043Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1204,"mrl":"dirty","":"mend"}
5142023-10-13T18:14:14.547Z{"msg":"max_flush now has: [ClientId(0), ClientId(1), ClientId(2)]","v":0,"name":"crucible","level":30,"time":"2023-10-13T18:14:13.315432655Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1204,"mrl":"dirty","":"mend"}
5152023-10-13T18:14:14.557Z{"msg":"extent:4 dirty: true true false","v":0,"name":"crucible","level":30,"time":"2023-10-13T18:14:13.315453316Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1204,"mrl":"dirty","":"mend"}
5162023-10-13T18:14:14.568Z{"msg":"find dest for source 0 for extent at index 4","v":0,"name":"crucible","level":30,"time":"2023-10-13T18:14:13.31547231Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1204,"mrl":"dirty","":"mend"}
5172023-10-13T18:14:14.576Z{"msg":"source 0, add dest 1 source flush","v":0,"name":"crucible","level":30,"time":"2023-10-13T18:14:13.315491524Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1204,"mrl":"dirty","":"mend"}
5182023-10-13T18:14:14.585Z{"msg":"source 0, add dest 2 source flush","v":0,"name":"crucible","level":30,"time":"2023-10-13T18:14:13.315510516Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1204,"mrl":"dirty","":"mend"}
5192023-10-13T18:14:14.599Z{"msg":"Transition from WaitQuorum to Repair","v":0,"name":"crucible","level":30,"time":"2023-10-13T18:14:13.315530057Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1204}
5202023-10-13T18:14:14.607Z{"msg":"Transition from WaitQuorum to Repair","v":0,"name":"crucible","level":30,"time":"2023-10-13T18:14:13.315546792Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1204}
5212023-10-13T18:14:14.615Z{"msg":"Transition from WaitQuorum to Repair","v":0,"name":"crucible","level":30,"time":"2023-10-13T18:14:13.315563508Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1204}
5222023-10-13T18:14:14.642Z{"msg":"Found 5 extents that need repair","v":0,"name":"crucible","level":30,"time":"2023-10-13T18:14:13.315580318Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1204}
5232023-10-13T18:14:14.646Z{"msg":"Full repair list: {0: ExtentFix { source: ClientId(0), dest: [ClientId(1), ClientId(2)] }, 2: ExtentFix { source: ClientId(0), dest: [ClientId(1), ClientId(2)] }, 1: ExtentFix { source: ClientId(0), dest: [ClientId(1), ClientId(2)] }, 3: ExtentFix { source: ClientId(0), dest: [ClientId(1), ClientId(2)] }, 4: ExtentFix { source: ClientId(0), dest: [ClientId(1), ClientId(2)] }}","v":0,"name":"crucible","level":30,"time":"2023-10-13T18:14:13.315607018Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1204,"":"downstairs"}
5242023-10-13T18:14:14.649Z{"msg":"Task list: [ReconcileIO { id: ReconciliationId(0), op: ExtentFlush { repair_id: ReconciliationId(0), extent_id: 0, client_id: ClientId(0), flush_number: 1950, 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: 2, client_id: ClientId(0), flush_number: 1950, gen_number: 28 }, state: ClientData([New, New, New]) }, ReconcileIO { id: ReconciliationId(5), op: ExtentClose { repair_id: ReconciliationId(5), extent_id: 2 }, state: ClientData([New, New, New]) }, ReconcileIO { id: ReconciliationId(6), op: ExtentRepair { repair_id: ReconciliationId(6), 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(7), op: ExtentReopen { repair_id: ReconciliationId(7), extent_id: 2 }, state: ClientData([New, New, New]) }, ReconcileIO { id: ReconciliationId(8), op: ExtentFlush { repair_id: ReconciliationId(8), extent_id: 1, client_id: ClientId(0), flush_number: 1950, gen_number: 28 }, state: ClientData([New, New, New]) }, ReconcileIO { id: ReconciliationId(9), op: ExtentClose { repair_id: ReconciliationId(9), extent_id: 1 }, state: ClientData([New, New, New]) }, ReconcileIO { id: ReconciliationId(10), op: ExtentRepair { repair_id: ReconciliationId(10), extent_id: 1, source_client_id: ClientId(0), source_repair_address: 0.0.0.0:12810, dest_clients: [ClientId(1), ClientId(2)] }, state: ClientData([New, New, New]) }, ReconcileIO { id: ReconciliationId(11), op: ExtentReopen { repair_id: ReconciliationId(11), extent_id: 1 }, state: ClientData([New, New, New]) }, ReconcileIO { id: ReconciliationId(12), op: ExtentFlush { repair_id: ReconciliationId(12), extent_id: 3, client_id: ClientId(0), flush_number: 1950, 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(1), 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: 4, client_id: ClientId(0), flush_number: 1950, gen_number: 28 }, state: ClientData([New, New, New]) }, ReconcileIO { id: ReconciliationId(17), op: ExtentClose { repair_id: ReconciliationId(17), extent_id: 4 }, state: ClientData([New, New, New]) }, ReconcileIO { id: ReconciliationId(18), op: ExtentRepair { repair_id: ReconciliationId(18), extent_id: 4, 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: 4 }, state: ClientData([New, New, New]) }]","v":0,"name":"crucible","level":30,"time":"2023-10-13T18:14:13.315739539Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1204,"":"downstairs"}
5252023-10-13T18:14:14.652Z{"msg":"Begin repair with 20 commands","v":0,"name":"crucible","level":30,"time":"2023-10-13T18:14:13.3157614Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1204}
5262023-10-13T18:14:14.656Z{"msg":"Pop front: ReconcileIO { id: ReconciliationId(0), op: ExtentFlush { repair_id: ReconciliationId(0), extent_id: 0, client_id: ClientId(0), flush_number: 1950, gen_number: 28 }, state: ClientData([New, New, New]) }","v":0,"name":"crucible","level":30,"time":"2023-10-13T18:14:13.315788739Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1204}
5272023-10-13T18:14:14.659Z{"msg":"Sent repair work, now wait for resp","v":0,"name":"crucible","level":30,"time":"2023-10-13T18:14:13.315811775Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1204}
5282023-10-13T18:14:14.692Z{"msg":"[2] received reconcile message","v":0,"name":"crucible","level":30,"time":"2023-10-13T18:14:13.315828884Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1204}
5292023-10-13T18:14:14.699Z{"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: 1950, gen_number: 28 }, state: ClientData([New, New, InProgress]) }","v":0,"name":"crucible","level":30,"time":"2023-10-13T18:14:13.315850722Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1204,"":"downstairs"}
5302023-10-13T18:14:14.703Z{"msg":"[0] received reconcile message","v":0,"name":"crucible","level":30,"time":"2023-10-13T18:14:13.315868893Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1204}
5312023-10-13T18:14:14.708Z{"msg":"[2] client ExtentFlush { repair_id: ReconciliationId(0), extent_id: 0, client_id: ClientId(0), flush_number: 1950, gen_number: 28 }","v":0,"name":"crucible","level":30,"time":"2023-10-13T18:14:13.315892895Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1204}
5322023-10-13T18:14:14.713Z{"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: 1950, gen_number: 28 }, state: ClientData([InProgress, New, InProgress]) }","v":0,"name":"crucible","level":30,"time":"2023-10-13T18:14:13.315931411Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1204,"":"downstairs"}
5332023-10-13T18:14:14.717Z{"msg":"[0] client ExtentFlush { repair_id: ReconciliationId(0), extent_id: 0, client_id: ClientId(0), flush_number: 1950, gen_number: 28 }","v":0,"name":"crucible","level":30,"time":"2023-10-13T18:14:13.315970967Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1204}
5342023-10-13T18:14:14.720Z{"msg":"[1] received reconcile message","v":0,"name":"crucible","level":30,"time":"2023-10-13T18:14:13.316005743Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1204}
5352023-10-13T18:14:14.724Z{"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: 1950, gen_number: 28 }, state: ClientData([InProgress, InProgress, Done]) }","v":0,"name":"crucible","level":30,"time":"2023-10-13T18:14:13.316048437Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1204,"":"downstairs"}
5362023-10-13T18:14:14.728Z{"msg":"[1] client ExtentFlush { repair_id: ReconciliationId(0), extent_id: 0, client_id: ClientId(0), flush_number: 1950, gen_number: 28 }","v":0,"name":"crucible","level":30,"time":"2023-10-13T18:14:13.316090176Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1204}
5372023-10-13T18:14:14.731Z{"msg":"Completion from [0] id:0 status:true","v":0,"name":"crucible","level":30,"time":"2023-10-13T18:14:13.317400812Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1204}
5382023-10-13T18:14:14.734Z{"msg":"[1/20] Repair commands completed","v":0,"name":"crucible","level":30,"time":"2023-10-13T18:14:13.317430614Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1204}
5392023-10-13T18:14:14.738Z{"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-10-13T18:14:13.317451928Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1204}
5402023-10-13T18:14:14.742Z{"msg":"Sent repair work, now wait for resp","v":0,"name":"crucible","level":30,"time":"2023-10-13T18:14:13.317469493Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1204}
5412023-10-13T18:14:14.745Z{"msg":"[2] received reconcile message","v":0,"name":"crucible","level":30,"time":"2023-10-13T18:14:13.317486847Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1204}
5422023-10-13T18:14:14.749Z{"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-10-13T18:14:13.31750778Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1204,"":"downstairs"}
5432023-10-13T18:14:14.753Z{"msg":"[2] client ExtentClose { repair_id: ReconciliationId(1), extent_id: 0 }","v":0,"name":"crucible","level":30,"time":"2023-10-13T18:14:13.317528023Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1204}
5442023-10-13T18:14:14.757Z{"msg":"[0] received reconcile message","v":0,"name":"crucible","level":30,"time":"2023-10-13T18:14:13.317545083Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1204}
5452023-10-13T18:14:14.760Z{"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-10-13T18:14:13.317590251Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1204,"":"downstairs"}
5462023-10-13T18:14:14.764Z{"msg":"[0] client ExtentClose { repair_id: ReconciliationId(1), extent_id: 0 }","v":0,"name":"crucible","level":30,"time":"2023-10-13T18:14:13.317631879Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1204}
5472023-10-13T18:14:14.767Z{"msg":"[1] received reconcile message","v":0,"name":"crucible","level":30,"time":"2023-10-13T18:14:13.317669549Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1204}
5482023-10-13T18:14:14.771Z{"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-10-13T18:14:13.317713223Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1204,"":"downstairs"}
5492023-10-13T18:14:14.774Z{"msg":"[1] client ExtentClose { repair_id: ReconciliationId(1), extent_id: 0 }","v":0,"name":"crucible","level":30,"time":"2023-10-13T18:14:13.317754687Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1204}
5502023-10-13T18:14:14.779Z{"msg":"Completion from [0] id:1 status:true","v":0,"name":"crucible","level":30,"time":"2023-10-13T18:14:13.320412245Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1204}
5512023-10-13T18:14:14.782Z{"msg":"[2/20] Repair commands completed","v":0,"name":"crucible","level":30,"time":"2023-10-13T18:14:13.320449128Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1204}
5522023-10-13T18:14:14.785Z{"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-10-13T18:14:13.320475275Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1204}
5532023-10-13T18:14:14.789Z{"msg":"Sent repair work, now wait for resp","v":0,"name":"crucible","level":30,"time":"2023-10-13T18:14:13.320493427Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1204}
5542023-10-13T18:14:14.792Z{"msg":"[2] received reconcile message","v":0,"name":"crucible","level":30,"time":"2023-10-13T18:14:13.320514749Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1204}
5552023-10-13T18:14:14.797Z{"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-10-13T18:14:13.320538771Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1204,"":"downstairs"}
5562023-10-13T18:14:14.800Z{"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-10-13T18:14:13.320561869Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1204}
5572023-10-13T18:14:14.804Z{"msg":"[2] Sending repair request ReconciliationId(2)","v":0,"name":"crucible","level":30,"time":"2023-10-13T18:14:13.320585508Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1204}
5582023-10-13T18:14:14.807Z{"msg":"[0] received reconcile message","v":0,"name":"crucible","level":30,"time":"2023-10-13T18:14:13.320618865Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1204}
5592023-10-13T18:14:14.810Z{"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-10-13T18:14:13.320648153Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1204,"":"downstairs"}
5602023-10-13T18:14:14.813Z{"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-10-13T18:14:13.320670566Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1204}
5612023-10-13T18:14:14.817Z{"msg":"[0] No action required ReconciliationId(2)","v":0,"name":"crucible","level":30,"time":"2023-10-13T18:14:13.320687872Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1204}
5622023-10-13T18:14:14.820Z{"msg":"[1] received reconcile message","v":0,"name":"crucible","level":30,"time":"2023-10-13T18:14:13.320704547Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1204}
5632023-10-13T18:14:14.824Z{"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-10-13T18:14:13.320728409Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1204,"":"downstairs"}
5642023-10-13T18:14:14.828Z{"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-10-13T18:14:13.320750248Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1204}
5652023-10-13T18:14:14.832Z{"msg":"[1] Sending repair request ReconciliationId(2)","v":0,"name":"crucible","level":30,"time":"2023-10-13T18:14:13.320767465Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1204}
5662023-10-13T18:14:14.835Z{"msg":"Completion from [2] id:2 status:true","v":0,"name":"crucible","level":30,"time":"2023-10-13T18:14:13.447203869Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1204}
5672023-10-13T18:14:14.839Z{"msg":"[3/20] Repair commands completed","v":0,"name":"crucible","level":30,"time":"2023-10-13T18:14:13.447258199Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1204}
5682023-10-13T18:14:14.842Z{"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-10-13T18:14:13.447280751Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1204}
5692023-10-13T18:14:14.846Z{"msg":"Sent repair work, now wait for resp","v":0,"name":"crucible","level":30,"time":"2023-10-13T18:14:13.44730409Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1204}
5702023-10-13T18:14:14.849Z{"msg":"[2] received reconcile message","v":0,"name":"crucible","level":30,"time":"2023-10-13T18:14:13.447335951Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1204}
5712023-10-13T18:14:14.853Z{"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-10-13T18:14:13.447377737Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1204,"":"downstairs"}
5722023-10-13T18:14:14.857Z{"msg":"[2] client ExtentReopen { repair_id: ReconciliationId(3), extent_id: 0 }","v":0,"name":"crucible","level":30,"time":"2023-10-13T18:14:13.447418512Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1204}
5732023-10-13T18:14:14.860Z{"msg":"[0] received reconcile message","v":0,"name":"crucible","level":30,"time":"2023-10-13T18:14:13.447455287Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1204}
5742023-10-13T18:14:14.864Z{"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-10-13T18:14:13.447495081Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1204,"":"downstairs"}
5752023-10-13T18:14:14.867Z{"msg":"[0] client ExtentReopen { repair_id: ReconciliationId(3), extent_id: 0 }","v":0,"name":"crucible","level":30,"time":"2023-10-13T18:14:13.447532795Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1204}
5762023-10-13T18:14:14.871Z{"msg":"[1] received reconcile message","v":0,"name":"crucible","level":30,"time":"2023-10-13T18:14:13.44755233Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1204}
5772023-10-13T18:14:14.881Z{"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-10-13T18:14:13.447573985Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1204,"":"downstairs"}
5782023-10-13T18:14:14.885Z{"msg":"[1] client ExtentReopen { repair_id: ReconciliationId(3), extent_id: 0 }","v":0,"name":"crucible","level":30,"time":"2023-10-13T18:14:13.447593065Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1204}
5792023-10-13T18:14:14.890Z{"msg":"Completion from [0] id:3 status:true","v":0,"name":"crucible","level":30,"time":"2023-10-13T18:14:13.448480236Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1204}
5802023-10-13T18:14:14.894Z{"msg":"[4/20] Repair commands completed","v":0,"name":"crucible","level":30,"time":"2023-10-13T18:14:13.44851164Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1204}
5812023-10-13T18:14:14.897Z{"msg":"Pop front: ReconcileIO { id: ReconciliationId(4), op: ExtentFlush { repair_id: ReconciliationId(4), extent_id: 2, client_id: ClientId(0), flush_number: 1950, gen_number: 28 }, state: ClientData([New, New, New]) }","v":0,"name":"crucible","level":30,"time":"2023-10-13T18:14:13.44853545Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1204}
5822023-10-13T18:14:14.900Z{"msg":"Sent repair work, now wait for resp","v":0,"name":"crucible","level":30,"time":"2023-10-13T18:14:13.448553467Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1204}
5832023-10-13T18:14:14.903Z{"msg":"[2] received reconcile message","v":0,"name":"crucible","level":30,"time":"2023-10-13T18:14:13.448570839Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1204}
5842023-10-13T18:14:14.907Z{"msg":"[2] rep_in_progress: return ReconcileIO { id: ReconciliationId(4), op: ExtentFlush { repair_id: ReconciliationId(4), extent_id: 2, client_id: ClientId(0), flush_number: 1950, gen_number: 28 }, state: ClientData([New, New, InProgress]) }","v":0,"name":"crucible","level":30,"time":"2023-10-13T18:14:13.44859357Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1204,"":"downstairs"}
5852023-10-13T18:14:14.911Z{"msg":"[2] client ExtentFlush { repair_id: ReconciliationId(4), extent_id: 2, client_id: ClientId(0), flush_number: 1950, gen_number: 28 }","v":0,"name":"crucible","level":30,"time":"2023-10-13T18:14:13.448615292Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1204}
5862023-10-13T18:14:14.915Z{"msg":"[0] received reconcile message","v":0,"name":"crucible","level":30,"time":"2023-10-13T18:14:13.448632915Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1204}
5872023-10-13T18:14:14.918Z{"msg":"[1] received reconcile message","v":0,"name":"crucible","level":30,"time":"2023-10-13T18:14:13.448650266Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1204}
5882023-10-13T18:14:14.922Z{"msg":"[1] rep_in_progress: return ReconcileIO { id: ReconciliationId(4), op: ExtentFlush { repair_id: ReconciliationId(4), extent_id: 2, client_id: ClientId(0), flush_number: 1950, gen_number: 28 }, state: ClientData([New, InProgress, Done]) }","v":0,"name":"crucible","level":30,"time":"2023-10-13T18:14:13.448672975Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1204,"":"downstairs"}
5892023-10-13T18:14:14.926Z{"msg":"[1] client ExtentFlush { repair_id: ReconciliationId(4), extent_id: 2, client_id: ClientId(0), flush_number: 1950, gen_number: 28 }","v":0,"name":"crucible","level":30,"time":"2023-10-13T18:14:13.448693872Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1204}
5902023-10-13T18:14:14.929Z{"msg":"[0] rep_in_progress: return ReconcileIO { id: ReconciliationId(4), op: ExtentFlush { repair_id: ReconciliationId(4), extent_id: 2, client_id: ClientId(0), flush_number: 1950, gen_number: 28 }, state: ClientData([InProgress, InProgress, Done]) }","v":0,"name":"crucible","level":30,"time":"2023-10-13T18:14:13.448716745Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1204,"":"downstairs"}
5912023-10-13T18:14:14.933Z{"msg":"[0] client ExtentFlush { repair_id: ReconciliationId(4), extent_id: 2, client_id: ClientId(0), flush_number: 1950, gen_number: 28 }","v":0,"name":"crucible","level":30,"time":"2023-10-13T18:14:13.448737836Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1204}
5922023-10-13T18:14:14.936Z{"msg":"Completion from [0] id:4 status:true","v":0,"name":"crucible","level":30,"time":"2023-10-13T18:14:13.450747881Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1204}
5932023-10-13T18:14:14.963Z{"msg":"[5/20] Repair commands completed","v":0,"name":"crucible","level":30,"time":"2023-10-13T18:14:13.450775986Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1204}
5942023-10-13T18:14:14.977Z{"msg":"Pop front: ReconcileIO { id: ReconciliationId(5), op: ExtentClose { repair_id: ReconciliationId(5), extent_id: 2 }, state: ClientData([New, New, New]) }","v":0,"name":"crucible","level":30,"time":"2023-10-13T18:14:13.45079753Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1204}
5952023-10-13T18:14:14.981Z{"msg":"Sent repair work, now wait for resp","v":0,"name":"crucible","level":30,"time":"2023-10-13T18:14:13.450815224Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1204}
5962023-10-13T18:14:14.985Z{"msg":"[2] received reconcile message","v":0,"name":"crucible","level":30,"time":"2023-10-13T18:14:13.450832391Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1204}
5972023-10-13T18:14:14.988Z{"msg":"[2] rep_in_progress: return ReconcileIO { id: ReconciliationId(5), op: ExtentClose { repair_id: ReconciliationId(5), extent_id: 2 }, state: ClientData([New, New, InProgress]) }","v":0,"name":"crucible","level":30,"time":"2023-10-13T18:14:13.450853692Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1204,"":"downstairs"}
5982023-10-13T18:14:14.992Z{"msg":"[2] client ExtentClose { repair_id: ReconciliationId(5), extent_id: 2 }","v":0,"name":"crucible","level":30,"time":"2023-10-13T18:14:13.450873935Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1204}
5992023-10-13T18:14:14.995Z{"msg":"[0] received reconcile message","v":0,"name":"crucible","level":30,"time":"2023-10-13T18:14:13.450891236Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1204}
6002023-10-13T18:14:14.998Z{"msg":"[0] rep_in_progress: return ReconcileIO { id: ReconciliationId(5), op: ExtentClose { repair_id: ReconciliationId(5), extent_id: 2 }, state: ClientData([InProgress, New, InProgress]) }","v":0,"name":"crucible","level":30,"time":"2023-10-13T18:14:13.450912476Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1204,"":"downstairs"}
6012023-10-13T18:14:15.013Z{"msg":"[0] client ExtentClose { repair_id: ReconciliationId(5), extent_id: 2 }","v":0,"name":"crucible","level":30,"time":"2023-10-13T18:14:13.450931876Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1204}
6022023-10-13T18:14:15.018Z{"msg":"[1] received reconcile message","v":0,"name":"crucible","level":30,"time":"2023-10-13T18:14:13.450949518Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1204}
6032023-10-13T18:14:15.022Z{"msg":"[1] rep_in_progress: return ReconcileIO { id: ReconciliationId(5), op: ExtentClose { repair_id: ReconciliationId(5), extent_id: 2 }, state: ClientData([InProgress, InProgress, InProgress]) }","v":0,"name":"crucible","level":30,"time":"2023-10-13T18:14:13.450970738Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1204,"":"downstairs"}
6042023-10-13T18:14:15.025Z{"msg":"[1] client ExtentClose { repair_id: ReconciliationId(5), extent_id: 2 }","v":0,"name":"crucible","level":30,"time":"2023-10-13T18:14:13.450990299Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1204}
6052023-10-13T18:14:15.029Z{"msg":"Completion from [1] id:5 status:true","v":0,"name":"crucible","level":30,"time":"2023-10-13T18:14:13.453720983Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1204}
6062023-10-13T18:14:15.033Z{"msg":"[6/20] Repair commands completed","v":0,"name":"crucible","level":30,"time":"2023-10-13T18:14:13.856098306Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1204}
6072023-10-13T18:14:15.047Z{"msg":"Pop front: ReconcileIO { id: ReconciliationId(6), op: ExtentRepair { repair_id: ReconciliationId(6), 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-10-13T18:14:13.856187353Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1204}
6082023-10-13T18:14:15.065Z{"msg":"Sent repair work, now wait for resp","v":0,"name":"crucible","level":30,"time":"2023-10-13T18:14:13.856235109Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1204}
6092023-10-13T18:14:15.095Z{"msg":"[2] received reconcile message","v":0,"name":"crucible","level":30,"time":"2023-10-13T18:14:13.856279152Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1204}
6102023-10-13T18:14:15.114Z{"msg":"[2] rep_in_progress: return ReconcileIO { id: ReconciliationId(6), op: ExtentRepair { repair_id: ReconciliationId(6), 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-10-13T18:14:13.856328299Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1204,"":"downstairs"}
6112023-10-13T18:14:15.119Z{"msg":"[2] client ExtentRepair { repair_id: ReconciliationId(6), 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-10-13T18:14:13.856375992Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1204}
6122023-10-13T18:14:15.127Z{"msg":"[2] Sending repair request ReconciliationId(6)","v":0,"name":"crucible","level":30,"time":"2023-10-13T18:14:13.856420246Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1204}
6132023-10-13T18:14:15.135Z{"msg":"[0] received reconcile message","v":0,"name":"crucible","level":30,"time":"2023-10-13T18:14:13.856442319Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1204}
6142023-10-13T18:14:15.142Z{"msg":"[0] rep_in_progress: return ReconcileIO { id: ReconciliationId(6), op: ExtentRepair { repair_id: ReconciliationId(6), 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-10-13T18:14:13.856466785Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1204,"":"downstairs"}
6152023-10-13T18:14:15.147Z{"msg":"[0] client ExtentRepair { repair_id: ReconciliationId(6), 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-10-13T18:14:13.856504239Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1204}
6162023-10-13T18:14:15.155Z{"msg":"[0] No action required ReconciliationId(6)","v":0,"name":"crucible","level":30,"time":"2023-10-13T18:14:13.856541599Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1204}
6172023-10-13T18:14:15.164Z{"msg":"[1] received reconcile message","v":0,"name":"crucible","level":30,"time":"2023-10-13T18:14:13.856577861Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1204}
6182023-10-13T18:14:15.170Z{"msg":"[1] rep_in_progress: return ReconcileIO { id: ReconciliationId(6), op: ExtentRepair { repair_id: ReconciliationId(6), 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-10-13T18:14:13.856625269Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1204,"":"downstairs"}
6192023-10-13T18:14:15.190Z{"msg":"[1] client ExtentRepair { repair_id: ReconciliationId(6), 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-10-13T18:14:13.856667788Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1204}
6202023-10-13T18:14:15.211Z{"msg":"[1] Sending repair request ReconciliationId(6)","v":0,"name":"crucible","level":30,"time":"2023-10-13T18:14:13.856700914Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1204}
6212023-10-13T18:14:15.224Z{"msg":"Completion from [1] id:6 status:true","v":0,"name":"crucible","level":30,"time":"2023-10-13T18:14:13.856733726Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1204}
6222023-10-13T18:14:15.228Z{"msg":"[7/20] Repair commands completed","v":0,"name":"crucible","level":30,"time":"2023-10-13T18:14:13.856763308Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1204}
6232023-10-13T18:14:15.236Z{"msg":"Pop front: ReconcileIO { id: ReconciliationId(7), op: ExtentReopen { repair_id: ReconciliationId(7), extent_id: 2 }, state: ClientData([New, New, New]) }","v":0,"name":"crucible","level":30,"time":"2023-10-13T18:14:13.856798029Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1204}
6242023-10-13T18:14:15.255Z{"msg":"Sent repair work, now wait for resp","v":0,"name":"crucible","level":30,"time":"2023-10-13T18:14:13.856830916Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1204}
6252023-10-13T18:14:15.259Z{"msg":"[2] received reconcile message","v":0,"name":"crucible","level":30,"time":"2023-10-13T18:14:13.856860728Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1204}
6262023-10-13T18:14:15.263Z{"msg":"[2] rep_in_progress: return ReconcileIO { id: ReconciliationId(7), op: ExtentReopen { repair_id: ReconciliationId(7), extent_id: 2 }, state: ClientData([New, New, InProgress]) }","v":0,"name":"crucible","level":30,"time":"2023-10-13T18:14:13.856896208Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1204,"":"downstairs"}
6272023-10-13T18:14:15.267Z{"msg":"[2] client ExtentReopen { repair_id: ReconciliationId(7), extent_id: 2 }","v":0,"name":"crucible","level":30,"time":"2023-10-13T18:14:13.856931423Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1204}
6282023-10-13T18:14:15.272Z{"msg":"[0] received reconcile message","v":0,"name":"crucible","level":30,"time":"2023-10-13T18:14:13.856965566Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1204}
6292023-10-13T18:14:15.284Z{"msg":"[0] rep_in_progress: return ReconcileIO { id: ReconciliationId(7), op: ExtentReopen { repair_id: ReconciliationId(7), extent_id: 2 }, state: ClientData([InProgress, New, InProgress]) }","v":0,"name":"crucible","level":30,"time":"2023-10-13T18:14:13.857004724Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1204,"":"downstairs"}
6302023-10-13T18:14:15.288Z{"msg":"[0] client ExtentReopen { repair_id: ReconciliationId(7), extent_id: 2 }","v":0,"name":"crucible","level":30,"time":"2023-10-13T18:14:13.857037582Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1204}
6312023-10-13T18:14:15.291Z{"msg":"[1] received reconcile message","v":0,"name":"crucible","level":30,"time":"2023-10-13T18:14:13.857067272Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1204}
6322023-10-13T18:14:15.295Z{"msg":"[1] rep_in_progress: return ReconcileIO { id: ReconciliationId(7), op: ExtentReopen { repair_id: ReconciliationId(7), extent_id: 2 }, state: ClientData([InProgress, InProgress, InProgress]) }","v":0,"name":"crucible","level":30,"time":"2023-10-13T18:14:13.857107415Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1204,"":"downstairs"}
6332023-10-13T18:14:15.298Z{"msg":"[1] client ExtentReopen { repair_id: ReconciliationId(7), extent_id: 2 }","v":0,"name":"crucible","level":30,"time":"2023-10-13T18:14:13.85714689Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1204}
6342023-10-13T18:14:15.302Z{"msg":"Completion from [2] id:7 status:true","v":0,"name":"crucible","level":30,"time":"2023-10-13T18:14:13.857183974Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1204}
6352023-10-13T18:14:15.307Z{"msg":"[8/20] Repair commands completed","v":0,"name":"crucible","level":30,"time":"2023-10-13T18:14:13.857218748Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1204}
6362023-10-13T18:14:15.311Z{"msg":"Pop front: ReconcileIO { id: ReconciliationId(8), op: ExtentFlush { repair_id: ReconciliationId(8), extent_id: 1, client_id: ClientId(0), flush_number: 1950, gen_number: 28 }, state: ClientData([New, New, New]) }","v":0,"name":"crucible","level":30,"time":"2023-10-13T18:14:13.857262495Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1204}
6372023-10-13T18:14:15.317Z{"msg":"Sent repair work, now wait for resp","v":0,"name":"crucible","level":30,"time":"2023-10-13T18:14:13.857298398Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1204}
6382023-10-13T18:14:15.320Z{"msg":"[2] received reconcile message","v":0,"name":"crucible","level":30,"time":"2023-10-13T18:14:14.462554596Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1204}
6392023-10-13T18:14:15.323Z{"msg":"[2] rep_in_progress: return ReconcileIO { id: ReconciliationId(8), op: ExtentFlush { repair_id: ReconciliationId(8), extent_id: 1, client_id: ClientId(0), flush_number: 1950, gen_number: 28 }, state: ClientData([New, New, InProgress]) }","v":0,"name":"crucible","level":30,"time":"2023-10-13T18:14:14.462656054Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1204,"":"downstairs"}
6402023-10-13T18:14:15.327Z{"msg":"[2] client ExtentFlush { repair_id: ReconciliationId(8), extent_id: 1, client_id: ClientId(0), flush_number: 1950, gen_number: 28 }","v":0,"name":"crucible","level":30,"time":"2023-10-13T18:14:14.462701982Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1204}
6412023-10-13T18:14:15.330Z{"msg":"[1] received reconcile message","v":0,"name":"crucible","level":30,"time":"2023-10-13T18:14:14.462732148Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1204}
6422023-10-13T18:14:15.333Z{"msg":"[1] rep_in_progress: return ReconcileIO { id: ReconciliationId(8), op: ExtentFlush { repair_id: ReconciliationId(8), extent_id: 1, client_id: ClientId(0), flush_number: 1950, gen_number: 28 }, state: ClientData([New, InProgress, Done]) }","v":0,"name":"crucible","level":30,"time":"2023-10-13T18:14:14.462756097Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1204,"":"downstairs"}
6432023-10-13T18:14:15.337Z{"msg":"[1] client ExtentFlush { repair_id: ReconciliationId(8), extent_id: 1, client_id: ClientId(0), flush_number: 1950, gen_number: 28 }","v":0,"name":"crucible","level":30,"time":"2023-10-13T18:14:14.462777182Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1204}
6442023-10-13T18:14:15.341Z{"msg":"[0] received reconcile message","v":0,"name":"crucible","level":30,"time":"2023-10-13T18:14:14.46279465Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1204}
6452023-10-13T18:14:15.344Z{"msg":"[0] rep_in_progress: return ReconcileIO { id: ReconciliationId(8), op: ExtentFlush { repair_id: ReconciliationId(8), extent_id: 1, client_id: ClientId(0), flush_number: 1950, gen_number: 28 }, state: ClientData([InProgress, Done, Done]) }","v":0,"name":"crucible","level":30,"time":"2023-10-13T18:14:14.462817271Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1204,"":"downstairs"}
6462023-10-13T18:14:15.347Z{"msg":"[0] client ExtentFlush { repair_id: ReconciliationId(8), extent_id: 1, client_id: ClientId(0), flush_number: 1950, gen_number: 28 }","v":0,"name":"crucible","level":30,"time":"2023-10-13T18:14:14.462837777Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1204}
6472023-10-13T18:14:15.351Z{"msg":"Completion from [0] id:8 status:true","v":0,"name":"crucible","level":30,"time":"2023-10-13T18:14:14.462855091Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1204}
6482023-10-13T18:14:15.354Z{"msg":"[9/20] Repair commands completed","v":0,"name":"crucible","level":30,"time":"2023-10-13T18:14:14.462872188Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1204}
6492023-10-13T18:14:15.358Z{"msg":"Pop front: ReconcileIO { id: ReconciliationId(9), op: ExtentClose { repair_id: ReconciliationId(9), extent_id: 1 }, state: ClientData([New, New, New]) }","v":0,"name":"crucible","level":30,"time":"2023-10-13T18:14:14.462892451Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1204}
6502023-10-13T18:14:15.362Z{"msg":"Sent repair work, now wait for resp","v":0,"name":"crucible","level":30,"time":"2023-10-13T18:14:14.462910006Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1204}
6512023-10-13T18:14:15.365Z{"msg":"[2] received reconcile message","v":0,"name":"crucible","level":30,"time":"2023-10-13T18:14:14.462926946Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1204}
6522023-10-13T18:14:15.368Z{"msg":"[2] rep_in_progress: return ReconcileIO { id: ReconciliationId(9), op: ExtentClose { repair_id: ReconciliationId(9), extent_id: 1 }, state: ClientData([New, New, InProgress]) }","v":0,"name":"crucible","level":30,"time":"2023-10-13T18:14:14.462947716Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1204,"":"downstairs"}
6532023-10-13T18:14:15.372Z{"msg":"[2] client ExtentClose { repair_id: ReconciliationId(9), extent_id: 1 }","v":0,"name":"crucible","level":30,"time":"2023-10-13T18:14:14.462966933Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1204}
6542023-10-13T18:14:15.375Z{"msg":"[0] received reconcile message","v":0,"name":"crucible","level":30,"time":"2023-10-13T18:14:14.462984397Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1204}
6552023-10-13T18:14:15.381Z{"msg":"[0] rep_in_progress: return ReconcileIO { id: ReconciliationId(9), op: ExtentClose { repair_id: ReconciliationId(9), extent_id: 1 }, state: ClientData([InProgress, New, InProgress]) }","v":0,"name":"crucible","level":30,"time":"2023-10-13T18:14:14.463005579Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1204,"":"downstairs"}
6562023-10-13T18:14:15.385Z{"msg":"[0] client ExtentClose { repair_id: ReconciliationId(9), extent_id: 1 }","v":0,"name":"crucible","level":30,"time":"2023-10-13T18:14:14.463024786Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1204}
6572023-10-13T18:14:15.389Z{"msg":"[1] received reconcile message","v":0,"name":"crucible","level":30,"time":"2023-10-13T18:14:14.46304221Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1204}
6582023-10-13T18:14:15.392Z{"msg":"[1] rep_in_progress: return ReconcileIO { id: ReconciliationId(9), op: ExtentClose { repair_id: ReconciliationId(9), extent_id: 1 }, state: ClientData([InProgress, InProgress, InProgress]) }","v":0,"name":"crucible","level":30,"time":"2023-10-13T18:14:14.463063391Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1204,"":"downstairs"}
6592023-10-13T18:14:15.395Z{"msg":"[1] client ExtentClose { repair_id: ReconciliationId(9), extent_id: 1 }","v":0,"name":"crucible","level":30,"time":"2023-10-13T18:14:14.463082568Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1204}
6602023-10-13T18:14:15.398Z{"msg":"Completion from [1] id:9 status:true","v":0,"name":"crucible","level":30,"time":"2023-10-13T18:14:14.463099871Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1204}
6612023-10-13T18:14:15.402Z{"msg":"[10/20] Repair commands completed","v":0,"name":"crucible","level":30,"time":"2023-10-13T18:14:14.463116842Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1204}
6622023-10-13T18:14:15.406Z{"msg":"Pop front: ReconcileIO { id: ReconciliationId(10), op: ExtentRepair { repair_id: ReconciliationId(10), extent_id: 1, source_client_id: ClientId(0), source_repair_address: 0.0.0.0:12810, dest_clients: [ClientId(1), ClientId(2)] }, state: ClientData([New, New, New]) }","v":0,"name":"crucible","level":30,"time":"2023-10-13T18:14:14.463140625Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1204}
6632023-10-13T18:14:15.409Z{"msg":"Sent repair work, now wait for resp","v":0,"name":"crucible","level":30,"time":"2023-10-13T18:14:14.463157987Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1204}
6642023-10-13T18:14:15.412Z{"msg":"[2] received reconcile message","v":0,"name":"crucible","level":30,"time":"2023-10-13T18:14:14.46317515Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1204}
6652023-10-13T18:14:15.415Z{"msg":"[2] rep_in_progress: return ReconcileIO { id: ReconciliationId(10), op: ExtentRepair { repair_id: ReconciliationId(10), extent_id: 1, source_client_id: ClientId(0), source_repair_address: 0.0.0.0:12810, dest_clients: [ClientId(1), ClientId(2)] }, state: ClientData([New, New, InProgress]) }","v":0,"name":"crucible","level":30,"time":"2023-10-13T18:14:14.463198659Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1204,"":"downstairs"}
6662023-10-13T18:14:15.419Z{"msg":"[2] client ExtentRepair { repair_id: ReconciliationId(10), 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-10-13T18:14:14.463220798Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1204}
6672023-10-13T18:14:15.423Z{"msg":"[2] Sending repair request ReconciliationId(10)","v":0,"name":"crucible","level":30,"time":"2023-10-13T18:14:14.463238498Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1204}
6682023-10-13T18:14:15.427Z{"msg":"[0] received reconcile message","v":0,"name":"crucible","level":30,"time":"2023-10-13T18:14:14.463255636Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1204}
6692023-10-13T18:14:15.430Z{"msg":"[0] rep_in_progress: return ReconcileIO { id: ReconciliationId(10), op: ExtentRepair { repair_id: ReconciliationId(10), extent_id: 1, source_client_id: ClientId(0), source_repair_address: 0.0.0.0:12810, dest_clients: [ClientId(1), ClientId(2)] }, state: ClientData([InProgress, New, InProgress]) }","v":0,"name":"crucible","level":30,"time":"2023-10-13T18:14:14.749846931Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1204,"":"downstairs"}
6702023-10-13T18:14:15.434Z{"msg":"[0] client ExtentRepair { repair_id: ReconciliationId(10), 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-10-13T18:14:14.749920971Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1204}
6712023-10-13T18:14:15.437Z{"msg":"[0] No action required ReconciliationId(10)","v":0,"name":"crucible","level":30,"time":"2023-10-13T18:14:14.749943967Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1204}
6722023-10-13T18:14:15.441Z{"msg":"[1] received reconcile message","v":0,"name":"crucible","level":30,"time":"2023-10-13T18:14:14.749965674Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1204}
6732023-10-13T18:14:15.444Z{"msg":"[1] rep_in_progress: return ReconcileIO { id: ReconciliationId(10), op: ExtentRepair { repair_id: ReconciliationId(10), extent_id: 1, source_client_id: ClientId(0), source_repair_address: 0.0.0.0:12810, dest_clients: [ClientId(1), ClientId(2)] }, state: ClientData([Done, InProgress, InProgress]) }","v":0,"name":"crucible","level":30,"time":"2023-10-13T18:14:14.750006777Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1204,"":"downstairs"}
6742023-10-13T18:14:15.449Z{"msg":"[1] client ExtentRepair { repair_id: ReconciliationId(10), 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-10-13T18:14:14.750051457Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1204}
6752023-10-13T18:14:15.452Z{"msg":"[1] Sending repair request ReconciliationId(10)","v":0,"name":"crucible","level":30,"time":"2023-10-13T18:14:14.750089601Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1204}
6762023-10-13T18:14:15.455Z{"msg":"Completion from [1] id:10 status:true","v":0,"name":"crucible","level":30,"time":"2023-10-13T18:14:14.750126455Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1204}
6772023-10-13T18:14:15.458Z{"msg":"[11/20] Repair commands completed","v":0,"name":"crucible","level":30,"time":"2023-10-13T18:14:14.75015865Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1204}
6782023-10-13T18:14:15.462Z{"msg":"Pop front: ReconcileIO { id: ReconciliationId(11), op: ExtentReopen { repair_id: ReconciliationId(11), extent_id: 1 }, state: ClientData([New, New, New]) }","v":0,"name":"crucible","level":30,"time":"2023-10-13T18:14:14.750196777Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1204}
6792023-10-13T18:14:15.465Z{"msg":"Sent repair work, now wait for resp","v":0,"name":"crucible","level":30,"time":"2023-10-13T18:14:14.750229932Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1204}
6802023-10-13T18:14:15.471Z{"msg":"[2] received reconcile message","v":0,"name":"crucible","level":30,"time":"2023-10-13T18:14:14.750259699Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1204}
6812023-10-13T18:14:15.475Z{"msg":"[2] rep_in_progress: return ReconcileIO { id: ReconciliationId(11), op: ExtentReopen { repair_id: ReconciliationId(11), extent_id: 1 }, state: ClientData([New, New, InProgress]) }","v":0,"name":"crucible","level":30,"time":"2023-10-13T18:14:14.750295616Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1204,"":"downstairs"}
6822023-10-13T18:14:15.478Z{"msg":"[2] client ExtentReopen { repair_id: ReconciliationId(11), extent_id: 1 }","v":0,"name":"crucible","level":30,"time":"2023-10-13T18:14:14.750333834Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1204}
6832023-10-13T18:14:15.481Z{"msg":"[0] received reconcile message","v":0,"name":"crucible","level":30,"time":"2023-10-13T18:14:14.750367769Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1204}
6842023-10-13T18:14:15.485Z{"msg":"[0] rep_in_progress: return ReconcileIO { id: ReconciliationId(11), op: ExtentReopen { repair_id: ReconciliationId(11), extent_id: 1 }, state: ClientData([InProgress, New, InProgress]) }","v":0,"name":"crucible","level":30,"time":"2023-10-13T18:14:14.75040761Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1204,"":"downstairs"}
6852023-10-13T18:14:15.488Z{"msg":"[0] client ExtentReopen { repair_id: ReconciliationId(11), extent_id: 1 }","v":0,"name":"crucible","level":30,"time":"2023-10-13T18:14:14.750447718Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1204}
6862023-10-13T18:14:15.492Z{"msg":"[1] received reconcile message","v":0,"name":"crucible","level":30,"time":"2023-10-13T18:14:14.750482633Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1204}
6872023-10-13T18:14:15.495Z{"msg":"[1] rep_in_progress: return ReconcileIO { id: ReconciliationId(11), op: ExtentReopen { repair_id: ReconciliationId(11), extent_id: 1 }, state: ClientData([InProgress, InProgress, InProgress]) }","v":0,"name":"crucible","level":30,"time":"2023-10-13T18:14:14.75052492Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1204,"":"downstairs"}
6882023-10-13T18:14:15.499Z{"msg":"[1] client ExtentReopen { repair_id: ReconciliationId(11), extent_id: 1 }","v":0,"name":"crucible","level":30,"time":"2023-10-13T18:14:14.750564506Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1204}
6892023-10-13T18:14:15.502Z{"msg":"Completion from [1] id:11 status:true","v":0,"name":"crucible","level":30,"time":"2023-10-13T18:14:14.750600133Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1204}
6902023-10-13T18:14:15.506Z{"msg":"[12/20] Repair commands completed","v":0,"name":"crucible","level":30,"time":"2023-10-13T18:14:14.7506347Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1204}
6912023-10-13T18:14:15.510Z{"msg":"Pop front: ReconcileIO { id: ReconciliationId(12), op: ExtentFlush { repair_id: ReconciliationId(12), extent_id: 3, client_id: ClientId(0), flush_number: 1950, gen_number: 28 }, state: ClientData([New, New, New]) }","v":0,"name":"crucible","level":30,"time":"2023-10-13T18:14:14.750675389Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1204}
6922023-10-13T18:14:15.513Z{"msg":"Sent repair work, now wait for resp","v":0,"name":"crucible","level":30,"time":"2023-10-13T18:14:14.750712142Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1204}
6932023-10-13T18:14:15.516Z{"msg":"[2] received reconcile message","v":0,"name":"crucible","level":30,"time":"2023-10-13T18:14:14.750745626Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1204}
6942023-10-13T18:14:15.520Z{"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: 1950, gen_number: 28 }, state: ClientData([New, New, InProgress]) }","v":0,"name":"crucible","level":30,"time":"2023-10-13T18:14:14.750789224Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1204,"":"downstairs"}
6952023-10-13T18:14:15.524Z{"msg":"[2] client ExtentFlush { repair_id: ReconciliationId(12), extent_id: 3, client_id: ClientId(0), flush_number: 1950, gen_number: 28 }","v":0,"name":"crucible","level":30,"time":"2023-10-13T18:14:14.750833749Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1204}
6962023-10-13T18:14:15.532Z{"msg":"[0] received reconcile message","v":0,"name":"crucible","level":30,"time":"2023-10-13T18:14:14.750871519Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1204}
6972023-10-13T18:14:15.536Z{"msg":"[1] received reconcile message","v":0,"name":"crucible","level":30,"time":"2023-10-13T18:14:14.750905464Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1204}
6982023-10-13T18:14:15.540Z{"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: 1950, gen_number: 28 }, state: ClientData([InProgress, New, Done]) }","v":0,"name":"crucible","level":30,"time":"2023-10-13T18:14:14.750945509Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1204,"":"downstairs"}
6992023-10-13T18:14:15.544Z{"msg":"[0] client ExtentFlush { repair_id: ReconciliationId(12), extent_id: 3, client_id: ClientId(0), flush_number: 1950, gen_number: 28 }","v":0,"name":"crucible","level":30,"time":"2023-10-13T18:14:14.750970451Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1204}
7002023-10-13T18:14:15.547Z{"msg":"The guest has finished waiting for activation with:28
7012023-10-13T18:14:15.551Z[1] rep_in_progress: return ReconcileIO { id: ReconciliationId(12), op: ExtentFlush { repair_id: ReconciliationId(12), extent_id: 3, client_id: ClientId(0), flush_number: 1950, gen_number: 28 }, state: ClientData([InProgress, InProgress, Done]) }","v"Wait for a query_work_queue command to finish before sending IO
7022023-10-13T18:14:15.554Z:0,"name":"crucible","level":30,"time":"2023-10-13T18:14:14.864676598Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1204,"":"downstairs"}
7032023-10-13T18:14:15.558Z{"msg":"[1] client ExtentFlush { repair_id: ReconciliationId(12), extent_id: 3, client_id: ClientId(0), flush_number: 1950, gen_number: 28 }","v":0,"name":"crucible","level":30,"time":"2023-10-13T18:14:14.864706922Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1204}
7042023-10-13T18:14:15.561Z{"msg":"Completion from [0] id:12 status:true","v":0,"name":"crucible","level":30,"time":"2023-10-13T18:14:14.864724898Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1204}
7052023-10-13T18:14:15.565Z{"msg":"[13/20] Repair commands completed","v":0,"name":"crucible","level":30,"time":"2023-10-13T18:14:14.864742068Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1204}
7062023-10-13T18:14:15.569Z{"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-10-13T18:14:14.864762462Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1204}
7072023-10-13T18:14:15.573Z{"msg":"Sent repair work, now wait for resp","v":0,"name":"crucible","level":30,"time":"2023-10-13T18:14:14.864779719Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1204}
7082023-10-13T18:14:15.578Z{"msg":"[2] received reconcile message","v":0,"name":"crucible","level":30,"time":"2023-10-13T18:14:14.864796579Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1204}
7092023-10-13T18:14:15.582Z{"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-10-13T18:14:14.864817439Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1204,"":"downstairs"}
7102023-10-13T18:14:15.585Z{"msg":"[2] client ExtentClose { repair_id: ReconciliationId(13), extent_id: 3 }","v":0,"name":"crucible","level":30,"time":"2023-10-13T18:14:14.864836646Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1204}
7112023-10-13T18:14:15.589Z{"msg":"[0] received reconcile message","v":0,"name":"crucible","level":30,"time":"2023-10-13T18:14:14.864853885Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1204}
7122023-10-13T18:14:15.592Z{"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-10-13T18:14:14.864874552Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1204,"":"downstairs"}
7132023-10-13T18:14:15.596Z{"msg":"[0] client ExtentClose { repair_id: ReconciliationId(13), extent_id: 3 }","v":0,"name":"crucible","level":30,"time":"2023-10-13T18:14:14.864893685Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1204}
7142023-10-13T18:14:15.599Z{"msg":"[1] received reconcile message","v":0,"name":"crucible","level":30,"time":"2023-10-13T18:14:14.864910846Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1204}
7152023-10-13T18:14:15.602Z{"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-10-13T18:14:14.864931722Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1204,"":"downstairs"}
7162023-10-13T18:14:15.605Z{"msg":"[1] client ExtentClose { repair_id: ReconciliationId(13), extent_id: 3 }","v":0,"name":"crucible","level":30,"time":"2023-10-13T18:14:14.864950601Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1204}
7172023-10-13T18:14:15.608Z{"msg":"Completion from [1] id:13 status:true","v":0,"name":"crucible","level":30,"time":"2023-10-13T18:14:14.864967688Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1204}
7182023-10-13T18:14:15.611Z{"msg":"[14/20] Repair commands completed","v":0,"name":"crucible","level":30,"time":"2023-10-13T18:14:14.864984691Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1204}
7192023-10-13T18:14:15.615Z{"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(1), ClientId(2)] }, state: ClientData([New, New, New]) }","v":0,"name":"crucible","level":30,"time":"2023-10-13T18:14:14.865007979Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1204}
7202023-10-13T18:14:15.632Z{"msg":"Sent repair work, now wait for resp","v":0,"name":"crucible","level":30,"time":"2023-10-13T18:14:14.865024984Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1204}
7212023-10-13T18:14:16.052Z{"msg":"[2] received reconcile message","v":0,"name":"crucible","level":30,"time":"2023-10-13T18:14:14.86504166Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1204}
7222023-10-13T18:14:16.055Z{"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(1), ClientId(2)] }, state: ClientData([New, New, InProgress]) }","v":0,"name":"crucible","level":30,"time":"2023-10-13T18:14:14.865065146Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1204,"":"downstairs"}
7232023-10-13T18:14:16.059Z{"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(1), ClientId(2)] }","v":0,"name":"crucible","level":30,"time":"2023-10-13T18:14:14.865087227Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1204}
7242023-10-13T18:14:16.062Z{"msg":"[2] Sending repair request ReconciliationId(14)","v":0,"name":"crucible","level":30,"time":"2023-10-13T18:14:14.865104503Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1204}
7252023-10-13T18:14:16.068Z{"msg":"[0] received reconcile message","v":0,"name":"crucible","level":30,"time":"2023-10-13T18:14:14.865121272Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1204}
7262023-10-13T18:14:16.072Z{"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(1), ClientId(2)] }, state: ClientData([InProgress, New, InProgress]) }","v":0,"name":"crucible","level":30,"time":"2023-10-13T18:14:14.865144746Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1204,"":"downstairs"}
7272023-10-13T18:14:16.081Z{"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(1), ClientId(2)] }","v":0,"name":"crucible","level":30,"time":"2023-10-13T18:14:14.865166577Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1204}
7282023-10-13T18:14:16.087Z{"msg":"[0] No action required ReconciliationId(14)","v":0,"name":"crucible","level":30,"time":"2023-10-13T18:14:14.865183851Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1204}
7292023-10-13T18:14:16.091Z{"msg":"[1] received reconcile message","v":0,"name":"crucible","level":30,"time":"2023-10-13T18:14:14.865200792Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1204}
7302023-10-13T18:14:16.099Z{"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(1), ClientId(2)] }, state: ClientData([Done, InProgress, InProgress]) }","v":0,"name":"crucible","level":30,"time":"2023-10-13T18:14:14.865224495Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1204,"":"downstairs"}
7312023-10-13T18:14:16.106Z{"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(1), ClientId(2)] }","v":0,"name":"crucible","level":30,"time":"2023-10-13T18:14:14.865246325Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1204}
7322023-10-13T18:14:16.116Z{"Region: es:10 ec:5 bs:4096 ts:204800 tb:50 max_io:50 or 204800
7332023-10-13T18:14:16.124Zmsg":"[1] Sending repair request ReconciliationId(14)","v":0,"name":"crucible","level":30,"time":"2023-10-13T18:14:15.029598608Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1204}
7342023-10-13T18:14:16.131Z{"msg":"Completion from [1] id:14 status:true","v":0,"name":"crucible","level":30,"time":"2023-10-13T18:14:15.029638829Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1204}
7352023-10-13T18:14:16.140Z{"msg":"[15/20] Repair commands completed","v":0,"name":"crucible","level":30,"time":"2023-10-13T18:14:15.02965834Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1204}
7362023-10-13T18:14:16.150Z{"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-10-13T18:14:15.02968023Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1204}
7372023-10-13T18:14:16.159Z{"msg":"Sent repair work, now wait for resp","v":0,"name":"crucible","level":30,"time":"2023-10-13T18:14:15.029698046Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1204}
7382023-10-13T18:14:16.168Z{"msg":"[0] received reconcile message","v":0,"name":"crucible","level":30,"time":"2023-10-13T18:14:15.029715664Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1204}
7392023-10-13T18:14:16.187Z{"msg":"[0] rep_in_progress: return ReconcileIO { id: ReconciliationId(15), op: ExtentReopen { repair_id: ReconciliationId(15), extent_id: 3 }, state: ClientData([InProgress, New, New]) }","v":0,"name":"crucible","level":30,"time":"2023-10-13T18:14:15.029737482Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1204,"":"downstairs"}
7402023-10-13T18:14:16.210Z{"msg":"[1] received reconcile message","v":0,"name":"crucible","level":30,"time":"2023-10-13T18:14:15.029756656Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1204}
7412023-10-13T18:14:16.215Z{"msg":"[2] received reconcile message","v":0,"name":"crucible","level":30,"time":"2023-10-13T18:14:15.029773864Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1204}
7422023-10-13T18:14:16.219Z{"msg":"[1] rep_in_progress: return ReconcileIO { id: ReconciliationId(15), op: ExtentReopen { repair_id: ReconciliationId(15), extent_id: 3 }, state: ClientData([InProgress, InProgress, New]) }","v":0,"name":"crucible","level":30,"time":"Loading write count information from file "/var/tmp/test_up/verify_file"
7432023-10-13T18:14:16.222Z2023-10-13T18:14:15.02979509Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1204,"":"downstairs"}
7442023-10-13T18:14:16.226Z{"msg":"[1] client ExtentReopen { repair_id: ReconciliationId(15), extent_id: 3 }","v":0,"name":"crucible","level":30,"time":"2023-10-13T18:14:15.029822016Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1204}
7452023-10-13T18:14:16.230Z{"msg":"[0] client ExtentReopen { repair_id: ReconciliationId(15), extent_id: 3 }","v":0,"name":"crucible","level":30Read and Verify all blocks (0..50 range:true)
7462023-10-13T18:14:16.234Z,"time":"2023-10-13T18:14:15.029840714Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1204}
7472023-10-13T18:14:16.238Z{"msg":"[2] 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-10-13T18:14:15.029862651Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1204,"":"downstairs"}
7482023-10-13T18:14:16.241Z{"msg":"[2] client ExtentReopen { repair_id: ReconciliationId(15), extent_id: 3 }","v":0,"name":"crucible","level":30,"time":"2023-10-13T18:14:15.029882358Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1204}
7492023-10-13T18:14:16.244Z{"msg":"Completion from [0] id:15 status:true","v":0,"name":"crucible","level":30,"time":"2023-10-13T18:14:15.029899848Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1204}
7502023-10-13T18:14:16.247Z{"msg":"[16/20] Repair commands completed","v":0,"name":"crucible","level":30,"time":"2023-10-13T18:14:15.029916824Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1204}
7512023-10-13T18:14:16.251Z{"msg":"Pop front: ReconcileIO { id: ReconciliationId(16), op: ExtentFlush { repair_id: ReconciliationId(16), extent_id: 4, client_id: ClientId(0), flush_number: 1950, gen_number: 28 }, state: ClientData([New, New, New]) }","v":0,"name":"crucible","level":30,"time":"2023-10-13T18:14:15.029938729Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1204}
7522023-10-13T18:14:16.254Z{"msg":"Sent repair work, now wait for resp","v":0,"name":"crucible","level":30,"time":"2023-10-13T18:14:15.029956178Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1204}
7532023-10-13T18:14:16.258Z{"msg":"[2] received reconcile message","v":0,"name":"crucible","level":30,"time":"2023-10-13T18:14:15.030010691Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1204}
7542023-10-13T18:14:16.262Z{"msg":"[2] rep_in_progress: return ReconcileIO { id: ReconciliationId(16), op: ExtentFlush { repair_id: ReconciliationId(16), extent_id: 4, client_id: ClientId(0), flush_number: 1950, gen_number: 28 }, state: ClientData([New, New, InProgress]) }","v":0,"name":"crucible","level":30,"time":"2023-10-13T18:14:15.0300372Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1204,"":"downstairs"}
7552023-10-13T18:14:16.268Z{"msg":"[2] client ExtentFlush { repair_id: ReconciliationId(16), extent_id: 4, client_id: ClientId(0), flush_number: 1950, gen_number: 28 }","v":0,"name":"crucible","level":30,"time":"2023-10-13T18:14:15.030058923Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1204}
7562023-10-13T18:14:16.275Z{"msg":"[1] received reconcile message","v":0,"name":"crucible","level":30,"time":"2023-10-13T18:14:15.030076167Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1204}
7572023-10-13T18:14:16.703Z{"msg":"[0] received reconcile message","v":0,"name":"crucible","level":30,"time":"2023-10-13T18:14:15.030093338Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1204}
7582023-10-13T18:14:16.711Z{"msg":"[1] rep_in_progress: return ReconcileIO { id: ReconciliationId(16), op: ExtentFlush { repair_id: ReconciliationId(16), extent_id: 4, client_id: ClientId(0), flush_number: 1950, gen_number: 28 }, state: ClientData([New, InProgress, Done]) }","v":0,"name":"crucible","level":30,"time":"2023-10-13T18:14:15.030115854Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1204,"":"downstairs"}
7592023-10-13T18:14:16.720Z{"msg":"[1] client ExtentFlush { repair_id: ReconciliationId(16), extent_id: 4, client_id: ClientId(0), flush_number: 1950, gen_number: 28 }","v":0,"name":"crucible","level":30,"time":"2023-10-13T18:14:15.030136781Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1204}
7602023-10-13T18:14:16.727Z{"msg":"[0] rep_in_progress: return ReconcileIO { id: ReconciliationId(16), op: ExtentFlush { repair_id: ReconciliationId(16), extent_id: 4, client_id: ClientId(0), flush_number: 1950, gen_number: 28 }, state: ClientData([InProgress, InProgress, Done]) }","v":0,"name":"crucible","level":30,"time":"2023-10-13T18:14:15.03015978Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1204,"":"downstairs"}
7612023-10-13T18:14:16.736Z{"msg":"[0] client ExtentFlush { repair_id: ReconciliationId(16), extent_id: 4, client_id: ClientId(0), flush_number: 1950, gen_number: 28 }","v":0,"name":"crucible","level":30,"time":"2023-10-13T18:14:15.030180887Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1204}
7622023-10-13T18:14:16.750Z{"msg":"Completion from [0] id:16 status:true","v":0,"name":"crucible","level":30,"time":"2023-10-13T18:14:15.030198551Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1204}
7632023-10-13T18:14:16.754Z{"msg":"[17/20] Repair commands completed","v":0,"name":"crucible","level":30,"time":"2023-10-13T18:14:15.030215504Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1204}
7642023-10-13T18:14:16.758Z{"msg":"Pop front: ReconcileIO { id: ReconciliationId(17), op: ExtentClose { repair_id: ReconciliationId(17), extent_id: 4 }, state: ClientData([New, New, New]) }","v":0,"name":"crucible","level":30,"time":"2023-10-13T18:14:15.030235974Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1204}
7652023-10-13T18:14:16.763Z{"msg":"Sent repair work, now wait for resp","v":0,"name":"crucible","level":30,"time":"2023-10-13T18:14:15.030253449Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1204}
7662023-10-13T18:14:16.767Z{Wrote out file "/var/tmp/test_up/verify_file"
7672023-10-13T18:14:16.771Z"Verify test completed
7682023-10-13T18:14:16.775Zmsg":"[2] received reconcile message","v":0,"name":"crucible","level":30,"time":"2023-10-13T18:14:15.309948649Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1204}
7692023-10-13T18:14:16.779Z{"msg":"[2] rep_in_progress: return ReconcileIO { id: ReconciliationId(17), op: ExtentClose { repair_id: ReconciliationId(17), extent_id: 4 }, state: ClientData([New, New, InProgress]) }","v":0,"name":"crucible","level":30,"time":"2023-10-13T18:14:15.309995221Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1204,"":"downstairs"}
7702023-10-13T18:14:16.785Z{"msg":"[2] client ExtentClose { repair_id: ReconciliationId(17), extent_id: 4 }","v":0,"name":"crucible","level":30,"time":"2023-10-13T18:14:15.310017224Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1204}
7712023-10-13T18:14:16.789Z{"msg":"[0] received reconcile message","v":0,"name":"crucible","level":30,"time":"2023-10-13T18:14:15.31003545Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1204}
7722023-10-13T18:14:16.800Z{"msg":"[0] rep_in_progress: return ReconcileIO { id: ReconciliationId(17), op: ExtentClose { repair_id: ReconciliationId(17), extent_id: 4 }, state: ClientData([InProgress, New, InProgress]) }","v":0,"name":"crucible","level":30,"time":"2023-10-13T18:14:15.310057061Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1204,"":"downstairs"}
7732023-10-13T18:14:16.824Z{"msg":"[0] client ExtentClose { repair_id: ReconciliationId(17), extent_id: 4 }","v":0,"name":"crucible","level":30,"time":"2023-10-13T18:14:15.310076771Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1204}
7742023-10-13T18:14:16.830Z{"msg":"[1] received reconcile message","v":0,"name":"crucible","level":30,"time":"2023-10-13T18:14:15.310094038Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1204}
7752023-10-13T18:14:16.833Z{"msg":"[1] rep_in_progress: return ReconcileIO { id: ReconciliationId(17), op: ExtentClose { repair_id: ReconciliationId(17), extent_id: 4 }, state: ClientData([InProgress, InProgress, Done]) }","v":0,"name":"crucible","level":30,"time":"2023-10-13T18:14:15.310115474Z","hostname":"Wrote out file "/var/tmp/test_up/verify_file"
7762023-10-13T18:14:16.840Zip-10-150-1-58.us-west-2.compute.internal"CLIENT: Tests done. All submitted work has been ACK'd
7772023-10-13T18:14:16.844Z,"pid":1204,"":"downstairs"}
7782023-10-13T18:14:16.849Z{"msg":"[1] client ExtentClose { repair_id: ReconciliationId(17), extent_id: 4 }","v":0,"name":"crucible","level":30,"time":"2023-10-13T18:14:15.310141461Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1204}
7792023-10-13T18:14:16.869Z{"msg":"Completion from [0] id:17 status:true","v":0,"name":"crucible","level":30,"time":"2023-10-13T18:14:15.310159026Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1204}
7802023-10-13T18:14:17.287Z{"msg":"[18/20] Repair commands completed","v":0,"name":"crucible","level":30,"time":"2023-10-13T18:14:15.310176108Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1204}
7812023-10-13T18:14:17.290Z{"msg":"Pop front: ReconcileIO { id: ReconciliationId(18), op: ExtentRepair { repair_id: ReconciliationId(18), extent_id: 4, 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-10-13T18:14:15.310199177Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1204}
7822023-10-13T18:14:17.293Z{"msg":"Sent repair work, now wait for resp","v":0,"name":"crucible","level":30,"time":"2023-10-13T18:14:15.310216278Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1204}
7832023-10-13T18:14:17.296Z{"msg":"[2] received reconcile message","v":0,"name":"crucible","level":30,"time":"2023-10-13T18:14:15.3102333Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1204}
7842023-10-13T18:14:17.299Z{"msg":"[2] rep_in_progress: return ReconcileIO { id: ReconciliationId(18), op: ExtentRepair { repair_id: ReconciliationId(18), extent_id: 4, 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-10-13T18:14:15.310257351Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1204,"":"downstairs"}
7852023-10-13T18:14:17.304Z{----------------------------------------------------------------
7862023-10-13T18:14:17.308Z" Crucible gen:28 GIO:true work queues: Upstairs:0 downstairs:0
7872023-10-13T18:14:17.315Z
7882023-10-13T18:14:17.320Zmsg":"[2] client ExtentRepair { repair_id: ReconciliationId(18), extent_id: 4, source_client_id: ClientId(0), source_repair_address: 0.0.0.0:12810, dest_clients: [ClientId(1), ClientId(2)] }","v":0,"name":"crucibleDownstairs last five completed:","level":30 1001 1000
7892023-10-13T18:14:17.325Zreal 5:10.395777206
7902023-10-13T18:14:17.329Z,"time":"2023-10-13T18:14:15.310287032Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1204}Upstairs last five completed:
7912023-10-13T18:14:17.332Zuser 4:26.681279223
7922023-10-13T18:14:17.336Z{"msg":"[2] Sending repair request ReconciliationId(18)","v":0,"name":"crucible","level":30 2 1
7932023-10-13T18:14:17.340Zsys 20.114893658
7942023-10-13T18:14:17.344Z,"time":"2023-10-13T18:14:15.310305681Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1204}
7952023-10-13T18:14:17.348Ztrap 0.298680092
7962023-10-13T18:14:17.352Z{"msg":"[0] received reconcile message","v":0,"name":"crucible","level":30,"time":"2023-10-13T18:14:15.310322907Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1204}
7972023-10-13T18:14:17.356Ztflt 0.151780843
7982023-10-13T18:14:17.360Z{"msg":"[0] rep_in_progress: return ReconcileIO { id: ReconciliationId(18), op: ExtentRepair { repair_id: ReconciliationId(18), extent_id: 4, 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-10-13T18:14:15.310346705Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1204,"":"downstairs"}
7992023-10-13T18:14:17.364Zdflt 0.061604828
8002023-10-13T18:14:17.367Z{"msg":"[0] client ExtentRepair { repair_id: ReconciliationId(18), extent_id: 4, source_client_id: ClientId(0), source_repair_address: 0.0.0.0:12810, dest_clients: [ClientId(1), ClientId(2)] }","v":0,"name":"crucible","level":30CLIENT: Up:0 ds:0 act:3
8012023-10-13T18:14:17.371Zkflt 0.000829131
8022023-10-13T18:14:17.375Z,"CLIENT: All crucible jobs finished, exiting program
8032023-10-13T18:14:17.379Zlock 47:39.002436747
8042023-10-13T18:14:17.386Ztime":"2023-10-13T18:14:15.310368932Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1204}
8052023-10-13T18:14:17.390Zslp 9:41.554053366
8062023-10-13T18:14:17.394Z{"msg":"[0] No action required ReconciliationId(18)","v":0,"name":"crucible","level":30,"time":"2023-10-13T18:14:15.310390535Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1204}
8072023-10-13T18:14:17.399Zlat 16.081785877
8082023-10-13T18:14:17.403Z{"msg":"[1] received reconcile message","v":0,"name":"crucible","level":30,"time":"2023-10-13T18:14:15.310407701Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1204}
8092023-10-13T18:14:17.406Zstop 0.026644544
8102023-10-13T18:14:17.410Z{"msg":"[1] rep_in_progress: return ReconcileIO { id: ReconciliationId(18), op: ExtentRepair { repair_id: ReconciliationId(18), extent_id: 4, 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-10-13T18:14:15.310431347Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1204,"":"downstairs"}
8112023-10-13T18:14:17.413Z{"msg":"[1] client ExtentRepair { repair_id: ReconciliationId(18), extent_id: 4, 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-10-13T18:14:15.31045359Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1204}
8122023-10-13T18:14:17.418Z{"msg":"[1] Sending repair request ReconciliationId(18)","v":0,"name":"crucible","level":30,"time":"2023-10-13T18:14:15.310471496Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1204}
8132023-10-13T18:14:17.422Z{"msg":"Completion from [1] id:18 status:true","v":0,"name":"crucible","level":30,"time":"2023-10-13T18:14:15.310488499Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1204}
8142023-10-13T18:14:17.426Z{"msg":"[19/20] Repair commands completed","v":0,"name":"crucible","level":30,"time":"2023-10-13T18:14:15.310511024Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1204}
8152023-10-13T18:14:17.430Z{"msg":"Pop front: ReconcileIO { id: ReconciliationId(19), op: ExtentReopen { repair_id: ReconciliationId(19), extent_id: 4 }, state: ClientData([New, New, New]) }","v":0,"name":"crucible","level":30,"time":"2023-10-13T18:14:15.310547353Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1204}
8162023-10-13T18:14:17.434Z{"msg":"Sent repair work, now wait for resp","v":0,"name":"crucible","level":30,"time":"2023-10-13T18:14:15.310581434Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1204}
8172023-10-13T18:14:17.438Z{"msg":"[2] received reconcile message","v":0,"name":"crucible","level":30,"time":"2023-10-13T18:14:15.310614025Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1204}
8182023-10-13T18:14:17.442Z{"msg":"[2] rep_in_progress: return ReconcileIO { id: ReconciliationId(19), op: ExtentReopen { repair_id: ReconciliationId(19), extent_id: 4 }, state: ClientData([New, New, InProgress]) }","v":0,"name":"crucible","level":30,"time":"2023-10-13T18:14:15.427243077Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1204,"":"downstairs"}
8192023-10-13T18:14:17.445Z{"msg":"[2] client ExtentReopen { repair_id: ReconciliationId(19), extent_id: 4 }","v":0,"name":"crucible","level":30,"time":"2023-10-13T18:14:15.427279646Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1204}
8202023-10-13T18:14:17.449Z{"msg":"[0] received reconcile message","v":0,"name":"crucible","level":30,"time":"2023-10-13T18:14:15.427298324Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1204}
8212023-10-13T18:14:17.453Z{"msg":"[0] rep_in_progress: return ReconcileIO { id: ReconciliationId(19), op: ExtentReopen { repair_id: ReconciliationId(19), extent_id: 4 }, state: ClientData([InProgress, New, InProgress]) }","v":0,"name":"crucible","level":30,"time":"2023-10-13T18:14:15.427320008Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1204,"":"downstairs"}
8222023-10-13T18:14:17.456Z{"msg":"[0] client ExtentReopen { repair_id: ReconciliationId(19), extent_id: 4 }","v":0,"name":"crucible","level":30,"time":"2023-10-13T18:14:15.427339453Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1204}
8232023-10-13T18:14:17.460Z{"msg":"[1] received reconcile message","v":0,"name":"crucible","level":30,"time":"2023-10-13T18:14:15.427356973Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1204}
8242023-10-13T18:14:17.464Z{"msg":"[1] rep_in_progress: return ReconcileIO { id: ReconciliationId(19), op: ExtentReopen { repair_id: ReconciliationId(19), extent_id: 4 }, state: ClientData([InProgress, InProgress, InProgress]) }","v":0,"name":"crucible","level":30,"time":"2023-10-13T18:14:15.427378243Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1204,"":"downstairs"}
8252023-10-13T18:14:17.468Z{"msg":"[1] client ExtentReopen { repair_id: ReconciliationId(19), extent_id: 4 }","v":0,"name":"crucible","level":30,"time":"2023-10-13T18:14:15.427398369Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1204}
8262023-10-13T18:14:17.476Z{"msg":"Completion from [1] id:19 status:true","v":0,"name":"crucible","level":30,"time":"2023-10-13T18:14:15.427415855Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1204}
8272023-10-13T18:14:17.479Z{"msg":"[20/20] Repair commands completed","v":0,"name":"crucible","level":30,"time":"2023-10-13T18:14:15.427432826Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1204}
8282023-10-13T18:14:17.482Z{"msg":"5 extents repaired in 1.437 ave:0.2873","v":0,"name":"crucible","level":30,"time":"2023-10-13T18:14:15.42744976Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1204}
8292023-10-13T18:14:17.486Z{"msg":"All required repair work is completed","v":0,"name":"crucible","level":30,"time":"2023-10-13T18:14:15.427466901Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1204}
8302023-10-13T18:14:17.489Z{"msg":"Set Downstairs and Upstairs active after repairs","v":0,"name":"crucible","level":30,"time":"2023-10-13T18:14:15.427484189Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1204}
8312023-10-13T18:14:17.492Z{"msg":"f231106b-141e-4f7e-aae5-1762578fb505 is now active with session: ab49641b-96ea-4185-9698-f085775a74ab","v":0,"name":"crucible","level":30,"time":"2023-10-13T18:14:15.427502955Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1204}
8322023-10-13T18:14:17.495Z{"msg":"Notify all downstairs, region set compare is done.","v":0,"name":"crucible","level":30,"time":"2023-10-13T18:14:15.427520799Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1204}
8332023-10-13T18:14:17.498Z{"msg":"Set check for repair","v":0,"name":"crucible","level":30,"time":"2023-10-13T18:14:15.427537703Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1204}
8342023-10-13T18:14:17.503Z{"msg":"[0] received reconcile message","v":0,"name":"crucible","level":30,"time":"2023-10-13T18:14:15.427554715Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1204}
8352023-10-13T18:14:17.506Z{"msg":"[2] received reconcile message","v":0,"name":"crucible","level":30,"time":"2023-10-13T18:14:15.427571539Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1204}
8362023-10-13T18:14:17.510Z{"msg":"[0] All repairs completed, exit","v":0,"name":"crucible","level":30,"time":"2023-10-13T18:14:15.427588322Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1204}
8372023-10-13T18:14:17.514Z{"msg":"[2] All repairs completed, exit","v":0,"name":"crucible","level":30,"time":"2023-10-13T18:14:15.427604904Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1204}
8382023-10-13T18:14:17.517Z{"msg":"[0] Starts cmd_loop","v":0,"name":"crucible","level":30,"time":"2023-10-13T18:14:15.427621101Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1204}
8392023-10-13T18:14:17.520Z{"msg":"[2] Starts cmd_loop","v":0,"name":"crucible","level":30,"time":"2023-10-13T18:14:15.427637294Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1204}
8402023-10-13T18:14:17.523Z{"msg":"[1] received reconcile message","v":0,"name":"crucible","level":30,"time":"2023-10-13T18:14:15.427654261Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1204}
8412023-10-13T18:14:17.525Z{"msg":"[1] All repairs completed, exit","v":0,"name":"crucible","level":30,"time":"2023-10-13T18:14:15.427671096Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1204}
8422023-10-13T18:14:17.531Z{"msg":"[1] Starts cmd_loop","v":0,"name":"crucible","level":30,"time":"2023-10-13T18:14:15.427687513Z","hostname":"ip-10-150-1-58.us-west-2.compute.internal","pid":1204}
8432023-10-13T18:14:17.535ZRepair part 2 passed
8442023-10-13T18:14:17.538Z/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
8452023-10-13T18:14:17.541ZEXT BLOCKS GEN0 GEN1 GEN2 FL0 FL1 FL2 D0 D1 D2 DIFF
8462023-10-13T18:14:17.544Z 0 000-009 28 28 28 1950 1950 1950 F F F
8472023-10-13T18:14:17.592Z 1 010-019 28 28 28 1950 1950 1950 F F F
8482023-10-13T18:14:17.596Z 2 020-029 28 28 28 1950 1950 1950 F F F
8492023-10-13T18:14:17.600Z 3 030-039 28 28 28 1950 1950 1950 F F F
8502023-10-13T18:14:17.604Z 4 040-049 28 28 28 1950 1950 1950 F F F
8512023-10-13T18:14:17.607ZMax gen: 28, Max flush: 1950
8522023-10-13T18:14:17.612Zdump test passed
8532023-10-13T18:14:17.623Z/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
8542023-10-13T18:14:17.646Z Extent 1
8552023-10-13T18:14:17.670ZGEN 28 28 28
8562023-10-13T18:14:17.685ZFLUSH_ID 1950 1950 1950
8572023-10-13T18:14:18.109ZDIRTY
8582023-10-13T18:14:18.123Z
8592023-10-13T18:14:18.138ZBLOCK D0 D1 D2 C0 C1 C2 DIFF
8602023-10-13T18:14:18.156Z010 A A A A A A
8612023-10-13T18:14:18.172Z011 A A A A A A
8622023-10-13T18:14:18.233Z012 A A A A A A
8632023-10-13T18:14:18.259Z013 A A A A A A
8642023-10-13T18:14:18.279Z014 A A A A A A
8652023-10-13T18:14:18.296Z015 A A A A A A
8662023-10-13T18:14:18.721Z016 A A A A A A
8672023-10-13T18:14:18.725Z017 A A A A A A
8682023-10-13T18:14:18.728Z018 A A A A A A
8692023-10-13T18:14:18.731Z019 A A A A A A
8702023-10-13T18:14:18.734Zdump extent test passed
8712023-10-13T18:14:18.737Z/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
8722023-10-13T18:14:18.740ZExtent 2 Block in extent 0 Actual block 20
8732023-10-13T18:14:18.744Z
8742023-10-13T18:14:18.750Z DATA SHA256 VER
8752023-10-13T18:14:18.764Z------ ---------------------------------------------------------------- ---
8762023-10-13T18:14:18.779Z 0 686741f7460d36c0138221ab33bbd9e205831ecc42e747b2d343cc49dd94e7fa A
8772023-10-13T18:14:18.797Z 1 686741f7460d36c0138221ab33bbd9e205831ecc42e747b2d343cc49dd94e7fa A
8782023-10-13T18:14:18.812Z 2 686741f7460d36c0138221ab33bbd9e205831ecc42e747b2d343cc49dd94e7fa A
8792023-10-13T18:14:18.827Z
8802023-10-13T18:14:18.845ZNONCES 0 1 2 DIFF
8812023-10-13T18:14:18.862Z------ ------------------------ ------------------------ ------------------------ -----
8822023-10-13T18:14:18.877Z 0 b9fb3235572be1efc738ea00 b9fb3235572be1efc738ea00 b9fb3235572be1efc738ea00
8832023-10-13T18:14:18.890Z
8842023-10-13T18:14:18.907Z TAGS 0 1 2 DIFF
8852023-10-13T18:14:18.926Z------ -------------------------------- -------------------------------- -------------------------------- -----
8862023-10-13T18:14:19.402Z 0 ed9d7622e009eb4443a6feda6ed482ae ed9d7622e009eb4443a6feda6ed482ae ed9d7622e009eb4443a6feda6ed482ae
8872023-10-13T18:14:19.410Z
8882023-10-13T18:14:19.415ZHASHES 0 1 2 DIFF
8892023-10-13T18:14:19.419Z------ ---------------- ---------------- ---------------- -----
8902023-10-13T18:14:19.423Z 0 3318092a8ddd89cb 3318092a8ddd89cb 3318092a8ddd89cb
8912023-10-13T18:14:19.427Z
8922023-10-13T18:14:19.431Zdump block test passed
8932023-10-13T18:14:19.436ZUpstairs tests have completed, stopping all downstairs
8942023-10-13T18:14:19.439Z
8952023-10-13T18:14:19.443ZAll Tests have passed
8962023-10-13T18:14:19.447Z5:11 Test duration
8972023-10-13T18:14:19.453Zprocess exited: duration 322746 ms, exit code 0
 
8982023-10-13T18:14:19.496Zfound 5 output files
8992023-10-13T18:14:19.527Zuploading: /tmp/test_up/dsc-out.txt (4483 bytes)
9002023-10-13T18:14:20.598Zuploaded: /tmp/test_up/dsc-out.txt
9012023-10-13T18:14:20.608Zuploading: /tmp/test_up/test_up_out.txt (3507118 bytes)
9022023-10-13T18:14:22.980Zuploaded: /tmp/test_up/test_up_out.txt
9032023-10-13T18:14:23.006Zuploading: /tmp/test_up/dsc/downstairs-8810.txt (68557 bytes)
9042023-10-13T18:14:24.095Zuploaded: /tmp/test_up/dsc/downstairs-8810.txt
9052023-10-13T18:14:24.128Zuploading: /tmp/test_up/dsc/downstairs-8820.txt (60907 bytes)
9062023-10-13T18:14:25.180Zuploaded: /tmp/test_up/dsc/downstairs-8820.txt
9072023-10-13T18:14:25.187Zuploading: /tmp/test_up/dsc/downstairs-8830.txt (10939 bytes)
9082023-10-13T18:14:26.223Zuploaded: /tmp/test_up/dsc/downstairs-8830.txt