01HCKKW0YHGQDRH4TBF3NRKRKF: test-up-unencrypted

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

Tags:

Artefacts:

Output:

SEQ GLOBAL TIME DETAILS
12023-10-13T04:38:17.760Zjob dependencies complete; ready to run (waiting for 22 m 44 s)
22023-10-13T04:41:19.757Zjob assigned to worker 01HCKNBEQSH08P7ZM4AJ1TJMRF (queued for 3 m 1 s)
32023-10-13T04:41:21.119Zdownloading input: /input/build/work/bins/crucible-downstairs.gz
42023-10-13T04:41:46.228Zdownloaded input: /input/build/work/bins/crucible-downstairs.gz
52023-10-13T04:41:46.241Zdownloading input: /input/build/work/bins/crucible-hammer.gz
62023-10-13T04:41:58.238Zdownloaded input: /input/build/work/bins/crucible-hammer.gz
72023-10-13T04:41:58.256Zdownloading input: /input/build/work/bins/crutest.gz
82023-10-13T04:42:13.402Zdownloaded input: /input/build/work/bins/crutest.gz
92023-10-13T04:42:13.413Zdownloading input: /input/build/work/bins/dsc.gz
102023-10-13T04:42:25.215Zdownloaded input: /input/build/work/bins/dsc.gz
112023-10-13T04:42:25.310Zdownloading input: /input/build/work/scripts/test_ds.sh
122023-10-13T04:42:25.593Zdownloaded input: /input/build/work/scripts/test_ds.sh
132023-10-13T04:42:25.649Zdownloading input: /input/build/work/scripts/test_live_repair.sh
142023-10-13T04:42:25.760Zdownloaded input: /input/build/work/scripts/test_live_repair.sh
152023-10-13T04:42:25.894Zdownloading input: /input/build/work/scripts/test_repair.sh
162023-10-13T04:42:25.943Zdownloaded input: /input/build/work/scripts/test_repair.sh
172023-10-13T04:42:25.972Zdownloading input: /input/build/work/scripts/test_replay.sh
182023-10-13T04:42:26.509Zdownloaded input: /input/build/work/scripts/test_replay.sh
192023-10-13T04:42:26.546Zdownloading input: /input/build/work/scripts/test_up.sh
202023-10-13T04:42:26.560Zdownloaded input: /input/build/work/scripts/test_up.sh
212023-10-13T04:42:26.582Zdownloading input: /input/build/tmp/cargo-test-out.log
222023-10-13T04:42:28.305Zdownloaded input: /input/build/tmp/cargo-test-out.log
 
232023-10-13T04:42:28.318Zstarting task 0: "setup"
242023-10-13T04:42:28.468Z++ uname -s
252023-10-13T04:42:28.480Z+ kern=SunOS
262023-10-13T04:42:28.495Z+ case "$kern" in
272023-10-13T04:42:28.501Z+ groupadd -g 12345 build
282023-10-13T04:42:28.515Z+ useradd -u 12345 -g build -d /home/build -s /bin/bash -c build -P 'Primary Administrator' build
292023-10-13T04:42:30.482Z+ zfs create -o mountpoint=/work rpool/work
302023-10-13T04:42:30.576Z++ awk '$2 == "/home" { print $3 }' /etc/mnttab
312023-10-13T04:42:30.581Z+ home_fs=zfs
322023-10-13T04:42:30.591Z+ [[ zfs == autofs ]]
332023-10-13T04:42:30.596Z+ mkdir -p /home/build
342023-10-13T04:42:30.603Z+ chown build:build /home/build /work
352023-10-13T04:42:31.585Z+ chmod 0700 /home/build /work
362023-10-13T04:42:31.592Zprocess exited: duration 3257 ms, exit code 0
 
372023-10-13T04:42:31.623Zstarting task 1: "authentication"
382023-10-13T04:42:31.653Zprocess exited: duration 24 ms, exit code 0
 
392023-10-13T04:42:31.659Zstarting task 2: "build"
402023-10-13T04:42:31.668Z+ banner cores
412023-10-13T04:42:31.708Z
422023-10-13T04:42:31.714Z #### #### ##### ###### ####
432023-10-13T04:42:31.719Z # # # # # # # #
442023-10-13T04:42:31.729Z # # # # # ##### ####
452023-10-13T04:42:31.739Z # # # ##### # #
462023-10-13T04:42:31.749Z # # # # # # # # #
472023-10-13T04:42:31.759Z #### #### # # ###### ####
482023-10-13T04:42:31.765Z
492023-10-13T04:42:31.778Z+ pfexec coreadm -i /tmp/core.%f.%p -g /tmp/core.%f.%p -e global -e log -e proc-setid -e global-setid
502023-10-13T04:42:31.788Z+ echo 'input bins dir contains:'
512023-10-13T04:42:31.796Zinput bins dir contains:
522023-10-13T04:42:31.807Z+ ls -ltr /input/build/work/bins
532023-10-13T04:42:31.814Ztotal 697495
542023-10-13T04:42:31.825Z-rw-r--r-- 1 root root 107725299 Oct 13 04:41 crucible-downstairs.gz
552023-10-13T04:42:31.842Z-rw-r--r-- 1 root root 85722441 Oct 13 04:41 crucible-hammer.gz
562023-10-13T04:42:31.852Z-rw-r--r-- 1 root root 95189178 Oct 13 04:42 crutest.gz
572023-10-13T04:42:31.858Z-rw-r--r-- 1 root root 68233986 Oct 13 04:42 dsc.gz
582023-10-13T04:42:31.868Z+ banner unpack
592023-10-13T04:42:31.882Z
602023-10-13T04:42:31.891Z # # # # ##### ## #### # #
612023-10-13T04:42:31.900Z # # ## # # # # # # # # #
622023-10-13T04:42:31.908Z # # # # # # # # # # ####
632023-10-13T04:42:31.917Z # # # # # ##### ###### # # #
642023-10-13T04:42:31.922Z # # # ## # # # # # # #
652023-10-13T04:42:31.927Z #### # # # # # #### # #
662023-10-13T04:42:31.934Z
672023-10-13T04:42:31.939Z+ mkdir -p /var/tmp/bins
682023-10-13T04:42:31.946Z+ for t in "$input/bins/"*.gz
692023-10-13T04:42:31.951Z++ basename /input/build/work/bins/crucible-downstairs.gz
702023-10-13T04:42:31.956Z+ b=crucible-downstairs.gz
712023-10-13T04:42:31.964Z+ b=crucible-downstairs
722023-10-13T04:42:31.970Z+ gunzip
732023-10-13T04:42:35.533Z+ chmod +x /var/tmp/bins/crucible-downstairs
742023-10-13T04:42:35.543Z+ for t in "$input/bins/"*.gz
752023-10-13T04:42:35.550Z++ basename /input/build/work/bins/crucible-hammer.gz
762023-10-13T04:42:35.555Z+ b=crucible-hammer.gz
772023-10-13T04:42:35.566Z+ b=crucible-hammer
782023-10-13T04:42:35.585Z+ gunzip
792023-10-13T04:42:38.481Z+ chmod +x /var/tmp/bins/crucible-hammer
802023-10-13T04:42:38.488Z+ for t in "$input/bins/"*.gz
812023-10-13T04:42:38.506Z++ basename /input/build/work/bins/crutest.gz
822023-10-13T04:42:38.512Z+ b=crutest.gz
832023-10-13T04:42:38.519Z+ b=crutest
842023-10-13T04:42:38.527Z+ gunzip
852023-10-13T04:42:41.796Z+ chmod +x /var/tmp/bins/crutest
862023-10-13T04:42:41.800Z+ for t in "$input/bins/"*.gz
872023-10-13T04:42:41.804Z++ basename /input/build/work/bins/dsc.gz
882023-10-13T04:42:41.808Z+ b=dsc.gz
892023-10-13T04:42:41.813Z+ b=dsc
902023-10-13T04:42:41.817Z+ gunzip
912023-10-13T04:42:44.116Z+ chmod +x /var/tmp/bins/dsc
922023-10-13T04:42:44.124Z+ export BINDIR=/var/tmp/bins
932023-10-13T04:42:44.132Z+ BINDIR=/var/tmp/bins
942023-10-13T04:42:44.157Z+ banner test_up_unencrypted
952023-10-13T04:42:44.171Z
962023-10-13T04:42:44.179Z ##### ###### #### ##### # # ##### # # # #
972023-10-13T04:42:44.196Z # # # # # # # # # # ## #
982023-10-13T04:42:44.207Z # ##### #### # # # # # # # # # #
992023-10-13T04:42:44.214Z # # # # # # ##### # # # # #
1002023-10-13T04:42:44.229Z # # # # # # # # # # # ##
1012023-10-13T04:42:44.235Z # ###### #### # ####### #### # ####### #### # #
1022023-10-13T04:42:44.241Z
1032023-10-13T04:42:44.249Z+ ptime -m bash /input/build/work/scripts/test_up.sh -N unencrypted
1042023-10-13T04:42:44.261Z/input/build/work
1052023-10-13T04:42:44.280ZTurn off color for downstairs dump
1062023-10-13T04:42:44.342Zdsc output goes to /tmp/test_up/dsc-out.txt
1072023-10-13T04:42:44.358ZCreating three downstairs regions
1082023-10-13T04:42:44.584ZStarting three downstairs
1092023-10-13T04:42:50.506ZDisable automatic restart on all downstairs
1102023-10-13T04:42:50.546Z
1112023-10-13T04:42:50.580ZBegin tests, output goes to /tmp/test_up/test_up_out.txt
1122023-10-13T04:42:50.593ZRunning test: span
1132023-10-13T04:42:53.873ZCompleted test: span
1142023-10-13T04:42:53.908ZRunning test: big
1152023-10-13T04:42:58.239ZCompleted test: big
1162023-10-13T04:42:58.246ZRunning test: dep
1172023-10-13T04:43:35.580ZCompleted test: dep
1182023-10-13T04:43:35.592ZRunning test: balloon
1192023-10-13T04:44:05.889ZCompleted test: balloon
1202023-10-13T04:44:05.964ZRunning test: deactivate
1212023-10-13T04:44:21.128ZCompleted test: deactivate
1222023-10-13T04:44:21.340ZRunning hammer
1232023-10-13T04:44:27.908ZRun repair tests
1242023-10-13T04:44:27.917Z/var/tmp/bins/crutest fill -g 26 -q -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
1252023-10-13T04:44:27.931Z{"msg":"Upstairs starts","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:44:27.922408856Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1187}
1262023-10-13T04:44:27.945Z{"msg":"Crucible Version: BuildInfo {\n version: \"0.0.1\",\n git_sha: \"0a6b3facda3a9a8c75c70b591db2d34571e435e8\",\n git_commit_timestamp: \"2023-10-13T04:02:07.000000000Z\",\n git_branch: \"alan/unwrapless\",\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-13T04:44:27.92282715Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1187}
1272023-10-13T04:44:28.371Z{"msg":"Upstairs <-> Downstairs Message Version: 4","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:44:27.922877624Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1187}
1282023-10-13T04:44:28.381Z{"msg":"Upstairs opts: Upstairs UUID: b869de47-53a4-4c5c-b1a2-a976d57d8d3d, Targets: [127.0.0.1:8810, 127.0.0.1:8820, 127.0.0.1:8830], lossy: false, flush_timeout: None, key populated: false, cert_pem populated: false, key_pem populated: false, root_cert_pem populated: false, Control: None, read_only: false","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:44:27.922906657Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1187}
1292023-10-13T04:44:28.410Z{"msg":"Crucible stats registered with UUID: b869de47-53a4-4c5c-b1a2-a976d57d8d3d","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:44:27.922949063Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1187}
1302023-10-13T04:44:28.420Z{"msg":"Crucible b869de47-53a4-4c5c-b1a2-a976d57d8d3d has session id: 9d443e27-9c19-4127-bfea-b663840e5532","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:44:27.922976423Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1187}
1312023-10-13T04:44:28.431ZCrucible runtime is spawned
1322023-10-13T04:44:28.442Z{"msg":"up_listen starts","v":0,"name":"crucible","level":30The guest has requested activation with gen:26
1332023-10-13T04:44:28.858Z,"time":"2023-10-13T04:44:27.923293649Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1187,"task":"up_listen"}
1342023-10-13T04:44:28.865Z{"msg":"Wait for all three downstairs to come online","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:44:27.923408232Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1187}
1352023-10-13T04:44:28.876Z{"msg":"Flush timeout: 0.5","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:44:27.923456248Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1187}
1362023-10-13T04:44:28.888Z{"msg":"[0] connecting to 127.0.0.1:8810","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:44:27.923476689Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1187,"looper":"0"}
1372023-10-13T04:44:28.906Z{"msg":"[0] b869de47-53a4-4c5c-b1a2-a976d57d8d3d looper connected","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:44:27.923671812Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1187,"looper":"0"}
1382023-10-13T04:44:28.925Z{"msg":"[1] connecting to 127.0.0.1:8820","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:44:27.923754311Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1187,"looper":"1"}
1392023-10-13T04:44:28.942Z{"msg":"[2] connecting to 127.0.0.1:8830","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:44:27.923879389Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1187,"looper":"2"}
1402023-10-13T04:44:28.969Z{"msg":"[1] b869de47-53a4-4c5c-b1a2-a976d57d8d3d looper connected","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:44:27.923982547Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1187,"looper":"1"}
1412023-10-13T04:44:28.981Z{"msg":"[2] b869de47-53a4-4c5c-b1a2-a976d57d8d3d looper connected","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:44:27.924059119Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1187,"looper":"2"}
1422023-10-13T04:44:28.991Z{"msg":"b869de47-53a4-4c5c-b1a2-a976d57d8d3d active request set","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:44:27.924508212Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1187}
1432023-10-13T04:44:29.025Z{"msg":"Set desired generation to :26","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:44:27.924558133Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1187}
1442023-10-13T04:44:29.139Z{"msg":"[0] Proc runs for 127.0.0.1:8810 in state New","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:44:27.924699847Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1187}
1452023-10-13T04:44:29.170Z{"msg":"[1] Proc runs for 127.0.0.1:8820 in state New","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:44:27.925011421Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1187}
1462023-10-13T04:44:29.177Z{"msg":"[2] Proc runs for 127.0.0.1:8830 in state New","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:44:27.925065407Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1187}
1472023-10-13T04:44:29.185Z{"msg":"[0] b869de47-53a4-4c5c-b1a2-a976d57d8d3d (3f91dcf1-5e04-456f-a27d-9275e14fd7ec) New New New ds_transition to WaitActive","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:44:27.925384658Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1187}
1482023-10-13T04:44:29.258Z{"msg":"[0] Transition from New to WaitActive","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:44:27.925537008Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1187}
1492023-10-13T04:44:29.285Z{"msg":"[0] client is_active_req TRUE, promote! session 3f91dcf1-5e04-456f-a27d-9275e14fd7ec","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:44:27.925612768Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1187}
1502023-10-13T04:44:29.345Z{"msg":"[2] b869de47-53a4-4c5c-b1a2-a976d57d8d3d (3f91dcf1-5e04-456f-a27d-9275e14fd7ec) WaitActive New New ds_transition to WaitActive","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:44:27.925637743Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1187}
1512023-10-13T04:44:29.395Z{"msg":"[2] Transition from New to WaitActive","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:44:27.925667658Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1187}
1522023-10-13T04:44:30.265Z{"msg":"[2] client is_active_req TRUE, promote! session 3f91dcf1-5e04-456f-a27d-9275e14fd7ec","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:44:27.925757178Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1187}
1532023-10-13T04:44:30.301Z{"msg":"[1] b869de47-53a4-4c5c-b1a2-a976d57d8d3d (3f91dcf1-5e04-456f-a27d-9275e14fd7ec) WaitActive New WaitActive ds_transition to WaitActive","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:44:27.925878685Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1187}
1542023-10-13T04:44:30.332Z{"msg":"[1] Transition from New to WaitActive","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:44:27.926013073Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1187}
1552023-10-13T04:44:30.349Z{"msg":"[1] client is_active_req TRUE, promote! session 3f91dcf1-5e04-456f-a27d-9275e14fd7ec","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:44:27.926072891Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1187}
1562023-10-13T04:44:30.362Z{"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-13T04:44:27.926286584Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1187}
1572023-10-13T04:44:30.368Z{"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-13T04:44:27.926344141Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1187}
1582023-10-13T04:44:30.375Z{"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-13T04:44:27.926401999Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1187}
1592023-10-13T04:44:30.385Z{"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: false, database_read_version: 1, database_write_version: 1 }","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:44:27.926451531Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1187}
1602023-10-13T04:44:30.389Z{"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: false, database_read_version: 1, database_write_version: 1 }","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:44:27.926551242Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1187}
1612023-10-13T04:44:30.394Z{"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: false, database_read_version: 1, database_write_version: 1 }","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:44:27.926631421Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1187}
1622023-10-13T04:44:30.400Z{"msg":"b869de47-53a4-4c5c-b1a2-a976d57d8d3d WaitActive WaitActive WaitActive","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:44:27.926709174Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1187}
1632023-10-13T04:44:30.407Z{"msg":"b869de47-53a4-4c5c-b1a2-a976d57d8d3d WaitActive WaitActive WaitActive","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:44:27.926754388Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1187}
1642023-10-13T04:44:30.415Z{"msg":"b869de47-53a4-4c5c-b1a2-a976d57d8d3d WaitActive WaitActive WaitActive","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:44:27.926977278Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1187}
1652023-10-13T04:44:30.421Z{"msg":"[1] b869de47-53a4-4c5c-b1a2-a976d57d8d3d (3f91dcf1-5e04-456f-a27d-9275e14fd7ec) WaitActive WaitActive WaitActive ds_transition to WaitQuorum","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:44:27.927044312Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1187}
1662023-10-13T04:44:30.428Z{"msg":"[1] Transition from WaitActive to WaitQuorum","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:44:27.927120245Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1187}
1672023-10-13T04:44:30.440Z{"msg":"[1] new RM replaced this: None","v":0,"name":"crucible","level":40,"time":"2023-10-13T04:44:27.927191847Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1187}
1682023-10-13T04:44:30.447Z{"msg":"[1] 127.0.0.1:8820 task reports connection:true","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:44:27.927264003Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1187}
1692023-10-13T04:44:30.454Z{"msg":"[2] b869de47-53a4-4c5c-b1a2-a976d57d8d3d (3f91dcf1-5e04-456f-a27d-9275e14fd7ec) WaitActive WaitQuorum WaitActive ds_transition to WaitQuorum","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:44:27.927331024Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1187}
1702023-10-13T04:44:30.462Z{"msg":"[2] Transition from WaitActive to WaitQuorum","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:44:27.927375546Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1187}
1712023-10-13T04:44:30.468Z{"msg":"[2] new RM replaced this: None","v":0,"name":"crucible","level":40,"time":"2023-10-13T04:44:27.927415395Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1187}
1722023-10-13T04:44:30.472Z{"msg":"b869de47-53a4-4c5c-b1a2-a976d57d8d3d WaitActive WaitQuorum WaitQuorum","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:44:27.927455402Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1187}
1732023-10-13T04:44:30.478Z{"msg":"[1] Starts reconcile loop","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:44:27.927494488Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1187}
1742023-10-13T04:44:30.484Z{"msg":"[2] Starts reconcile loop","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:44:27.927533052Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1187}
1752023-10-13T04:44:30.491Z{"msg":"[0] b869de47-53a4-4c5c-b1a2-a976d57d8d3d (3f91dcf1-5e04-456f-a27d-9275e14fd7ec) WaitActive WaitQuorum WaitQuorum ds_transition to WaitQuorum","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:44:27.927574367Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1187}
1762023-10-13T04:44:30.501Z{"msg":"[0] Transition from WaitActive to WaitQuorum","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:44:27.927596349Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1187}
1772023-10-13T04:44:30.508Z{"msg":"[0] new RM replaced this: None","v":0,"name":"crucible","level":40The guest has finished waiting for activation with:26
1782023-10-13T04:44:30.516Z,"time":"Wait for a query_work_queue command to finish before sending IO
1792023-10-13T04:44:30.525Z2023-10-13T04:44:27.927633958Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1187}
1802023-10-13T04:44:30.531Z{"msg":"[0]R flush_numbers: [1613, 1613, 1613, 1613, 1613]","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:44:27.927659649Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1187}
1812023-10-13T04:44:30.537Z{"msg":"[0]R generation: [20, 20, 20, 20, 20]","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:44:27.927701432Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1187}
1822023-10-13T04:44:30.540Z{"msg":"[0]R dirty: [false, false, false, false, false]","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:44:27.927766682Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1187}
1832023-10-13T04:44:30.544Z{"msg":"[1]R flush_numbers: [1613, 1613, 1613, 1613, 1613]","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:44:27.927833477Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1187}
1842023-10-13T04:44:30.547Z{"msg":"[1]R generation: [20, 20, 20, 20, 20]","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:44:27.927908976Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1187}
1852023-10-13T04:44:30.550Z{"msg":"[1]R dirty: [false, false, false, false, false]","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:44:27.927969574Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1187}
1862023-10-13T04:44:30.553Z{"msg":"[2]R flush_numbers: [1613, 1613, 1613, 1613, 1613]","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:44:27.927992992Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1187}
1872023-10-13T04:44:30.558Z{"msg":"[2]R generation: [20, 20, 20, 20, 20]","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:44:27.928035966Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1187}
1882023-10-13T04:44:30.561Z{"msg":"[2]R dirty: [false, false, false, false, false]","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:44:27.928075896Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1187}
1892023-10-13T04:44:30.564Z{"msg":"Max found gen is 21","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:44:27.928133836Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1187}
1902023-10-13T04:44:30.567Z{"msg":"Generation requested: 26 >= found:21","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:44:27.928165456Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1187}
1912023-10-13T04:44:30.570Z{"msg":"Next flush: 1614","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:44:27.928225481Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1187}
1922023-10-13T04:44:30.573Z{"msg":"All extents match","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:44:27.928246866Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1187}
1932023-10-13T04:44:30.590Z{"msg":"No downstairs repair required","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:44:27.928264041Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1187}
1942023-10-13T04:44:30.607Z{"msg":"[0] Starts reconcile loop","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:44:27.928280847Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1187}
1952023-10-13T04:44:30.611Z{"msg":"No initial repair work was required","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:44:27.928298439Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1187}
1962023-10-13T04:44:30.614Z{"msg":"Set Downstairs and Upstairs active","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:44:27.928315847Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1187}
1972023-10-13T04:44:30.617Z{"msg":"b869de47-53a4-4c5c-b1a2-a976d57d8d3d is now active with session: 3f91dcf1-5e04-456f-a27d-9275e14fd7ec","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:44:27.928338282Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1187}
1982023-10-13T04:44:30.621Z{"msg":"b869de47-53a4-4c5c-b1a2-a976d57d8d3d Set Active after no repair","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:44:27.928357083Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1187}
1992023-10-13T04:44:30.624Z{"msg":"Notify all downstairs, region set compare is done.","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:44:27.928374887Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1187}
2002023-10-13T04:44:30.630Z{"msg":"Set check for repair","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:44:27.928391854Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1187}
2012023-10-13T04:44:30.641Z{"msg":"[2] 127.0.0.1:8830 task reports connection:true","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:44:27.928409487Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1187}
2022023-10-13T04:44:30.670Z{"msg":"[1] received reconcile message","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:44:27.928426708Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1187}
2032023-10-13T04:44:30.678Z{"msg":"b869de47-53a4-4c5c-b1a2-a976d57d8d3d Active Active Active","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:44:27.928444448Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1187}
2042023-10-13T04:44:30.686Z{"msg":"Set check for repair","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:44:27.928461525Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1187}
2052023-10-13T04:44:30.689Z{"msg":"[0] 127.0.0.1:8810 task reports connection:true","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:44:27.928478917Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1187}
2062023-10-13T04:44:30.692Z{"msg":"[1] All repairs completed, exit","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:44:27.928495825Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1187}
2072023-10-13T04:44:30.694Z{"msg":"[0] received reconcile message","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:44:27.928512765Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1187}
2082023-10-13T04:44:30.697Z{"msg":"b869de47-53a4-4c5c-b1a2-a976d57d8d3d Active Active Active","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:44:27.928530342Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1187}
2092023-10-13T04:44:30.700Z{"msg":"Set check for repair","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:44:27.928547293Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1187}Region: es:10 ec:5 bs:4096 ts:204800 tb:50 max_io:50 or 204800
2102023-10-13T04:44:30.704Z
2112023-10-13T04:44:30.707Z{"msg":"[1] Starts cmd_loop","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:44:27.928573703Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1187}
2122023-10-13T04:44:30.712Z{"msg":"[0] All repairs completed, exit","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:44:27.928590883Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1187}
2132023-10-13T04:44:30.716Z{"msg":"[0] Starts cmd_loop","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:44:27.928608263Z","hostnameFill test
2142023-10-13T04:44:30.720Z":"ip-10-150-1-198.us-west-2.compute.internal","pid":1187}
2152023-10-13T04:44:30.723Z{"msg":"[2] received reconcile message","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:44:27.928627816Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1187}
2162023-10-13T04:44:30.734Z{"msg":"[2] All repairs completed, exit","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:44:27.928644848Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1187}
2172023-10-13T04:44:30.750Z{"msg":"[2] Starts cmd_loop","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:44:27.928661293Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1187}
2182023-10-13T04:44:31.203ZRead and Verify all blocks (0..50 range:false)
2192023-10-13T04:44:31.622ZWrote out file "/var/tmp/test_up/verify_file"
2202023-10-13T04:44:31.743ZCLIENT: Tests done. All submitted work has been ACK'd
2212023-10-13T04:44:31.767Z----------------------------------------------------------------
2222023-10-13T04:44:31.815Z Crucible gen:26 GIO:true work queues: Upstairs:0 downstairs:1
2232023-10-13T04:44:31.891ZGW_ID ACK DSID TYPE BLOCKS DS:0 DS:1 DS:2 REPLAY
2242023-10-13T04:44:31.968Z 3 Acked 1002 Read 50 Done Done Done false
2252023-10-13T04:44:32.061Z STATES DS:0 DS:1 DS:2 TOTAL
2262023-10-13T04:44:32.138Z New 0 0 0 0
2272023-10-13T04:44:32.571Z Sent 0 0 0 0
2282023-10-13T04:44:32.592Z Done 1 1 1 3
2292023-10-13T04:44:32.610Z Skipped 0 0 0 0
2302023-10-13T04:44:32.637Z Error 0 0 0 0
2312023-10-13T04:44:32.653ZLast Flush: 1001 1001 1001
2322023-10-13T04:44:32.669ZDownstairs last five completed: 1001 1000
2332023-10-13T04:44:32.680ZUpstairs last five completed: 3 2 1
2342023-10-13T04:44:32.693ZCLIENT: Up:0 ds:1 act:3
2352023-10-13T04:44:32.706Z{"msg":"Checking if live repair is needed","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:44:28.92980655Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1187}
2362023-10-13T04:44:33.118Z{"msg":"No Live Repair required at this time","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:44:28.929863999Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1187}
2372023-10-13T04:44:33.125Z----------------------------------------------------------------
2382023-10-13T04:44:33.134Z Crucible gen:26 GIO:true work queues: Upstairs:0 downstairs:0
2392023-10-13T04:44:33.147ZDownstairs last five completed: 1003 1002 1001 1000
2402023-10-13T04:44:33.155ZUpstairs last five completed: 4 3 2 1
2412023-10-13T04:44:33.196ZCLIENT: Up:0 ds:0 act:3
2422023-10-13T04:44:33.233ZCLIENT: All crucible jobs finished, exiting program
2432023-10-13T04:44:33.238ZRepair setup passed
2442023-10-13T04:44:33.243ZCopy the 8830 file
2452023-10-13T04:44:33.251Zcp -r /var/tmp/test_up/8830 /var/tmp/test_up/previous
2462023-10-13T04:44:33.266Z/var/tmp/bins/crutest repair -g 27 -q -t 127.0.0.1:8810 -t 127.0.0.1:8820 -t 127.0.0.1:8830 --verify-out /var/tmp/test_up/verify_file --verify-in /var/tmp/test_up/verify_file
2472023-10-13T04:44:33.277Z{"msg":"Upstairs starts","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:44:32.049527308Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1193}
2482023-10-13T04:44:33.289Z{"msg":"Crucible Version: BuildInfo {\n version: \"0.0.1\",\n git_sha: \"0a6b3facda3a9a8c75c70b591db2d34571e435e8\",\n git_commit_timestamp: \"2023-10-13T04:02:07.000000000Z\",\n git_branch: \"alan/unwrapless\",\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-13T04:44:32.050011879Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1193}
2492023-10-13T04:44:33.300Z{"msg":"Upstairs <-> Downstairs Message Version: 4","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:44:32.05006133Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1193}
2502023-10-13T04:44:33.311Z{"msg":"Upstairs opts: Upstairs UUID: a74c4046-9052-4c63-afb2-17bfd502ccb5, Targets: [127.0.0.1:8810, 127.0.0.1:8820, 127.0.0.1:8830], lossy: false, flush_timeout: None, key populated: false, cert_pem populated: false, key_pem populated: false, root_cert_pem populated: false, Control: None, read_only: false","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:44:32.050131416Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1193}
2512023-10-13T04:44:33.320Z{"msg":"Crucible stats registered with UUID: a74c4046-9052-4c63-afb2-17bfd502ccb5","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:44:32.050206219Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1193}
2522023-10-13T04:44:33.331Z{"msg":"Crucible a74c4046-9052-4c63-afb2-17bfd502ccb5 has session id: fa650197-0e39-48e7-a061-11325bdc30e7","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:44:32.050245324Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1193}
2532023-10-13T04:44:33.337ZCrucible runtime is spawned
2542023-10-13T04:44:33.348Z{"The guest has requested activation with gen:27
2552023-10-13T04:44:33.354Zmsg":"up_listen starts","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:44:32.050593668Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1193,"task":"up_listen"}
2562023-10-13T04:44:33.359Z{"msg":"Wait for all three downstairs to come online","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:44:32.050663062Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1193}
2572023-10-13T04:44:33.365Z{"msg":"Flush timeout: 0.5","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:44:32.05070682Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1193}
2582023-10-13T04:44:33.372Z{"msg":"[2] connecting to 127.0.0.1:8830","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:44:32.050746066Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1193,"looper":"2"}
2592023-10-13T04:44:33.379Z{"msg":"[2] a74c4046-9052-4c63-afb2-17bfd502ccb5 looper connected","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:44:32.051070063Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1193,"looper":"2"}
2602023-10-13T04:44:33.385Z{"msg":"[1] connecting to 127.0.0.1:8820","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:44:32.051212864Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1193,"looper":"1"}
2612023-10-13T04:44:33.397Z{"msg":"[0] connecting to 127.0.0.1:8810","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:44:32.05133616Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1193,"looper":"0"}
2622023-10-13T04:44:33.526Z{"msg":"[1] a74c4046-9052-4c63-afb2-17bfd502ccb5 looper connected","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:44:32.051392256Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1193,"looper":"1"}
2632023-10-13T04:44:33.552Z{"msg":"[0] a74c4046-9052-4c63-afb2-17bfd502ccb5 looper connected","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:44:32.051700603Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1193,"looper":"0"}
2642023-10-13T04:44:33.564Z{"msg":"a74c4046-9052-4c63-afb2-17bfd502ccb5 active request set","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:44:32.051883683Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1193}
2652023-10-13T04:44:33.579Z{"msg":"Set desired generation to :27","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:44:32.051932987Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1193}
2662023-10-13T04:44:33.589Z{"msg":"[1] Proc runs for 127.0.0.1:8820 in state New","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:44:32.051993606Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1193}
2672023-10-13T04:44:33.615Z{"msg":"[2] Proc runs for 127.0.0.1:8830 in state New","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:44:32.052184263Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1193}
2682023-10-13T04:44:33.633Z{"msg":"[0] Proc runs for 127.0.0.1:8810 in state New","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:44:32.052403948Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1193}
2692023-10-13T04:44:33.644Z{"msg":"[1] a74c4046-9052-4c63-afb2-17bfd502ccb5 (a2bb2c98-3c22-4d92-9780-19822f65c2c5) New New New ds_transition to WaitActive","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:44:32.052890384Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1193}
2702023-10-13T04:44:33.654Z{"msg":"[1] Transition from New to WaitActive","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:44:32.052950194Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1193}
2712023-10-13T04:44:33.667Z{"msg":"[1] client is_active_req TRUE, promote! session a2bb2c98-3c22-4d92-9780-19822f65c2c5","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:44:32.05297546Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1193}
2722023-10-13T04:44:33.680Z{"msg":"[0] a74c4046-9052-4c63-afb2-17bfd502ccb5 (a2bb2c98-3c22-4d92-9780-19822f65c2c5) New WaitActive New ds_transition to WaitActive","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:44:32.053137422Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1193}
2732023-10-13T04:44:33.696Z{"msg":"[0] Transition from New to WaitActive","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:44:32.053201644Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1193}
2742023-10-13T04:44:33.711Z{"msg":"[2] a74c4046-9052-4c63-afb2-17bfd502ccb5 (a2bb2c98-3c22-4d92-9780-19822f65c2c5) WaitActive WaitActive New ds_transition to WaitActive","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:44:32.053279699Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1193}
2752023-10-13T04:44:33.729Z{"msg":"[2] Transition from New to WaitActive","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:44:32.053324104Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1193}
2762023-10-13T04:44:34.156Z{"msg":"[0] client is_active_req TRUE, promote! session a2bb2c98-3c22-4d92-9780-19822f65c2c5","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:44:32.053462187Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1193}
2772023-10-13T04:44:34.629Z{"msg":"[2] client is_active_req TRUE, promote! session a2bb2c98-3c22-4d92-9780-19822f65c2c5","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:44:32.053573104Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1193}
2782023-10-13T04:44:34.637Z{"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-13T04:44:32.053807544Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1193}
2792023-10-13T04:44:34.642Z{"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: false, database_read_version: 1, database_write_version: 1 }","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:44:32.053880573Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1193}
2802023-10-13T04:44:34.651Z{"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-13T04:44:32.053939511Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1193}
2812023-10-13T04:44:34.664Z{"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: false, database_read_version: 1, database_write_version: 1 }","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:44:32.054015811Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1193}
2822023-10-13T04:44:34.677Z{"msg":"a74c4046-9052-4c63-afb2-17bfd502ccb5 WaitActive WaitActive WaitActive","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:44:32.054085296Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1193}
2832023-10-13T04:44:34.682Z{"msg":"a74c4046-9052-4c63-afb2-17bfd502ccb5 WaitActive WaitActive WaitActive","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:44:32.054129017Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1193}
2842023-10-13T04:44:34.695Z{"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-13T04:44:32.05419948Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1193}
2852023-10-13T04:44:34.707Z{"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: false, database_read_version: 1, database_write_version: 1 }","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:44:32.054277536Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1193}
2862023-10-13T04:44:34.720Z{"msg":"a74c4046-9052-4c63-afb2-17bfd502ccb5 WaitActive WaitActive WaitActive","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:44:32.054344254Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1193}
2872023-10-13T04:44:35.148Z{"msg":"[0] a74c4046-9052-4c63-afb2-17bfd502ccb5 (a2bb2c98-3c22-4d92-9780-19822f65c2c5) WaitActive WaitActive WaitActive ds_transition to WaitQuorum","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:44:32.054637226Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1193}
2882023-10-13T04:44:35.175Z{"msg":"[0] Transition from WaitActive to WaitQuorum","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:44:32.054710381Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1193}
2892023-10-13T04:44:35.185Z{"msg":"[0] new RM replaced this: None","v":0,"name":"crucible","level":40,"time":"2023-10-13T04:44:32.054731687Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1193}
2902023-10-13T04:44:35.202Z{"msg":"[2] a74c4046-9052-4c63-afb2-17bfd502ccb5 (a2bb2c98-3c22-4d92-9780-19822f65c2c5) WaitQuorum WaitActive WaitActive ds_transition to WaitQuorum","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:44:32.054752905Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1193}
2912023-10-13T04:44:35.217Z{"msg":"[2] Transition from WaitActive to WaitQuorum","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:44:32.054772507Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1193}
2922023-10-13T04:44:35.685Z{"msg":"[2] new RM replaced this: None","v":0,"name":"crucible","level":40,"time":"2023-10-13T04:44:32.054790131Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1193}
2932023-10-13T04:44:35.717ZError: Difference in extent metadata found!
2942023-10-13T04:44:35.726Z{"msg":"[1] a74c4046-9052-4c63-afb2-17bfd502ccb5 (a2bb2c98-3c22-4d92-9780-19822f65c2c5) WaitQuorum WaitActive WaitQuorum ds_transition to WaitQuorum","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:44:32.054809913Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1193}
2952023-10-13T04:44:35.741Z{"msg":"[1] Transition from WaitActive to WaitQuorum","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:44:32.054828041Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1193}
2962023-10-13T04:44:35.754Z{"msg":"[1] new RM replaced this: None","v":0,"name":"crucible","level":40,"time":"2023-10-13T04:44:32.0548451Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1193}
2972023-10-13T04:44:35.766Z{"msg":"[0] 127.0.0.1:8810 task reports connection:true","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:44:32.054863372Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1193}
2982023-10-13T04:44:35.774Z{"msg":"a74c4046-9052-4c63-afb2-17bfd502ccb5 WaitQuorum WaitQuorum WaitQuorum","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:44:32.05488167Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1193}
2992023-10-13T04:44:35.780Z{"msg":"[0] Starts reconcile loop","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:44:32.054898959Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1193}
3002023-10-13T04:44:35.786Z{"msg":"[2] Starts reconcile loop","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:44:32.054915932Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1193}
3012023-10-13T04:44:35.797Z{"msg":"[1] Starts reconcile loop","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:44:32.054933226Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1193}
3022023-10-13T04:44:35.804Z{"msg":"[0]R flush_numbers: [1614, 1614, 1614, 1614, 1614]","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:44:32.055068871Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1193}
3032023-10-13T04:44:35.810Z{"msg":"[0]R generation: [26, 26, 26, 26, 26]","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:44:32.055093386Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1193}
3042023-10-13T04:44:35.820Z{"msg":"[0]R dirty: [false, false, false, false, false]","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:44:32.055111714Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1193}
3052023-10-13T04:44:35.833Z{"msg":"[1]R flush_numbers: [1614, 1614, 1614, 1614, 1614]","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:44:32.055129834Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1193}
3062023-10-13T04:44:35.845Z{"msg":"[1]R generation: [26, 26, 26, 26, 26]","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:44:32.055147452Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1193}
3072023-10-13T04:44:35.852Z{"msg":"[1]R dirty: [false, false, false, false, false]","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:44:32.055165527Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1193}
3082023-10-13T04:44:35.864Z{"msg":"[2]R flush_numbers: [1614, 1614, 1614, 1614, 1614]","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:44:32.055182892Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1193}
3092023-10-13T04:44:35.873Z{"msg":"[2]R generation: [26, 26, 26, 26, 26]","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:44:32.055201155Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1193}
3102023-10-13T04:44:35.892Z{"msg":"[2]R dirty: [false, false, false, false, false]","v":0,"name"The guest has finished waiting for activation with:27
3112023-10-13T04:44:35.906Z:"Wait for a query_work_queue command to finish before sending IO
3122023-10-13T04:44:35.915Zcrucible","level":30,"time":"2023-10-13T04:44:32.05522428Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1193}
3132023-10-13T04:44:35.925Z{"msg":"Max found gen is 27","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:44:32.055241431Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1193}
3142023-10-13T04:44:35.936Z{"msg":"Generation requested: 27 >= found:27","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:44:32.055258825Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1193}
3152023-10-13T04:44:35.943Z{"msg":"Next flush: 1615","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:44:32.055275692Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1193}
3162023-10-13T04:44:35.953Z{"msg":"All extents match","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:44:32.055292511Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1193}
3172023-10-13T04:44:35.962Z{"msg":"No downstairs repair required","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:44:32.055309601Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1193}
3182023-10-13T04:44:35.966Z{"msg":"No initial repair work was required","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:44:32.055326953Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1193}
3192023-10-13T04:44:35.980Z{"msg":"Set Downstairs and Upstairs active","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:44:32.055344483Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1193}
3202023-10-13T04:44:35.993Z{"msg":"a74c4046-9052-4c63-afb2-17bfd502ccb5 is now active with session: a2bb2c98-3c22-4d92-9780-19822f65c2c5","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:44:32.055363479Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1193}
3212023-10-13T04:44:36.006Z{"msg":"a74c4046-9052-4c63-afb2-17bfd502ccb5 Set Active after no repair","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:44:32.055382138Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1193}
3222023-10-13T04:44:36.012Z{"msg":"Notify all downstairs, region set compare is done.","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:44:32.055400352Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1193}
3232023-10-13T04:44:36.024Z{"msg":"Set check for repair","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:44:32.055425031Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1193}
3242023-10-13T04:44:36.045Z{"msg":"[2] 127.0.0.1:8830 task reports connection:true","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:44:32.055444338Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1193}
3252023-10-13T04:44:36.070Z{"msg":"a74c4046-9052-4c63-afb2-17bfd502ccb5 Active Active Active","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:44:32.055461989Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1193}
3262023-10-13T04:44:36.082Z{"msg":"Set check for repair","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:44:32.055478838Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1193}
3272023-10-13T04:44:36.092Z{"msg":"[1] 127.0.0.1:8820 task reports connection:true","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:44:32.055496286Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1193}
3282023-10-13T04:44:36.118Z{"msg":"a74c4046-9052-4c63-afb2-17bfd502ccb5 Active Active Active","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:44:32.055514533Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1193}
3292023-10-13T04:44:36.130Z{"msg":"Set check for repair","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:44:32.055531261Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1193}
3302023-10-13T04:44:36.134Z{"msg":"[0] received reconcile message","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:44:32.055548252Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1193}
3312023-10-13T04:44:36.144Z{"msg":"[0] All repairs completed, exit","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:44:32.055565408Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1193}
3322023-10-13T04:44:36.151Z{"msg":"[1] received reconcile message","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:44:32.055582454Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1193}
3332023-10-13T04:44:36.162Z{"msg":"[0] Starts cmd_loop","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:44:32.055599845Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1193}
3342023-10-13T04:44:36.196Z{"msg":"[2] received reconcile message","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:44:32.055617077Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1193}
3352023-10-13T04:44:36.216Z{"msg":"[1] All repairs completed, exit","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:44:32.055785561Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1193}
3362023-10-13T04:44:36.231Z{"msg":"[1] Starts cmd_loop","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:44:32.055808954Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1193}
3372023-10-13T04:44:36.244Z{"msg":"[2] All repairs completed, exit","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:44:32.055834159Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1193}
3382023-10-13T04:44:36.258Z{"msg":"[2] Starts cmd_loop","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:44:32.055854334Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1193}
3392023-10-13T04:44:36.275ZRegion: es:10 ec:5 bs:4096 ts:204800 tb:50 max_io:50 or 204800
3402023-10-13T04:44:36.284ZLoading write count information from file "/var/tmp/test_up/verify_file"
3412023-10-13T04:44:36.294ZRun Repair workload
3422023-10-13T04:44:36.298Z01/10 Write block 11 len 36864 data: 2 2 2 2 2 2 2 2 2
3432023-10-13T04:44:36.308Z02/10 Write block 10 len 20480 data: 2 3 3 3 3
3442023-10-13T04:44:36.317Z03/10 Write block 25 len 4096 data: 2
3452023-10-13T04:44:36.328Z04/10 Write block 32 len 28672 data: 2 2 2 2 2 2 2
3462023-10-13T04:44:36.357Z05/10 Read block 9 len 40960
3472023-10-13T04:44:36.369Z06/10 Read block 10 len 36864
3482023-10-13T04:44:36.379Z07/10 Write block 6 len 40960 data: 2 2 2 2 3 4 4 4 4 3
3492023-10-13T04:44:36.396Z08/10 Write block 36 len 24576 data: 3 3 3 2 2 2
3502023-10-13T04:44:36.404Z09/10 Read block 23 len 32768
3512023-10-13T04:44:36.414Z10/10 Write block 11 len 24576 data: 5 5 5 5 4 3
3522023-10-13T04:44:36.421Z----------------------------------------------------------------
3532023-10-13T04:44:36.428Z Crucible gen:27 GIO:true work queues: Upstairs:0 downstairs:10
3542023-10-13T04:44:36.432ZGW_ID ACK DSID TYPE BLOCKS DS:0 DS:1 DS:2 REPLAY
3552023-10-13T04:44:36.437Z 1 Acked 1000 Write 9 Done Done Done false
3562023-10-13T04:44:36.444Z 2 Acked 1001 Write 5 Done Done Done false
3572023-10-13T04:44:36.452Z 3 Acked 1002 Write 1 Done Done Done false
3582023-10-13T04:44:36.460Z 4 Acked 1003 Write 7 Done Done Done false
3592023-10-13T04:44:36.467Z 5 Acked 1004 Read 10 Done Done Done false
3602023-10-13T04:44:36.479Z 6 Acked 1005 Read 9 Done Done Done false
3612023-10-13T04:44:36.897Z 7 Acked 1006 Write 10 Done Done Done false
3622023-10-13T04:44:36.910Z 8 Acked 1007 Write 6 Done Done Done false
3632023-10-13T04:44:36.920Z 9 Acked 1008 Read 8 Done Done Done false
3642023-10-13T04:44:37.347Z 10 Acked 1009 Write 6 Sent Sent Sent false
3652023-10-13T04:44:37.362Z STATES DS:0 DS:1 DS:2 TOTAL
3662023-10-13T04:44:37.781Z New 0 0 0 0
3672023-10-13T04:44:37.801Z Sent 1 1 1 3
3682023-10-13T04:44:37.814Z Done 9 9 9 27
3692023-10-13T04:44:37.827Z Skipped 0 0 0 0
3702023-10-13T04:44:37.843Z Error 0 0 0 0
3712023-10-13T04:44:37.856ZLast Flush: 0 0 0
3722023-10-13T04:44:37.866ZDownstairs last five completed:
3732023-10-13T04:44:37.878ZUpstairs last five completed: 10 9 8 7 6 5
3742023-10-13T04:44:37.889ZWrote out file "/var/tmp/test_up/verify_file"
3752023-10-13T04:44:37.899ZRepair part 1 passed
3762023-10-13T04:44:38.318Z
3772023-10-13T04:44:38.338ZKill the current downstairs
3782023-10-13T04:44:38.758Zrm -rf /var/tmp/test_up/8830
3792023-10-13T04:44:38.766ZNow put back the original so we have a mismatch
3802023-10-13T04:44:38.775Zmv /var/tmp/test_up/previous /var/tmp/test_up/8830
3812023-10-13T04:44:38.842ZRestart downstairs with old directory
3822023-10-13T04:44:38.868Z/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
3832023-10-13T04:44:38.878ZEXT BLOCKS GEN0 GEN1 GEN2 FL0 FL1 FL2 D0 D1 D2 DIFF
3842023-10-13T04:44:38.890Z 0 000-009 26 26 26 1614 1614 1614 T T F <---
3852023-10-13T04:44:38.905Z 1 010-019 26 26 26 1614 1614 1614 T T F <---
3862023-10-13T04:44:38.914Z 2 020-029 26 26 26 1614 1614 1614 T T F <---
3872023-10-13T04:44:38.926Z 3 030-039 26 26 26 1614 1614 1614 T T F <---
3882023-10-13T04:44:38.951Z 4 040-049 26 26 26 1614 1614 1614 T T F <---
3892023-10-13T04:44:38.958ZMax gen: 26, Max flush: 1614
3902023-10-13T04:44:38.962Zdump test found error as expected
3912023-10-13T04:44:38.968Z
3922023-10-13T04:44:38.987Z
3932023-10-13T04:44:38.993Z/var/tmp/bins/crutest deactivate --range -g 28 -q -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-13T04:44:38.999Z{"msg":"Upstairs starts","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:44:32.552848951Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1200}
3952023-10-13T04:44:39.005Z{"msg":"Crucible Version: BuildInfo {\n version: \"0.0.1\",\n git_sha: \"0a6b3facda3a9a8c75c70b591db2d34571e435e8\",\n git_commit_timestamp: \"2023-10-13T04:02:07.000000000Z\",\n git_branch: \"alan/unwrapless\",\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-13T04:44:32.55327921Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1200}
3962023-10-13T04:44:39.009Z{"msg":"Upstairs <-> Downstairs Message Version: 4","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:44:32.553346606Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1200}
3972023-10-13T04:44:39.013Z{"msg":"Upstairs opts: Upstairs UUID: f845fd61-0eb2-446a-a3d3-f6ca309c1df1, Targets: [127.0.0.1:8810, 127.0.0.1:8820, 127.0.0.1:8830], lossy: false, flush_timeout: None, key populated: false, cert_pem populated: false, key_pem populated: false, root_cert_pem populated: false, Control: None, read_only: false","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:44:32.55337551Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1200}
3982023-10-13T04:44:39.017Z{"msg":"Crucible stats registered with UUID: f845fd61-0eb2-446a-a3d3-f6ca309c1df1","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:44:32.553395448Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1200}
3992023-10-13T04:44:39.022Z{"msg":"Crucible f845fd61-0eb2-446a-a3d3-f6ca309c1df1 has session id: 52dd234a-27b4-4f83-bd67-387cac9132c7","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:44:32.553415894Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1200}
4002023-10-13T04:44:39.026ZCrucible runtime is spawned
4012023-10-13T04:44:39.030ZThe guest has requested activation with gen:28
4022023-10-13T04:44:39.036Z{"msg":"up_listen starts","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:44:32.553866725Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1200,"task":"up_listen"}
4032023-10-13T04:44:39.039Z{"msg":"Wait for all three downstairs to come online","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:44:32.553929454Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1200}
4042023-10-13T04:44:39.044Z{"msg":"Flush timeout: 0.5","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:44:32.553953138Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1200}
4052023-10-13T04:44:39.047Z{"msg":"[1] connecting to 127.0.0.1:8820","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:44:32.553970824Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1200,"looper":"1"}
4062023-10-13T04:44:39.051Z{"msg":"[2] connecting to 127.0.0.1:8830","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:44:32.554347709Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1200,"looper":"2"}
4072023-10-13T04:44:39.055Z{"msg":"[1] f845fd61-0eb2-446a-a3d3-f6ca309c1df1 looper connected","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:44:32.554400165Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1200,"looper":"1"}
4082023-10-13T04:44:39.059Z{"msg":"[0] connecting to 127.0.0.1:8810","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:44:32.554508261Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1200,"looper":"0"}
4092023-10-13T04:44:39.064Z{"msg":"[0] f845fd61-0eb2-446a-a3d3-f6ca309c1df1 looper connected","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:44:32.554738613Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1200,"looper":"0"}
4102023-10-13T04:44:39.067Z{"msg":"f845fd61-0eb2-446a-a3d3-f6ca309c1df1 active request set","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:44:32.55501798Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1200}
4112023-10-13T04:44:39.070Z{"msg":"Set desired generation to :28","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:44:32.555052748Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1200}
4122023-10-13T04:44:39.072Z{"msg":"[1] Proc runs for 127.0.0.1:8820 in state New","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:44:32.555139791Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1200}
4132023-10-13T04:44:39.076Z{"msg":"[0] Proc runs for 127.0.0.1:8810 in state New","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:44:32.555434812Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1200}
4142023-10-13T04:44:39.079Z{"msg":"[1] f845fd61-0eb2-446a-a3d3-f6ca309c1df1 (6331a993-ca35-4e3d-a1ea-7235bed756ae) New New New ds_transition to WaitActive","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:44:32.55577088Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1200}
4152023-10-13T04:44:39.082Z{"msg":"[1] Transition from New to WaitActive","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:44:32.555817507Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1200}
4162023-10-13T04:44:39.086Z{"msg":"[1] client is_active_req TRUE, promote! session 6331a993-ca35-4e3d-a1ea-7235bed756ae","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:44:32.555856534Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1200}
4172023-10-13T04:44:39.090Z{"msg":"[0] f845fd61-0eb2-446a-a3d3-f6ca309c1df1 (6331a993-ca35-4e3d-a1ea-7235bed756ae) New WaitActive New ds_transition to WaitActive","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:44:32.555970318Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1200}
4182023-10-13T04:44:39.093Z{"msg":"[0] Transition from New to WaitActive","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:44:32.556016533Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1200}
4192023-10-13T04:44:39.101Z{"msg":"[0] client is_active_req TRUE, promote! session 6331a993-ca35-4e3d-a1ea-7235bed756ae","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:44:32.556056537Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1200}
4202023-10-13T04:44:39.117Z{"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-13T04:44:32.556367905Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1200}
4212023-10-13T04:44:39.125Z{"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: false, database_read_version: 1, database_write_version: 1 }","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:44:32.556455542Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1200}
4222023-10-13T04:44:39.136Z{"msg":"f845fd61-0eb2-446a-a3d3-f6ca309c1df1 WaitActive WaitActive New","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:44:32.556494758Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1200}
4232023-10-13T04:44:39.144Z{"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-13T04:44:32.556534081Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1200}
4242023-10-13T04:44:39.150Z{"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: false, database_read_version: 1, database_write_version: 1 }","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:44:32.55657516Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1200}
4252023-10-13T04:44:39.159Z{"msg":"f845fd61-0eb2-446a-a3d3-f6ca309c1df1 WaitActive WaitActive New","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:44:32.55660968Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1200}
4262023-10-13T04:44:39.164Z{"msg":"[0] f845fd61-0eb2-446a-a3d3-f6ca309c1df1 (6331a993-ca35-4e3d-a1ea-7235bed756ae) WaitActive WaitActive New ds_transition to WaitQuorum","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:44:32.557185183Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1200}
4272023-10-13T04:44:39.168Z{"msg":"[0] Transition from WaitActive to WaitQuorum","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:44:32.557257519Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1200}
4282023-10-13T04:44:39.172Z{"msg":"[0] new RM replaced this: None","v":0,"name":"crucible","level":40,"time":"2023-10-13T04:44:32.557276315Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1200}
4292023-10-13T04:44:39.180Z{"msg":"[1] f845fd61-0eb2-446a-a3d3-f6ca309c1df1 (6331a993-ca35-4e3d-a1ea-7235bed756ae) WaitQuorum WaitActive New ds_transition to WaitQuorum","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:44:32.557296581Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1200}
4302023-10-13T04:44:39.184Z{"msg":"[1] Transition from WaitActive to WaitQuorum","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:44:32.557314699Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1200}
4312023-10-13T04:44:39.190Z{"msg":"[1] new RM replaced this: None","v":0,"name":"crucible","level":40,"time":"2023-10-13T04:44:32.557331904Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1200}
4322023-10-13T04:44:39.196Z{"msg":"[0] 127.0.0.1:8810 task reports connection:true","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:44:32.557349552Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1200}
4332023-10-13T04:44:39.202Z{"msg":"f845fd61-0eb2-446a-a3d3-f6ca309c1df1 WaitQuorum WaitQuorum New","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:44:32.55736748Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1200}
4342023-10-13T04:44:39.221Z{"msg":"[0] Starts reconcile loop","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:44:32.557384993Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1200}
4352023-10-13T04:44:39.232Z{"msg":"[1] Starts reconcile loop","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:44:32.557401917Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1200}
4362023-10-13T04:44:39.239Z{"msg":"Waiting for 1 more clients to be ready","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:44:32.557424Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1200}
4372023-10-13T04:44:39.242Z{"msg":"Set check for repair","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:44:32.557441676Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1200}
4382023-10-13T04:44:39.246Z{"msg":"[1] 127.0.0.1:8820 task reports connection:true","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:44:32.557459459Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1200}
4392023-10-13T04:44:39.249Z{"msg":"f845fd61-0eb2-446a-a3d3-f6ca309c1df1 WaitQuorum WaitQuorum New","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:44:32.557477702Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1200}
4402023-10-13T04:44:39.252Z{"msg":"Waiting for 1 more clients to be ready","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:44:32.557495177Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1200}
4412023-10-13T04:44:39.255Z{"msg":"Set check for repair","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:44:32.557511932Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1200}
4422023-10-13T04:44:39.258Z{"msg":"Checking if live repair is needed","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:44:33.55833767Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1200}
4432023-10-13T04:44:39.262Z{"msg":"[2] f845fd61-0eb2-446a-a3d3-f6ca309c1df1 looper connected","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:44:34.558309871Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1200,"looper":"2"}
4442023-10-13T04:44:39.269Z{"msg":"[2] Proc runs for 127.0.0.1:8830 in state New","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:44:34.558365978Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1200}
4452023-10-13T04:44:39.272Z{"msg":"[2] f845fd61-0eb2-446a-a3d3-f6ca309c1df1 (6331a993-ca35-4e3d-a1ea-7235bed756ae) WaitQuorum WaitQuorum New ds_transition to WaitActive","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:44:34.559043701Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1200}
4462023-10-13T04:44:39.275Z{"msg":"[2] Transition from New to WaitActive","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:44:34.559068496Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1200}
4472023-10-13T04:44:39.284Z{"msg":"[2] client is_active_req TRUE, promote! session 6331a993-ca35-4e3d-a1ea-7235bed756ae","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:44:34.559088426Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1200}
4482023-10-13T04:44:39.295Z{"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-13T04:44:34.559635798Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1200}
4492023-10-13T04:44:39.308Z{"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: false, database_read_version: 1, database_write_version: 1 }","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:44:34.559664589Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1200}
4502023-10-13T04:44:39.319Z{"msg":"f845fd61-0eb2-446a-a3d3-f6ca309c1df1 WaitQuorum WaitQuorum WaitActive","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:44:34.559690737Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1200}
4512023-10-13T04:44:39.325Z{"msg":"[2] f845fd61-0eb2-446a-a3d3-f6ca309c1df1 (6331a993-ca35-4e3d-a1ea-7235bed756ae) WaitQuorum WaitQuorum WaitActive ds_transition to WaitQuorum","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:44:34.560257599Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1200}
4522023-10-13T04:44:39.335Z{"msg":"[2] Transition from WaitActive to WaitQuorum","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:44:34.560281386Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1200}
4532023-10-13T04:44:39.340Z{"msg":"[2] new RM replaced this: None","v":0,"name":"crucible","level":40,"time":"2023-10-13T04:44:34.560299247Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1200}
4542023-10-13T04:44:39.345Z{"msg":"[2] Starts reconcile loop","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:44:34.560316405Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1200}
4552023-10-13T04:44:39.351Z{"msg":"[2] 127.0.0.1:8830 task reports connection:true","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:44:34.560334245Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1200}
4562023-10-13T04:44:39.357Z{"msg":"f845fd61-0eb2-446a-a3d3-f6ca309c1df1 WaitQuorum WaitQuorum WaitQuorum","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:44:34.560359767Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1200}
4572023-10-13T04:44:39.364Z{"msg":"[0]R flush_numbers: [1614, 1614, 1614, 1614, 1614]","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:44:34.560398785Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1200}
4582023-10-13T04:44:39.370Z{"msg":"[0]R generation: [26, 26, 26, 26, 26]","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:44:34.560419549Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1200}
4592023-10-13T04:44:39.376Z{"msg":"[0]R dirty: [true, true, true, true, true]","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:44:34.560437428Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1200}
4602023-10-13T04:44:39.383Z{"msg":"[1]R flush_numbers: [1614, 1614, 1614, 1614, 1614]","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:44:34.560455236Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1200}
4612023-10-13T04:44:39.390Z{"msg":"[1]R generation: [26, 26, 26, 26, 26]","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:44:34.560472761Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1200}
4622023-10-13T04:44:39.397Z{"msg":"[1]R dirty: [true, true, true, true, true]","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:44:34.560490043Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1200}
4632023-10-13T04:44:39.419Z{"msg":"[2]R flush_numbers: [1614, 1614, 1614, 1614, 1614]","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:44:34.560507713Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1200}
4642023-10-13T04:44:39.437Z{"msg":"[2]R generation: [26, 26, 26, 26, 26]","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:44:34.560525121Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1200}
4652023-10-13T04:44:39.449Z{"msg":"[2]R dirty: [false, false, false, false, false]","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:44:34.560542772Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1200}
4662023-10-13T04:44:39.458Z{"msg":"Max found gen is 27","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:44:34.560559282Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1200}
4672023-10-13T04:44:39.471Z{"msg":"Generation requested: 28 >= found:27","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:44:34.560576424Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1200}
4682023-10-13T04:44:39.490Z{"msg":"Next flush: 1615","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:44:34.560592828Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1200}
4692023-10-13T04:44:39.935Z{"msg":"Extents 0 dirty","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:44:34.560609787Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1200,"":"mend"}
4702023-10-13T04:44:39.954Z{"msg":"First source client ID for extent 0","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:44:34.560628515Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1200,"mrl":"dirty","":"mend"}
4712023-10-13T04:44:39.980Z{"msg":"extent:0 gens: 26 26 26","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:44:34.560647701Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1200,"mrl":"dirty","":"mend"}
4722023-10-13T04:44:40.411Z{"msg":"extent:0 flush: 1614 1614 1614 scs: [ClientId(0), ClientId(1), ClientId(2)]","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:44:34.56066825Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1200,"mrl":"dirty","":"mend"}
4732023-10-13T04:44:40.425Z{"msg":"max_flush now has: [ClientId(0), ClientId(1), ClientId(2)]","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:44:34.560688318Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1200,"mrl":"dirty","":"mend"}
4742023-10-13T04:44:40.856Z{"msg":"extent:0 dirty: true true false","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:44:34.560707334Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1200,"mrl":"dirty","":"mend"}
4752023-10-13T04:44:41.269Z{"msg":"find dest for source 0 for extent at index 0","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:44:34.560727481Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1200,"mrl":"dirty","":"mend"}
4762023-10-13T04:44:41.313Z{"msg":"source 0, add dest 1 source flush","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:44:34.56074673Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1200,"mrl":"dirty","":"mend"}
4772023-10-13T04:44:41.333Z{"msg":"source 0, add dest 2 source flush","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:44:34.560766026Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1200,"mrl":"dirty","":"mend"}
4782023-10-13T04:44:41.349Z{"msg":"Extents 1 dirty","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:44:34.560786049Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1200,"":"mend"}
4792023-10-13T04:44:41.369Z{"msg":"First source client ID for extent 1","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:44:34.560804297Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1200,"mrl":"dirty","":"mend"}
4802023-10-13T04:44:41.393Z{"msg":"extent:1 gens: 26 26 26","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:44:34.560822952Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1200,"mrl":"dirty","":"mend"}
4812023-10-13T04:44:41.403Z{"msg":"extent:1 flush: 1614 1614 1614 scs: [ClientId(0), ClientId(1), ClientId(2)]","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:44:34.560842957Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1200,"mrl":"dirty","":"mend"}
4822023-10-13T04:44:41.410Z{"msg":"max_flush now has: [ClientId(0), ClientId(1), ClientId(2)]","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:44:34.560862973Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1200,"mrl":"dirty","":"mend"}
4832023-10-13T04:44:41.420Z{"msg":"extent:1 dirty: true true false","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:44:34.560888608Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1200,"mrl":"dirty","":"mend"}
4842023-10-13T04:44:41.434Z{"msg":"find dest for source 0 for extent at index 1","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:44:34.560909194Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1200,"mrl":"dirty","":"mend"}
4852023-10-13T04:44:41.448Z{"msg":"source 0, add dest 1 source flush","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:44:34.560928146Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1200,"mrl":"dirty","":"mend"}
4862023-10-13T04:44:41.471Z{"msg":"source 0, add dest 2 source flush","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:44:34.560947472Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1200,"mrl":"dirty","":"mend"}
4872023-10-13T04:44:41.482Z{"msg":"Extents 2 dirty","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:44:34.560966314Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1200,"":"mend"}
4882023-10-13T04:44:41.491Z{"msg":"First source client ID for extent 2","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:44:34.560984596Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1200,"mrl":"dirty","":"mend"}
4892023-10-13T04:44:41.505Z{"msg":"extent:2 gens: 26 26 26","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:44:34.561003211Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1200,"mrl":"dirty","":"mend"}
4902023-10-13T04:44:41.532Z{"msg":"extent:2 flush: 1614 1614 1614 scs: [ClientId(0), ClientId(1), ClientId(2)]","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:44:34.561023283Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1200,"mrl":"dirty","":"mend"}
4912023-10-13T04:44:41.959Z{"msg":"max_flush now has: [ClientId(0), ClientId(1), ClientId(2)]","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:44:34.561042998Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1200,"mrl":"dirty","":"mend"}
4922023-10-13T04:44:42.373Z{"msg":"extent:2 dirty: true true false","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:44:36.398299283Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1200,"mrl":"dirty","":"mend"}
4932023-10-13T04:44:42.379Z{"msg":"find dest for source 0 for extent at index 2","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:44:36.398380865Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1200,"mrl":"dirty","":"mend"}
4942023-10-13T04:44:42.384Z{"msg":"source 0, add dest 1 source flush","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:44:36.398428014Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1200,"mrl":"dirty","":"mend"}
4952023-10-13T04:44:42.398Z{"msg":"source 0, add dest 2 source flush","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:44:36.398476452Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1200,"mrl":"dirty","":"mend"}
4962023-10-13T04:44:42.416Z{"msg":"Extents 3 dirty","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:44:36.398499801Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1200,"":"mend"}
4972023-10-13T04:44:42.439Z{"msg":"First source client ID for extent 3","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:44:36.398519286Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1200,"mrl":"dirty","":"mend"}
4982023-10-13T04:44:42.456Z{"msg":"extent:3 gens: 26 26 26","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:44:36.398538586Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1200,"mrl":"dirty","":"mend"}
4992023-10-13T04:44:42.879Z{"msg":"extent:3 flush: 1614 1614 1614 scs: [ClientId(0), ClientId(1), ClientId(2)]","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:44:36.398559292Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1200,"mrl":"dirty","":"mend"}
5002023-10-13T04:44:42.887Z{"msg":"max_flush now has: [ClientId(0), ClientId(1), ClientId(2)]","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:44:36.398579424Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1200,"mrl":"dirty","":"mend"}
5012023-10-13T04:44:42.897Z{"msg":"extent:3 dirty: true true false","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:44:36.398598627Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1200,"mrl":"dirty","":"mend"}
5022023-10-13T04:44:42.908Z{"msg":"find dest for source 0 for extent at index 3","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:44:36.398618355Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1200,"mrl":"dirty","":"mend"}
5032023-10-13T04:44:42.934Z{"msg":"source 0, add dest 1 source flush","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:44:36.398637569Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1200,"mrl":"dirty","":"mend"}
5042023-10-13T04:44:42.949Z{"msg":"source 0, add dest 2 source flush","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:44:36.398656668Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1200,"mrl":"dirty","":"mend"}
5052023-10-13T04:44:42.974Z{"msg":"Extents 4 dirty","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:44:36.398688047Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1200,"":"mend"}
5062023-10-13T04:44:42.992Z{"msg":"First source client ID for extent 4","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:44:36.398707835Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1200,"mrl":"dirty","":"mend"}
5072023-10-13T04:44:43.016Z{"msg":"extent:4 gens: 26 26 26","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:44:36.39872686Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1200,"mrl":"dirty","":"mend"}
5082023-10-13T04:44:43.022Z{"msg":"extent:4 flush: 1614 1614 1614 scs: [ClientId(0), ClientId(1), ClientId(2)]","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:44:36.398747446Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1200,"mrl":"dirty","":"mend"}
5092023-10-13T04:44:43.027Z{"msg":"max_flush now has: [ClientId(0), ClientId(1), ClientId(2)]","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:44:36.39876726Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1200,"mrl":"dirty","":"mend"}
5102023-10-13T04:44:43.042Z{"msg":"extent:4 dirty: true true false","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:44:36.398786276Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1200,"mrl":"dirty","":"mend"}
5112023-10-13T04:44:43.050Z{"msg":"find dest for source 0 for extent at index 4","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:44:36.398805446Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1200,"mrl":"dirty","":"mend"}
5122023-10-13T04:44:43.060Z{"msg":"source 0, add dest 1 source flush","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:44:36.398824327Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1200,"mrl":"dirty","":"mend"}
5132023-10-13T04:44:43.072Z{"msg":"source 0, add dest 2 source flush","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:44:36.39884316Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1200,"mrl":"dirty","":"mend"}
5142023-10-13T04:44:43.140Z{"msg":"Transition from WaitQuorum to Repair","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:44:36.398862772Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1200}
5152023-10-13T04:44:43.187Z{"msg":"Transition from WaitQuorum to Repair","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:44:36.398879969Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1200}
5162023-10-13T04:44:43.195Z{"msg":"Transition from WaitQuorum to Repair","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:44:36.398897261Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1200}
5172023-10-13T04:44:43.204Z{"msg":"Found 5 extents that need repair","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:44:36.398919421Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1200}
5182023-10-13T04:44:43.213Z{"msg":"Full repair list: {3: ExtentFix { source: ClientId(0), dest: [ClientId(1), ClientId(2)] }, 1: ExtentFix { source: ClientId(0), dest: [ClientId(1), ClientId(2)] }, 0: ExtentFix { source: ClientId(0), dest: [ClientId(1), ClientId(2)] }, 2: 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-13T04:44:36.39896756Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1200,"":"downstairs"}
5192023-10-13T04:44:43.224Z{"msg":"Task list: [ReconcileIO { id: ReconciliationId(0), op: ExtentFlush { repair_id: ReconciliationId(0), extent_id: 3, client_id: ClientId(0), flush_number: 1615, gen_number: 27 }, state: ClientData([New, New, New]) }, ReconcileIO { id: ReconciliationId(1), op: ExtentClose { repair_id: ReconciliationId(1), extent_id: 3 }, state: ClientData([New, New, New]) }, ReconcileIO { id: ReconciliationId(2), op: ExtentRepair { repair_id: ReconciliationId(2), extent_id: 3, source_client_id: ClientId(0), source_repair_address: 0.0.0.0:12810, dest_clients: [ClientId(1), ClientId(2)] }, state: ClientData([New, New, New]) }, ReconcileIO { id: ReconciliationId(3), op: ExtentReopen { repair_id: ReconciliationId(3), extent_id: 3 }, state: ClientData([New, New, New]) }, ReconcileIO { id: ReconciliationId(4), op: ExtentFlush { repair_id: ReconciliationId(4), extent_id: 1, client_id: ClientId(0), flush_number: 1615, gen_number: 27 }, state: ClientData([New, New, New]) }, ReconcileIO { id: ReconciliationId(5), op: ExtentClose { repair_id: ReconciliationId(5), extent_id: 1 }, state: ClientData([New, New, New]) }, ReconcileIO { id: ReconciliationId(6), op: ExtentRepair { repair_id: ReconciliationId(6), 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(7), op: ExtentReopen { repair_id: ReconciliationId(7), extent_id: 1 }, state: ClientData([New, New, New]) }, ReconcileIO { id: ReconciliationId(8), op: ExtentFlush { repair_id: ReconciliationId(8), extent_id: 0, client_id: ClientId(0), flush_number: 1615, gen_number: 27 }, state: ClientData([New, New, New]) }, ReconcileIO { id: ReconciliationId(9), op: ExtentClose { repair_id: ReconciliationId(9), extent_id: 0 }, state: ClientData([New, New, New]) }, ReconcileIO { id: ReconciliationId(10), op: ExtentRepair { repair_id: ReconciliationId(10), 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(11), op: ExtentReopen { repair_id: ReconciliationId(11), extent_id: 0 }, state: ClientData([New, New, New]) }, ReconcileIO { id: ReconciliationId(12), op: ExtentFlush { repair_id: ReconciliationId(12), extent_id: 2, client_id: ClientId(0), flush_number: 1615, gen_number: 27 }, state: ClientData([New, New, New]) }, ReconcileIO { id: ReconciliationId(13), op: ExtentClose { repair_id: ReconciliationId(13), extent_id: 2 }, state: ClientData([New, New, New]) }, ReconcileIO { id: ReconciliationId(14), op: ExtentRepair { repair_id: ReconciliationId(14), 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(15), op: ExtentReopen { repair_id: ReconciliationId(15), extent_id: 2 }, state: ClientData([New, New, New]) }, ReconcileIO { id: ReconciliationId(16), op: ExtentFlush { repair_id: ReconciliationId(16), extent_id: 4, client_id: ClientId(0), flush_number: 1615, gen_number: 27 }, 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-13T04:44:36.399113025Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1200,"":"downstairs"}
5202023-10-13T04:44:43.231Z{"msg":"Begin repair with 20 commands","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:44:38.907502823Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1200}
5212023-10-13T04:44:43.241Z{"msg":"Pop front: ReconcileIO { id: ReconciliationId(0), op: ExtentFlush { repair_id: ReconciliationId(0), extent_id: 3, client_id: ClientId(0), flush_number: 1615, gen_number: 27 }, state: ClientData([New, New, New]) }","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:44:38.907588733Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1200}
5222023-10-13T04:44:43.248Z{"msg":"Sent repair work, now wait for resp","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:44:38.907636061Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1200}
5232023-10-13T04:44:43.255Z{"msg":"[2] received reconcile message","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:44:38.907658701Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1200}
5242023-10-13T04:44:43.272Z{"msg":"[2] rep_in_progress: return ReconcileIO { id: ReconciliationId(0), op: ExtentFlush { repair_id: ReconciliationId(0), extent_id: 3, client_id: ClientId(0), flush_number: 1615, gen_number: 27 }, state: ClientData([New, New, InProgress]) }","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:44:38.907681742Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1200,"":"downstairs"}
5252023-10-13T04:44:43.279Z{"msg":"[0] received reconcile message","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:44:38.907701745Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1200}
5262023-10-13T04:44:43.315Z{"msg":"[2] client ExtentFlush { repair_id: ReconciliationId(0), extent_id: 3, client_id: ClientId(0), flush_number: 1615, gen_number: 27 }","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:44:38.907721774Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1200}
5272023-10-13T04:44:43.328Z{"msg":"[0] rep_in_progress: return ReconcileIO { id: ReconciliationId(0), op: ExtentFlush { repair_id: ReconciliationId(0), extent_id: 3, client_id: ClientId(0), flush_number: 1615, gen_number: 27 }, state: ClientData([InProgress, New, InProgress]) }","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:44:38.907745261Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1200,"":"downstairs"}
5282023-10-13T04:44:43.337Z{"msg":"[0] client ExtentFlush { repair_id: ReconciliationId(0), extent_id: 3, client_id: ClientId(0), flush_number: 1615, gen_number: 27 }","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:44:38.907774841Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1200}
5292023-10-13T04:44:43.348Z{"msg":"[1] received reconcile message","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:44:38.907805307Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1200}
5302023-10-13T04:44:43.359Z{"msg":"[1] rep_in_progress: return ReconcileIO { id: ReconciliationId(0), op: ExtentFlush { repair_id: ReconciliationId(0), extent_id: 3, client_id: ClientId(0), flush_number: 1615, gen_number: 27 }, state: ClientData([InProgress, InProgress, Done]) }","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:44:38.907846479Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1200,"":"downstairs"}
5312023-10-13T04:44:43.369Z{"msg":"[1] client ExtentFlush { repair_id: ReconciliationId(0), extent_id: 3, client_id: ClientId(0), flush_number: 1615, gen_number: 27 }","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:44:38.907889532Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1200}
5322023-10-13T04:44:43.378Z{"msg":"Completion from [0] id:0 status:true","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:44:38.90792775Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1200}
5332023-10-13T04:44:43.389Z{"msg":"[1/20] Repair commands completed","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:44:38.907963933Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1200}
5342023-10-13T04:44:43.397Z{"msg":"Pop front: ReconcileIO { id: ReconciliationId(1), op: ExtentClose { repair_id: ReconciliationId(1), extent_id: 3 }, state: ClientData([New, New, New]) }","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:44:38.908004204Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1200}
5352023-10-13T04:44:43.409Z{"msg":"Sent repair work, now wait for resp","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:44:38.908038587Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1200}
5362023-10-13T04:44:43.438Z{"msg":"[2] received reconcile message","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:44:38.908069257Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1200}
5372023-10-13T04:44:43.446Z{"msg":"[2] rep_in_progress: return ReconcileIO { id: ReconciliationId(1), op: ExtentClose { repair_id: ReconciliationId(1), extent_id: 3 }, state: ClientData([New, New, InProgress]) }","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:44:38.908093976Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1200,"":"downstairs"}
5382023-10-13T04:44:43.454Z{"msg":"[2] client ExtentClose { repair_id: ReconciliationId(1), extent_id: 3 }","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:44:38.908114311Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1200}
5392023-10-13T04:44:43.463Z{"msg":"[0] received reconcile message","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:44:38.908131991Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1200}
5402023-10-13T04:44:43.472Z{"msg":"[0] rep_in_progress: return ReconcileIO { id: ReconciliationId(1), op: ExtentClose { repair_id: ReconciliationId(1), extent_id: 3 }, state: ClientData([InProgress, New, InProgress]) }","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:44:38.908196725Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1200,"":"downstairs"}
5412023-10-13T04:44:43.481Z{"msg":"[0] client ExtentClose { repair_id: ReconciliationId(1), extent_id: 3 }","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:44:38.908231948Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1200}
5422023-10-13T04:44:43.489Z{"msg":"[1] received reconcile message","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:44:38.908250567Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1200}
5432023-10-13T04:44:43.498Z{"msg":"[1] rep_in_progress: return ReconcileIO { id: ReconciliationId(1), op: ExtentClose { repair_id: ReconciliationId(1), extent_id: 3 }, state: ClientData([InProgress, InProgress, InProgress]) }","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:44:38.908271809Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1200,"":"downstairs"}
5442023-10-13T04:44:43.515Z{"msg":"[1] client ExtentClose { repair_id: ReconciliationId(1), extent_id: 3 }","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:44:38.908291089Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1200}
5452023-10-13T04:44:43.530Z{"msg":"Completion from [1] id:1 status:true","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:44:39.156413587Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1200}
5462023-10-13T04:44:43.964Z{"msg":"[2/20] Repair commands completed","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:44:39.15646094Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1200}
5472023-10-13T04:44:43.981Z{"msg":"Pop front: ReconcileIO { id: ReconciliationId(2), op: ExtentRepair { repair_id: ReconciliationId(2), extent_id: 3, source_client_id: ClientId(0), source_repair_address: 0.0.0.0:12810, dest_clients: [ClientId(1), ClientId(2)] }, state: ClientData([New, New, New]) }","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:44:39.156486699Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1200}
5482023-10-13T04:44:43.996Z{"msg":"Sent repair work, now wait for resp","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:44:39.156505177Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1200}
5492023-10-13T04:44:44.019Z{"msg":"[2] received reconcile message","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:44:39.156522746Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1200}
5502023-10-13T04:44:44.034Z{"msg":"[2] rep_in_progress: return ReconcileIO { id: ReconciliationId(2), op: ExtentRepair { repair_id: ReconciliationId(2), extent_id: 3, source_client_id: ClientId(0), source_repair_address: 0.0.0.0:12810, dest_clients: [ClientId(1), ClientId(2)] }, state: ClientData([New, New, InProgress]) }","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:44:39.156546778Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1200,"":"downstairs"}
5512023-10-13T04:44:44.040Z{"msg":"[2] client ExtentRepair { repair_id: ReconciliationId(2), 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-13T04:44:39.156569895Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1200}
5522023-10-13T04:44:44.045Z{"msg":"[2] Sending repair request ReconciliationId(2)","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:44:39.15658975Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1200}
5532023-10-13T04:44:44.055Z{"msg":"[0] received reconcile message","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:44:39.156607491Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1200}
5542023-10-13T04:44:44.064Z{"msg":"[0] rep_in_progress: return ReconcileIO { id: ReconciliationId(2), op: ExtentRepair { repair_id: ReconciliationId(2), extent_id: 3, source_client_id: ClientId(0), source_repair_address: 0.0.0.0:12810, dest_clients: [ClientId(1), ClientId(2)] }, state: ClientData([InProgress, New, InProgress]) }","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:44:39.15663174Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1200,"":"downstairs"}
5552023-10-13T04:44:44.074Z{"msg":"[0] client ExtentRepair { repair_id: ReconciliationId(2), 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-13T04:44:39.156654388Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1200}
5562023-10-13T04:44:44.082Z{"msg":"[0] No action required ReconciliationId(2)","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:44:39.156671784Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1200}
5572023-10-13T04:44:44.090Z{"msg":"[1] received reconcile message","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:44:39.156689018Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1200}
5582023-10-13T04:44:44.099Z{"msg":"[1] rep_in_progress: return ReconcileIO { id: ReconciliationId(2), op: ExtentRepair { repair_id: ReconciliationId(2), extent_id: 3, source_client_id: ClientId(0), source_repair_address: 0.0.0.0:12810, dest_clients: [ClientId(1), ClientId(2)] }, state: ClientData([Done, InProgress, InProgress]) }","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:44:39.156713278Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1200,"":"downstairs"}
5592023-10-13T04:44:44.106Z{"msg":"[1] client ExtentRepair { repair_id: ReconciliationId(2), 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-13T04:44:39.156745995Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1200}
5602023-10-13T04:44:44.116Z{"msg":"[1] Sending repair request ReconciliationId(2)","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:44:39.156780429Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1200}
5612023-10-13T04:44:44.123Z{"msg":"Completion from [1] id:2 status:true","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:44:39.156815598Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1200}
5622023-10-13T04:44:44.132Z{"msg":"[3/20] Repair commands completed","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:44:39.156851735Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1200}
5632023-10-13T04:44:44.137Z{"msg":"Pop front: ReconcileIO { id: ReconciliationId(3), op: ExtentReopen { repair_id: ReconciliationId(3), extent_id: 3 }, state: ClientData([New, New, New]) }","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:44:39.156893709Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1200}
5642023-10-13T04:44:44.142Z{"msg":"Sent repair work, now wait for resp","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:44:39.156928099Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1200}
5652023-10-13T04:44:44.158Z{"msg":"[2] received reconcile message","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:44:39.156961518Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1200}
5662023-10-13T04:44:44.171Z{"msg":"[2] rep_in_progress: return ReconcileIO { id: ReconciliationId(3), op: ExtentReopen { repair_id: ReconciliationId(3), extent_id: 3 }, state: ClientData([New, New, InProgress]) }","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:44:39.15699965Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1200,"":"downstairs"}
5672023-10-13T04:44:44.241Z{"msg":"[2] client ExtentReopen { repair_id: ReconciliationId(3), extent_id: 3 }","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:44:39.157035128Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1200}
5682023-10-13T04:44:44.244Z{"msg":"[0] received reconcile message","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:44:39.157066838Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1200}
5692023-10-13T04:44:44.247Z{"msg":"[0] rep_in_progress: return ReconcileIO { id: ReconciliationId(3), op: ExtentReopen { repair_id: ReconciliationId(3), extent_id: 3 }, state: ClientData([InProgress, New, InProgress]) }","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:44:39.157106211Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1200,"":"downstairs"}
5702023-10-13T04:44:44.250Z{"msg":"[0] client ExtentReopen { repair_id: ReconciliationId(3), extent_id: 3 }","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:44:39.157144463Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1200}
5712023-10-13T04:44:44.253Z{"msg":"[1] received reconcile message","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:44:39.157175052Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1200}
5722023-10-13T04:44:44.256Z{"msg":"[1] rep_in_progress: return ReconcileIO { id: ReconciliationId(3), op: ExtentReopen { repair_id: ReconciliationId(3), extent_id: 3 }, state: ClientData([InProgress, InProgress, InProgress]) }","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:44:39.157210845Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1200,"":"downstairs"}
5732023-10-13T04:44:44.260Z{"msg":"[1] client ExtentReopen { repair_id: ReconciliationId(3), extent_id: 3 }","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:44:39.157244659Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1200}
5742023-10-13T04:44:44.263Z{"msg":"Completion from [1] id:3 status:true","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:44:39.157279639Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1200}
5752023-10-13T04:44:44.266Z{"msg":"[4/20] Repair commands completed","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:44:39.157313916Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1200}
5762023-10-13T04:44:44.269Z{"msg":"Pop front: ReconcileIO { id: ReconciliationId(4), op: ExtentFlush { repair_id: ReconciliationId(4), extent_id: 1, client_id: ClientId(0), flush_number: 1615, gen_number: 27 }, state: ClientData([New, New, New]) }","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:44:39.342554576Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1200}
5772023-10-13T04:44:44.273Z{"msg":"Sent repair work, now wait for resp","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:44:39.342627675Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1200}
5782023-10-13T04:44:44.279Z{"msg":"[2] received reconcile message","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:44:39.342671299Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1200}
5792023-10-13T04:44:44.284Z{"msg":"[2] rep_in_progress: return ReconcileIO { id: ReconciliationId(4), op: ExtentFlush { repair_id: ReconciliationId(4), extent_id: 1, client_id: ClientId(0), flush_number: 1615, gen_number: 27 }, state: ClientData([New, New, InProgress]) }","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:44:39.342697145Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1200,"":"downstairs"}
5802023-10-13T04:44:44.288Z{"msg":"[2] client ExtentFlush { repair_id: ReconciliationId(4), extent_id: 1, client_id: ClientId(0), flush_number: 1615, gen_number: 27 }","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:44:39.342719946Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1200}
5812023-10-13T04:44:44.291Z{"msg":"[0] received reconcile message","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:44:39.342737944Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1200}
5822023-10-13T04:44:44.294Z{"msg":"[1] received reconcile message","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:44:39.342754991Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1200}
5832023-10-13T04:44:44.297Z{"msg":"[0] rep_in_progress: return ReconcileIO { id: ReconciliationId(4), op: ExtentFlush { repair_id: ReconciliationId(4), extent_id: 1, client_id: ClientId(0), flush_number: 1615, gen_number: 27 }, state: ClientData([InProgress, New, Done]) }","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:44:39.342777377Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1200,"":"downstairs"}
5842023-10-13T04:44:44.300Z{"msg":"[0] client ExtentFlush { repair_id: ReconciliationId(4), extent_id: 1, client_id: ClientId(0), flush_number: 1615, gen_number: 27 }","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:44:39.342798647Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1200}
5852023-10-13T04:44:44.302Z{"msg":"[1] rep_in_progress: return ReconcileIO { id: ReconciliationId(4), op: ExtentFlush { repair_id: ReconciliationId(4), extent_id: 1, client_id: ClientId(0), flush_number: 1615, gen_number: 27 }, state: ClientData([InProgress, InProgress, Done]) }","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:44:39.342821758Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1200,"":"downstairs"}
5862023-10-13T04:44:44.305Z{"msg":"[1] client ExtentFlush { repair_id: ReconciliationId(4), extent_id: 1, client_id: ClientId(0), flush_number: 1615, gen_number: 27 }","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:44:39.342842667Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1200}
5872023-10-13T04:44:44.308Z{"msg":"Completion from [0] id:4 status:true","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:44:39.34286028Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1200}
5882023-10-13T04:44:44.311Z{"msg":"[5/20] Repair commands completed","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:44:39.342877488Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1200}
5892023-10-13T04:44:44.320Z{"msg":"Pop front: ReconcileIO { id: ReconciliationId(5), op: ExtentClose { repair_id: ReconciliationId(5), extent_id: 1 }, state: ClientData([New, New, New]) }","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:44:39.342897846Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1200}
5902023-10-13T04:44:44.327Z{"msg":"Sent repair work, now wait for resp","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:44:39.342915421Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1200}
5912023-10-13T04:44:44.336Z{"msg":"[2] received reconcile message","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:44:39.342932729Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1200}
5922023-10-13T04:44:44.347Z{"msg":"[2] rep_in_progress: return ReconcileIO { id: ReconciliationId(5), op: ExtentClose { repair_id: ReconciliationId(5), extent_id: 1 }, state: ClientData([New, New, InProgress]) }","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:44:39.342953715Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1200,"":"downstairs"}
5932023-10-13T04:44:44.355Z{"msg":"[2] client ExtentClose { repair_id: ReconciliationId(5), extent_id: 1 }","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:44:39.342973245Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1200}
5942023-10-13T04:44:44.366Z{"msg":"[0] received reconcile message","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:44:39.342990911Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1200}
5952023-10-13T04:44:44.378Z{"msg":"[0] rep_in_progress: return ReconcileIO { id: ReconciliationId(5), op: ExtentClose { repair_id: ReconciliationId(5), extent_id: 1 }, state: ClientData([InProgress, New, InProgress]) }","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:44:39.343012206Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1200,"":"downstairs"}
5962023-10-13T04:44:44.389Z{"msg":"[0] client ExtentClose { repair_id: ReconciliationId(5), extent_id: 1 }","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:44:39.34303205Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1200}
5972023-10-13T04:44:44.400Z{"msg":"[1] received reconcile message","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:44:39.343049338Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1200}
5982023-10-13T04:44:44.406Z{"msg":"[1] rep_in_progress: return ReconcileIO { id: ReconciliationId(5), op: ExtentClose { repair_id: ReconciliationId(5), extent_id: 1 }, state: ClientData([InProgress, InProgress, InProgress]) }","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:44:39.343070709Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1200,"":"downstairs"}
5992023-10-13T04:44:44.425Z{"msg":"[1] client ExtentClose { repair_id: ReconciliationId(5), extent_id: 1 }","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:44:39.343089905Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1200}
6002023-10-13T04:44:44.438Z{"msg":"Completion from [1] id:5 status:true","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:44:39.343106989Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1200}
6012023-10-13T04:44:44.463Z{"msg":"[6/20] Repair commands completed","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:44:39.343124488Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1200}
6022023-10-13T04:44:44.482Z{"msg":"Pop front: ReconcileIO { id: ReconciliationId(6), op: ExtentRepair { repair_id: ReconciliationId(6), 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-13T04:44:39.343147369Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1200}
6032023-10-13T04:44:44.495Z{"msg":"Sent repair work, now wait for resp","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:44:39.343164756Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1200}
6042023-10-13T04:44:44.506Z{"msg":"[2] received reconcile message","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:44:39.343181648Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1200}
6052023-10-13T04:44:44.521Z{"msg":"[2] rep_in_progress: return ReconcileIO { id: ReconciliationId(6), op: ExtentRepair { repair_id: ReconciliationId(6), 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-13T04:44:39.343205194Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1200,"":"downstairs"}
6062023-10-13T04:44:44.535Z{"msg":"[2] client ExtentRepair { repair_id: ReconciliationId(6), 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-13T04:44:39.343227524Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1200}
6072023-10-13T04:44:44.553Z{"msg":"[2] Sending repair request ReconciliationId(6)","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:44:39.343244884Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1200}
6082023-10-13T04:44:44.566Z{"msg":"[0] received reconcile message","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:44:41.33512954Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1200}
6092023-10-13T04:44:44.575Z{"msg":"[0] rep_in_progress: return ReconcileIO { id: ReconciliationId(6), op: ExtentRepair { repair_id: ReconciliationId(6), 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-13T04:44:41.335191182Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1200,"":"downstairs"}
6102023-10-13T04:44:44.591Z{"msg":"[0] client ExtentRepair { repair_id: ReconciliationId(6), 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-13T04:44:41.335221424Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1200}
6112023-10-13T04:44:44.608Z{"msg":"[0] No action required ReconciliationId(6)","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:44:41.335240149Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1200}
6122023-10-13T04:44:44.618Z{"msg":"[1] received reconcile message","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:44:41.335257335Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1200}
6132023-10-13T04:44:44.637Z{"msg":"[1] rep_in_progress: return ReconcileIO { id: ReconciliationId(6), op: ExtentRepair { repair_id: ReconciliationId(6), 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-13T04:44:41.335290058Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1200,"":"downstairs"}
6142023-10-13T04:44:44.645Z{"msg":"[1] client ExtentRepair { repair_id: ReconciliationId(6), 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-13T04:44:41.335327286Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1200}
6152023-10-13T04:44:44.655Z{"msg":"[1] Sending repair request ReconciliationId(6)","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:44:41.33535609Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1200}
6162023-10-13T04:44:44.664Z{"msg":"Completion from [2] id:6 status:true","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:44:41.335383729Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1200}
6172023-10-13T04:44:44.672Z{"msg":"[7/20] Repair commands completed","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:44:41.335411687Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1200}
6182023-10-13T04:44:44.681Z{"msg":"Pop front: ReconcileIO { id: ReconciliationId(7), op: ExtentReopen { repair_id: ReconciliationId(7), extent_id: 1 }, state: ClientData([New, New, New]) }","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:44:41.335445619Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1200}
6192023-10-13T04:44:44.691Z{"msg":"Sent repair work, now wait for resp","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:44:41.335477744Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1200}
6202023-10-13T04:44:44.705Z{"msg":"[2] received reconcile message","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:44:41.335508483Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1200}
6212023-10-13T04:44:44.711Z{"msg":"[0] received reconcile message","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:44:41.335536334Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1200}
6222023-10-13T04:44:44.722Z{"msg":"[1] received reconcile message","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:44:41.335566496Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1200}
6232023-10-13T04:44:44.730Z{"msg":"[2] rep_in_progress: return ReconcileIO { id: ReconciliationId(7), op: ExtentReopen { repair_id: ReconciliationId(7), extent_id: 1 }, state: ClientData([New, New, InProgress]) }","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:44:41.335603574Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1200,"":"downstairs"}
6242023-10-13T04:44:44.734Z{"msg":"[2] client ExtentReopen { repair_id: ReconciliationId(7), extent_id: 1 }","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:44:41.335638461Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1200}
6252023-10-13T04:44:44.739Z{"msg":"[0] rep_in_progress: return ReconcileIO { id: ReconciliationId(7), op: ExtentReopen { repair_id: ReconciliationId(7), extent_id: 1 }, state: ClientData([InProgress, New, InProgress]) }","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:44:41.33567483Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1200,"":"downstairs"}
6262023-10-13T04:44:44.745Z{"msg":"[0] client ExtentReopen { repair_id: ReconciliationId(7), extent_id: 1 }","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:44:41.335708308Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1200}
6272023-10-13T04:44:44.748Z{"msg":"[1] rep_in_progress: return ReconcileIO { id: ReconciliationId(7), op: ExtentReopen { repair_id: ReconciliationId(7), extent_id: 1 }, state: ClientData([InProgress, InProgress, InProgress]) }","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:44:41.335745393Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1200,"":"downstairs"}
6282023-10-13T04:44:44.752Z{"msg":"[1] client ExtentReopen { repair_id: ReconciliationId(7), extent_id: 1 }","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:44:41.335777492Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1200}
6292023-10-13T04:44:44.757Z{"msg":"Completion from [1] id:7 status:true","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:44:41.335808009Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1200}
6302023-10-13T04:44:44.760Z{"msg":"[8/20] Repair commands completed","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:44:41.335836756Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1200}
6312023-10-13T04:44:44.764Z{"msg":"Pop front: ReconcileIO { id: ReconciliationId(8), op: ExtentFlush { repair_id: ReconciliationId(8), extent_id: 0, client_id: ClientId(0), flush_number: 1615, gen_number: 27 }, state: ClientData([New, New, New]) }","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:44:41.335873104Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1200}
6322023-10-13T04:44:44.771Z{"msg":"Sent repair work, now wait for resp","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:44:41.335905679Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1200}
6332023-10-13T04:44:44.776Z{"msg":"[2] received reconcile message","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:44:41.335937967Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1200}
6342023-10-13T04:44:44.779Z{"msg":"[2] rep_in_progress: return ReconcileIO { id: ReconciliationId(8), op: ExtentFlush { repair_id: ReconciliationId(8), extent_id: 0, client_id: ClientId(0), flush_number: 1615, gen_number: 27 }, state: ClientData([New, New, InProgress]) }","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:44:41.335976092Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1200,"":"downstairs"}
6352023-10-13T04:44:44.782Z{"msg":"[2] client ExtentFlush { repair_id: ReconciliationId(8), extent_id: 0, client_id: ClientId(0), flush_number: 1615, gen_number: 27 }","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:44:41.336015569Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1200}
6362023-10-13T04:44:44.787Z{"msg":"[1] received reconcile message","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:44:41.336051028Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1200}
6372023-10-13T04:44:44.800Z{"msg":"[1] rep_in_progress: return ReconcileIO { id: ReconciliationId(8), op: ExtentFlush { repair_id: ReconciliationId(8), extent_id: 0, client_id: ClientId(0), flush_number: 1615, gen_number: 27 }, state: ClientData([New, InProgress, Done]) }","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:44:41.33609285Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1200,"":"downstairs"}
6382023-10-13T04:44:44.814Z{"msg":"[0] received reconcile message","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:44:41.336130111Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1200}
6392023-10-13T04:44:44.823Z{"msg":"[1] client ExtentFlush { repair_id: ReconciliationId(8), extent_id: 0, client_id: ClientId(0), flush_number: 1615, gen_number: 27 }","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:44:43.024070948Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1200}
6402023-10-13T04:44:44.826Z{"msg":"[0] rep_in_progress: return ReconcileIO { id: ReconciliationId(8), op: ExtentFlush { repair_id: ReconciliationId(8), extent_id: 0, client_id: ClientId(0), flush_number: 1615, gen_number: 27 }, state: ClientData([InProgress, Done, Done]) }","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:44:43.024130565Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1200,"":"downstairs"}
6412023-10-13T04:44:44.829Z{"msg":"[0] client ExtentFlush { repair_id: ReconciliationId(8), extent_id: 0, client_id: ClientId(0), flush_number: 1615, gen_number: 27 }","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:44:43.024155153Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1200}
6422023-10-13T04:44:44.833Z{"msg":"Completion from [0] id:8 status:true","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:44:43.024173622Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1200}
6432023-10-13T04:44:44.836Z{"msg":"[9/20] Repair commands completed","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:44:43.024191304Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1200}
6442023-10-13T04:44:44.840Z{"msg":"Pop front: ReconcileIO { id: ReconciliationId(9), op: ExtentClose { repair_id: ReconciliationId(9), extent_id: 0 }, state: ClientData([New, New, New]) }","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:44:43.024211646Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1200}
6452023-10-13T04:44:44.843Z{"msg":"Sent repair work, now wait for resp","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:44:43.024229344Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1200}
6462023-10-13T04:44:44.846Z{"msg":"[2] received reconcile message","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:44:43.024246432Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1200}
6472023-10-13T04:44:44.853Z{"msg":"[2] rep_in_progress: return ReconcileIO { id: ReconciliationId(9), op: ExtentClose { repair_id: ReconciliationId(9), extent_id: 0 }, state: ClientData([New, New, InProgress]) }","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:44:43.024275063Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1200,"":"downstairs"}
6482023-10-13T04:44:44.865Z{"msg":"[2] client ExtentClose { repair_id: ReconciliationId(9), extent_id: 0 }","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:44:43.02431207Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1200}
6492023-10-13T04:44:44.872Z{"msg":"[0] received reconcile message","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:44:43.024334165Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1200}
6502023-10-13T04:44:44.876Z{"msg":"[0] rep_in_progress: return ReconcileIO { id: ReconciliationId(9), op: ExtentClose { repair_id: ReconciliationId(9), extent_id: 0 }, state: ClientData([InProgress, New, InProgress]) }","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:44:43.024355665Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1200,"":"downstairs"}
6512023-10-13T04:44:44.879Z{"msg":"[0] client ExtentClose { repair_id: ReconciliationId(9), extent_id: 0 }","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:44:43.024375332Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1200}
6522023-10-13T04:44:44.882Z{"msg":"[1] received reconcile message","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:44:43.024392842Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1200}
6532023-10-13T04:44:44.886Z{"msg":"[1] rep_in_progress: return ReconcileIO { id: ReconciliationId(9), op: ExtentClose { repair_id: ReconciliationId(9), extent_id: 0 }, state: ClientData([InProgress, InProgress, InProgress]) }","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:44:43.024414166Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1200,"":"downstairs"}
6542023-10-13T04:44:44.896Z{"msg":"[1] client ExtentClose { repair_id: ReconciliationId(9), extent_id: 0 }","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:44:43.024433424Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1200}
6552023-10-13T04:44:44.905Z{"msg":"Completion from [1] id:9 status:true","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:44:43.024451031Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1200}
6562023-10-13T04:44:44.918Z{"msg":"[10/20] Repair commands completed","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:44:43.024468221Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1200}
6572023-10-13T04:44:44.921Z{"msg":"Pop front: ReconcileIO { id: ReconciliationId(10), op: ExtentRepair { repair_id: ReconciliationId(10), 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-13T04:44:43.024491646Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1200}
6582023-10-13T04:44:44.925Z{"msg":"Sent repair work, now wait for resp","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:44:43.024509184Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1200}
6592023-10-13T04:44:44.930Z{"msg":"[2] received reconcile message","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:44:43.024526143Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1200}
6602023-10-13T04:44:44.935Z{"msg":"[2] rep_in_progress: return ReconcileIO { id: ReconciliationId(10), op: ExtentRepair { repair_id: ReconciliationId(10), 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-13T04:44:43.024549633Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1200,"":"downstairs"}
6612023-10-13T04:44:44.938Z{"msg":"[0] received reconcile message","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:44:43.024567781Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1200}
6622023-10-13T04:44:44.941Z{"msg":"[2] client ExtentRepair { repair_id: ReconciliationId(10), 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-13T04:44:43.024588791Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1200}
6632023-10-13T04:44:44.945Z{"msg":"[2] Sending repair request ReconciliationId(10)","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:44:43.024606421Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1200}
6642023-10-13T04:44:44.948Z{"msg":"[0] rep_in_progress: return ReconcileIO { id: ReconciliationId(10), op: ExtentRepair { repair_id: ReconciliationId(10), 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-13T04:44:43.024630141Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1200,"":"downstairs"}
6652023-10-13T04:44:44.952Z{"msg":"[0] client ExtentRepair { repair_id: ReconciliationId(10), 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-13T04:44:43.024652536Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1200}
6662023-10-13T04:44:44.956Z{"msg":"[0] No action required ReconciliationId(10)","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:44:43.024669886Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1200}
6672023-10-13T04:44:44.961Z{"msg":"[1] received reconcile message","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:44:43.024686751Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1200}
6682023-10-13T04:44:44.964Z{"msg":"[1] rep_in_progress: return ReconcileIO { id: ReconciliationId(10), op: ExtentRepair { repair_id: ReconciliationId(10), 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-13T04:44:43.024710697Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1200,"":"downstairs"}
6692023-10-13T04:44:44.968Z{"msg":"[1] client ExtentRepair { repair_id: ReconciliationId(10), 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-13T04:44:43.024746253Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1200}
6702023-10-13T04:44:44.987Z{"msg":"[1] Sending repair request ReconciliationId(10)","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:44:43.475867018Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1200}
6712023-10-13T04:44:44.993Z{"msg":"Completion from [1] id:10 status:true","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:44:43.475917979Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1200}
6722023-10-13T04:44:44.997Z{"msg":"[11/20] Repair commands completed","v":0,"name":"crucible","The guest has finished waiting for activation with:28
6732023-10-13T04:44:45.002Zlevel":30Wait for a query_work_queue command to finish before sending IO
6742023-10-13T04:44:45.011Z,"time":"2023-10-13T04:44:43.475942319Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1200}
6752023-10-13T04:44:45.021Z{"msg":"Pop front: ReconcileIO { id: ReconciliationId(11), op: ExtentReopen { repair_id: ReconciliationId(11), extent_id: 0 }, state: ClientData([New, New, New]) }","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:44:43.475964096Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1200}
6762023-10-13T04:44:45.039Z{"msg":"Sent repair work, now wait for resp","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:44:43.47598215Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1200}
6772023-10-13T04:44:45.043Z{"msg":"[2] received reconcile message","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:44:43.475999465Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1200}
6782023-10-13T04:44:45.048Z{"msg":"[2] rep_in_progress: return ReconcileIO { id: ReconciliationId(11), op: ExtentReopen { repair_id: ReconciliationId(11), extent_id: 0 }, state: ClientData([New, New, InProgress]) }","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:44:43.476020564Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1200,"":"downstairs"}
6792023-10-13T04:44:45.072Z{"msg":"[2] client ExtentReopen { repair_id: ReconciliationId(11), extent_id: 0 }","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:44:43.476041381Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1200}
6802023-10-13T04:44:45.078Z{"msg":"[0] received reconcile message","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:44:43.476059269Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1200}
6812023-10-13T04:44:45.100Z{"msg":"[0] rep_in_progress: return ReconcileIO { id: ReconciliationId(11), op: ExtentReopen { repair_id: ReconciliationId(11), extent_id: 0 }, state: ClientData([InProgress, New, InProgress]) }","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:44:43.476080277Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1200,"":"downstairs"}
6822023-10-13T04:44:45.110Z{"msg":"[0] client ExtentReopen { repair_id: ReconciliationId(11), extent_id: 0 }","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:44:43.476099924Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1200}
6832023-10-13T04:44:45.117Z{"msg":"[1] received reconcile message","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:44:43.476117419Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1200}
6842023-10-13T04:44:45.131Z{"msg":"[1] rep_in_progress: return ReconcileIO { id: ReconciliationId(11), op: ExtentReopen { repair_id: ReconciliationId(11), extent_id: 0 }, state: ClientData([InProgress, InProgress, InProgress]) }","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:44:43.476139025Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1200,"":"downstairs"}
6852023-10-13T04:44:45.145Z{"msg":"[1] client ExtentReopen { repair_id: ReconciliationId(11), extent_id: 0 }","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:44:43.476158282Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1200}
6862023-10-13T04:44:45.153Z{"msg":"Completion from [1] id:11 status:true","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:44:43.476175913Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1200}
6872023-10-13T04:44:45.156Z{"msg":"[12/20] Repair commands completed","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:44:43.476193027Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1200}
6882023-10-13T04:44:45.159Z{"msg":"Pop front: ReconcileIO { id: ReconciliationId(12), op: ExtentFlush { repair_id: ReconciliationId(12), extent_id: 2, client_id: ClientId(0), flush_number: 1615, gen_number: 27 }, state: ClientData([New, New, New]) }","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:44:43.47621459Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1200}
6892023-10-13T04:44:45.163Z{"msg":"Sent repair work, now wait for resp","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:44:43.476231527Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1200}
6902023-10-13T04:44:45.166Z{"msg":"[2] received reconcile message","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:44:43.476248422Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1200}
6912023-10-13T04:44:45.169Z{"msg":"[2] rep_in_progress: return ReconcileIO { id: ReconciliationId(12), op: ExtentFlush { repair_id: ReconciliationId(12), extent_id: 2, client_id: ClientId(0), flush_number: 1615, gen_number: 27 }, state: ClientData([New, New, InProgress]) }","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:44:43.476270508Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1200,"":"downstairs"}
6922023-10-13T04:44:45.172Z{"msg":"[2] client ExtentFlush { repair_id: ReconciliationId(12), extent_id: 2, client_id: ClientId(0), flush_number: 1615, gen_number: 27 }","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:44:43.476291517Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1200}
6932023-10-13T04:44:45.175Z{"msg":"[0] received reconcile message","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:44:43.476308916Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1200}
6942023-10-13T04:44:45.179Z{"msg":"[0] rep_in_progress: return ReconcileIO { id: ReconciliationId(12), op: ExtentFlush { repair_id: ReconciliationId(12), extent_id: 2, client_id: ClientId(0), flush_number: 1615, gen_number: 27 }, state: ClientData([InProgress, New, Done]) }","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:44:43.476331027Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1200,"":"downstairs"}
6952023-10-13T04:44:45.182Z{"msg":"[0] client ExtentFlush { repair_id: ReconciliationId(12), extent_id: 2, client_id: ClientId(0), flush_number: 1615, gen_number: 27 }","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:44:43.47635189Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1200}
6962023-10-13T04:44:45.185Z{"msg":"[1] received reconcile message","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:44:43.476369129Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1200}
6972023-10-13T04:44:45.188Z{"msg":"[1] rep_in_progress: return ReconcileIO { id: ReconciliationId(12), op: ExtentFlush { repair_id: ReconciliationId(12), extent_id: 2, client_id: ClientId(0), flush_number: 1615, gen_number: 27 }, state: ClientData([InProgress, InProgress, Done]) }","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:44:43.476392127Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1200,"":"downstairs"}
6982023-10-13T04:44:45.192Z{"msg":"[1] client ExtentFlush { repair_id: ReconciliationId(12), extent_id: 2, client_id: ClientId(0), flush_number: 1615, gen_number: 27 }","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:44:43.476413198Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1200}
6992023-10-13T04:44:45.196Z{"msg":"Completion from [0] id:12 status:true","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:44:43.476430839Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1200}
7002023-10-13T04:44:45.202Z{"msg":"[13/20] Repair commands completed","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:44:43.476448171Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1200}
7012023-10-13T04:44:45.207Z{"msg":"Pop front: ReconcileIO { id: ReconciliationId(13), op: ExtentClose { repair_id: ReconciliationId(13), extent_id: 2 }, state: ClientData([New, New, New]) }","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:44:43.47646849Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1200}
7022023-10-13T04:44:45.214Z{"msg":"Sent repair work, now wait for resp","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:44:43.476486007Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1200}
7032023-10-13T04:44:45.221Z{Region: es:10 ec:5 bs:4096 ts:204800 tb:50 max_io:50 or 204800
7042023-10-13T04:44:45.227Z"msg":"[2] received reconcile message","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:44:44.255193542Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1200}
7052023-10-13T04:44:45.233Z{"msg":"[2] rep_in_progress: return ReconcileIO { id: ReconciliationId(13), op: ExtentClose { repair_id: ReconciliationId(13), extent_id: 2 }, state: ClientData([New, New, InProgress]) }","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:44:44.255250247Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1200,"":"downstairs"}
7062023-10-13T04:44:45.239Z{"msg":"[2] client ExtentClose { repair_id: ReconciliationId(13), extent_id: 2 }","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:44:44.255272657Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1200}
7072023-10-13T04:44:45.282Z{"msg":"[0] received reconcile message","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:44:44.255290567Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1200}
7082023-10-13T04:44:45.292Z{"msg":"[1] received reconcile message","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:44:44.255307722Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1200}
7092023-10-13T04:44:45.303Z{"msg":"[0] rep_in_progress: return ReconcileIO { id: ReconciliationId(13), op: ExtentClose { repair_id: ReconciliationId(13), extent_id: 2 }, state: ClientData([InProgress, New, Done]) }","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:44:44.255328572Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1200,"":"downstairs"}
7102023-10-13T04:44:45.314Z{"msg":"[0] client ExtentClose { repair_id: ReconciliationId(13), extent_id: 2 }","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:44:44.255348077Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1200}
7112023-10-13T04:44:45.323Z{"msg":"[1] rep_in_progress: return ReconcileIO { id: ReconciliationId(13), op: ExtentClose { repair_id: ReconciliationId(13), extent_id: 2 }, state: ClientData([InProgress, InProgress, Done]) }","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:44:44.255369755Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1200,"":"downstairs"}
7122023-10-13T04:44:45.328Z{"msg":"[1] client ExtentClose { repair_id: ReconciliationId(13), extent_id: 2 }","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:44:44.255388937Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1200}
7132023-10-13T04:44:45.337Z{"msg":"Completion from [1] id:13 status:true","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:44:44.255406717Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1200}
7142023-10-13T04:44:45.346Z{"msg":"[14/20] Repair commands completed","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:44:44.255423594Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1200}
7152023-10-13T04:44:45.351ZLoading write count information from file "/var/tmp/test_up/verify_file"
7162023-10-13T04:44:45.355Z{"msg":"Pop front: ReconcileIO { id: ReconciliationId(14), op: ExtentRepair { repair_id: ReconciliationId(14), 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-13T04:44:44.255453793Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1200}
7172023-10-13T04:44:45.362Z{"msg":"Sent repair work, now wait for resp","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:44:44.255471222Z","Read and Verify all blocks (0..50 range:true)
7182023-10-13T04:44:45.374Zhostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1200}
7192023-10-13T04:44:45.802Z{"msg":"[2] received reconcile message","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:44:44.25549204Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1200}
7202023-10-13T04:44:45.829Z{"msg":"[2] rep_in_progress: return ReconcileIO { id: ReconciliationId(14), op: ExtentRepair { repair_id: ReconciliationId(14), 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-13T04:44:44.255516099Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1200,"":"downstairs"}
7212023-10-13T04:44:45.874Z{"msg":"[2] client ExtentRepair { repair_id: ReconciliationId(14), 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-13T04:44:44.255538217Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1200}
7222023-10-13T04:44:45.924Z{"msg":"[2] Sending repair request ReconciliationId(14)","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:44:44.255556307Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1200}
7232023-10-13T04:44:45.953Z{"msg":"[0] received reconcile message","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:44:44.255573287Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1200}
7242023-10-13T04:44:45.971Z{"msg":"[0] rep_in_progress: return ReconcileIO { id: ReconciliationId(14), op: ExtentRepair { repair_id: ReconciliationId(14), 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-13T04:44:44.255596851Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1200,"":"downstairs"}
7252023-10-13T04:44:46.011Z{"msg":"[0] client ExtentRepair { repair_id: ReconciliationId(14), 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-13T04:44:44.255619303Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1200}
7262023-10-13T04:44:46.043Z{"msg":"[0] No action required ReconciliationId(14)","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:44:44.255636973Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1200}
7272023-10-13T04:44:46.058Z{"msg":"[1] received reconcile message","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:44:44.25565375Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1200}
7282023-10-13T04:44:46.075Z{"msg":"[1] rep_in_progress: return ReconcileIO { id: ReconciliationId(14), op: ExtentRepair { repair_id: ReconciliationId(14), 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-13T04:44:44.255677549Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1200,"":"downstairs"}
7292023-10-13T04:44:46.091Z{"msg":"[1] client ExtentRepair { repair_id: ReconciliationId(14), 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-13T04:44:44.255699563Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1200}
7302023-10-13T04:44:46.109Z{"msg":"[1] Sending repair request ReconciliationId(14)","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:44:44.25571729Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1200}
7312023-10-13T04:44:46.143Z{"msg":"Completion from [1] id:14 status:true","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:44:44.255734703Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1200}
7322023-10-13T04:44:46.154Z{"msg":"[15/20] Repair commands completed","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:44:44.255751942Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1200}
7332023-10-13T04:44:46.163Z{"msg":"Pop front: ReconcileIO { id: ReconciliationId(15), op: ExtentReopen { repair_id: ReconciliationId(15), extent_id: 2 }, state: ClientData([New, New, New]) }","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:44:44.255772483Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1200}
7342023-10-13T04:44:46.170Z{"msg":"Sent repair work, now wait for resp","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:44:44.255790059Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1200}
7352023-10-13T04:44:46.176Z{"msg":"[2] received reconcile message","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:44:44.255807615Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1200}
7362023-10-13T04:44:46.194Z{Wrote out file "/var/tmp/test_up/verify_file"
7372023-10-13T04:44:46.199Z"msgVerify test completed
7382023-10-13T04:44:46.203Z":"[2] rep_in_progress: return ReconcileIO { id: ReconciliationId(15), op: ExtentReopen { repair_id: ReconciliationId(15), extent_id: 2 }, state: ClientData([New, New, InProgress]) }","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:44:44.488528747Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1200,"":"downstairs"}
7392023-10-13T04:44:46.209Z{"msg":"[2] client ExtentReopen { repair_id: ReconciliationId(15), extent_id: 2 }","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:44:44.488585383Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1200}
7402023-10-13T04:44:46.214Z{"msg":"[0] received reconcile message","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:44:44.488605168Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1200}
7412023-10-13T04:44:46.220Z{"msg":"[0] rep_in_progress: return ReconcileIO { id: ReconciliationId(15), op: ExtentReopen { repair_id: ReconciliationId(15), extent_id: 2 }, state: ClientData([InProgress, New, InProgress]) }","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:44:44.488626604Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1200,"":"downstairs"}
7422023-10-13T04:44:46.225Z{"msg":"[0] client ExtentReopen { repair_id: ReconciliationId(15), extent_id: 2 }","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:44:44.488646545Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1200}
7432023-10-13T04:44:46.232Z{"msg":"[1] received reconcile message","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:44:44.488663868Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1200}
7442023-10-13T04:44:46.237Z{"msg":"[1] rep_in_progress: return ReconcileIO { id: ReconciliationId(15), op: ExtentReopen { repair_id: ReconciliationId(15), extent_id: 2 }, state: ClientData([Done, InProgress, Done]) }","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:44:44.488685089Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1200,"":"downstairs"}
7452023-10-13T04:44:46.243Z{"msg":"[1] client ExtentReopen { repair_id: ReconciliationId(15), extent_id: 2 }","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:44:44.48870424Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1200}
7462023-10-13T04:44:46.253Z{"msg":"Completion from [1] id:15 status:true","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:44:44.488722697Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1200}
7472023-10-13T04:44:46.267Z{"msg":"[16/20] Repair commands completed","v":0,"name":"crucible","level":30,"Wrote out file "/var/tmp/test_up/verify_file"
7482023-10-13T04:44:46.276Ztime":CLIENT: Tests done. All submitted work has been ACK'd
7492023-10-13T04:44:46.695Z"2023-10-13T04:44:44.488739898Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1200}
7502023-10-13T04:44:46.704Z{"msg":"Pop front: ReconcileIO { id: ReconciliationId(16), op: ExtentFlush { repair_id: ReconciliationId(16), extent_id: 4, client_id: ClientId(0), flush_number: 1615, gen_number: 27 }, state: ClientData([New, New, New]) }","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:44:44.488768069Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1200}
7512023-10-13T04:44:47.126Z{"msg":"Sent repair work, now wait for resp","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:44:44.488785912Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1200}
7522023-10-13T04:44:47.139Z{"msg":"[2] received reconcile message","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:44:44.488802937Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1200}
7532023-10-13T04:44:47.159Z{"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: 1615, gen_number: 27 }, state: ClientData([New, New, InProgress]) }","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:44:44.488825226Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1200,"":"downstairs"}
7542023-10-13T04:44:47.167Z{"msg":"[2] client ExtentFlush { repair_id: ReconciliationId(16), extent_id: 4, client_id: ClientId(0), flush_number: 1615, gen_number: 27 }","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:44:44.48884654Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1200}
7552023-10-13T04:44:47.174Z{"msg":"[1] received reconcile message","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:44:44.488864177Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1200}
7562023-10-13T04:44:47.186Z{"msg":"[0] received reconcile message","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:44:44.488881184Z","hostname":"----------------------------------------------------------------
7572023-10-13T04:44:47.191Zip-10-150-1-198.us-west-2.compute.internal" Crucible gen:28 GIO:true work queues: Upstairs:0 downstairs:0
7582023-10-13T04:44:47.204Z,"pid":1200}
7592023-10-13T04:44:47.211Z{"msg":"Downstairs last five completed:[1] rep_in_progress: return ReconcileIO { id: ReconciliationId(16), op: ExtentFlush { repair_id: ReconciliationId(16), extent_id: 4, client_id: ClientId(0), flush_number: 1615, gen_number: 27 }, state: ClientData([New, InProgress, Done]) }" 1001, 1000
7602023-10-13T04:44:47.215Z"v":0,"name":"crucible","level":30Upstairs last five completed: ,"time":"2023-10-13T04:44:44.488913145Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1200,"":"downstairs"}
7612023-10-13T04:44:47.221Z 2{ 1
7622023-10-13T04:44:47.227Z"msg":"[1] client ExtentFlush { repair_id: ReconciliationId(16), extent_id: 4, client_id: ClientId(0), flush_number: 1615, gen_number: 27 }","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:44:44.488937069Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1200}
7632023-10-13T04:44:47.231Z{"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: 1615, gen_number: 27 }, state: ClientData([InProgress, InProgress, Done]) }","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:44:44.488960478Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1200,"":"downstairs"}
7642023-10-13T04:44:47.247Z{"msg":"[0] client ExtentFlush { repair_id: ReconciliationId(16), extent_id: 4, client_id: ClientId(0), flush_number: 1615, gen_number: 27 }","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:44:44.488981555Z","hostname"CLIENT: Up:0 ds:0 act:3
7652023-10-13T04:44:47.254ZCLIENT: All crucible jobs finished, exiting program
7662023-10-13T04:44:47.678Z:"ip-10-150-1-198.us-west-2.compute.internal","pid":1200}
7672023-10-13T04:44:47.694Z{"msg":"Completion from [0] id:16 status:true","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:44:44.489005069Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1200}
7682023-10-13T04:44:47.706Z{"msg":"[17/20] Repair commands completed","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:44:44.489022206Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1200}
7692023-10-13T04:44:47.721Z
7702023-10-13T04:44:47.736Z{"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-13T04:44:44.489042225Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1200}
7712023-10-13T04:44:47.749Zreal 2:01.068424076
7722023-10-13T04:44:47.759Z{"msg":"Sent repair work, now wait for resp","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:44:44.489059876Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1200}
7732023-10-13T04:44:47.768Zuser 1:18.944596217
7742023-10-13T04:44:47.776Z{"msg":"[2] received reconcile message","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:44:44.4890768Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1200}
7752023-10-13T04:44:47.790Zsys 18.223459982
7762023-10-13T04:44:47.799Z{"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-13T04:44:44.489097773Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1200,"":"downstairs"}
7772023-10-13T04:44:47.808Ztrap 0.155938199
7782023-10-13T04:44:47.825Z{"msg":"[2] client ExtentClose { repair_id: ReconciliationId(17), extent_id: 4 }","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:44:44.489117271Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1200}
7792023-10-13T04:44:47.834Ztflt 0.009024668
7802023-10-13T04:44:47.847Z{"msg":"[0] received reconcile message","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:44:44.489134389Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1200}
7812023-10-13T04:44:47.862Zdflt 0.065728943
7822023-10-13T04:44:47.879Z{"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-13T04:44:44.489167433Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1200,"":"downstairs"}
7832023-10-13T04:44:47.914Zkflt 0.000977689
7842023-10-13T04:44:47.923Z{"msg":"[0] client ExtentClose { repair_id: ReconciliationId(17), extent_id: 4 }","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:44:44.489205306Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1200}
7852023-10-13T04:44:47.932Zlock 18:07.402405740
7862023-10-13T04:44:47.938Z{"msg":"[1] received reconcile message","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:44:44.784999011Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1200}
7872023-10-13T04:44:47.943Zslp 3:49.681908045
7882023-10-13T04:44:47.950Z{"msg":"[1] rep_in_progress: return ReconcileIO { id: ReconciliationId(17), op: ExtentClose { repair_id: ReconciliationId(17), extent_id: 4 }, state: ClientData([InProgress, InProgress, InProgress]) }","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:44:44.785055721Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1200,"":"downstairs"}
7892023-10-13T04:44:47.956Zlat 14.483570403
7902023-10-13T04:44:47.962Z{"msg":"[1] client ExtentClose { repair_id: ReconciliationId(17), extent_id: 4 }","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:44:44.785078794Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1200}
7912023-10-13T04:44:47.967Zstop 0.027653586
7922023-10-13T04:44:47.976Z{"msg":"Completion from [1] id:17 status:true","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:44:44.78509755Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1200}
7932023-10-13T04:44:47.982Z{"msg":"[18/20] Repair commands completed","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:44:44.785115634Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1200}
7942023-10-13T04:44:47.987Z{"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-13T04:44:44.785139184Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1200}
7952023-10-13T04:44:47.992Z{"msg":"Sent repair work, now wait for resp","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:44:44.785156855Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1200}
7962023-10-13T04:44:47.998Z{"msg":"[2] received reconcile message","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:44:44.785173648Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1200}
7972023-10-13T04:44:48.004Z{"msg":"[0] received reconcile message","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:44:44.785190572Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1200}
7982023-10-13T04:44:48.424Z{"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-13T04:44:44.785214393Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1200,"":"downstairs"}
7992023-10-13T04:44:48.510Z{"msg":"[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":"crucible","level":30,"time":"2023-10-13T04:44:44.785236596Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1200}
8002023-10-13T04:44:48.524Z{"msg":"[2] Sending repair request ReconciliationId(18)","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:44:44.785254173Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1200}
8012023-10-13T04:44:48.539Z{"msg":"[1] received reconcile message","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:44:44.785271133Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1200}
8022023-10-13T04:44:48.553Z{"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-13T04:44:44.785294696Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1200,"":"downstairs"}
8032023-10-13T04:44:48.571Z{"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":30,"time":"2023-10-13T04:44:44.785316652Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1200}
8042023-10-13T04:44:48.594Z{"msg":"[0] No action required ReconciliationId(18)","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:44:44.785334037Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1200}
8052023-10-13T04:44:48.607Z{"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([InProgress, InProgress, InProgress]) }","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:44:44.785357848Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1200,"":"downstairs"}
8062023-10-13T04:44:48.624Z{"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-13T04:44:44.785380168Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1200}
8072023-10-13T04:44:48.640Z{"msg":"[1] Sending repair request ReconciliationId(18)","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:44:44.785397535Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1200}
8082023-10-13T04:44:48.651Z{"msg":"Completion from [1] id:18 status:true","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:44:44.785414751Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1200}
8092023-10-13T04:44:48.663Z{"msg":"[19/20] Repair commands completed","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:44:44.785431814Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1200}
8102023-10-13T04:44:48.673Z{"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-13T04:44:44.785452501Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1200}
8112023-10-13T04:44:48.685Z{"msg":"Sent repair work, now wait for resp","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:44:44.785470266Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1200}
8122023-10-13T04:44:48.693Z{"msg":"[2] received reconcile message","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:44:44.785487455Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1200}
8132023-10-13T04:44:48.704Z{"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-13T04:44:44.785508189Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1200,"":"downstairs"}
8142023-10-13T04:44:48.717Z{"msg":"[2] client ExtentReopen { repair_id: ReconciliationId(19), extent_id: 4 }","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:44:44.785527178Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1200}
8152023-10-13T04:44:48.726Z{"msg":"[0] received reconcile message","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:44:44.785544417Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1200}
8162023-10-13T04:44:48.734Z{"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-13T04:44:44.785565638Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1200,"":"downstairs"}
8172023-10-13T04:44:48.743Z{"msg":"[0] client ExtentReopen { repair_id: ReconciliationId(19), extent_id: 4 }","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:44:44.785584984Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1200}
8182023-10-13T04:44:48.754Z{"msg":"[1] received reconcile message","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:44:44.785601984Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1200}
8192023-10-13T04:44:48.770Z{"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-13T04:44:44.966322468Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1200,"":"downstairs"}
8202023-10-13T04:44:48.781Z{"msg":"[1] client ExtentReopen { repair_id: ReconciliationId(19), extent_id: 4 }","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:44:44.966361355Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1200}
8212023-10-13T04:44:49.238Z{"msg":"Completion from [1] id:19 status:true","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:44:44.966381269Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1200}
8222023-10-13T04:44:49.705Z{"msg":"[20/20] Repair commands completed","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:44:44.96639896Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1200}
8232023-10-13T04:44:49.743Z{"msg":"5 extents repaired in 8.543 ave:1.7086","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:44:44.966416689Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1200}
8242023-10-13T04:44:49.759Z{"msg":"All required repair work is completed","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:44:44.966434283Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1200}
8252023-10-13T04:44:49.779Z{"msg":"Set Downstairs and Upstairs active after repairs","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:44:44.966451994Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1200}
8262023-10-13T04:44:49.788Z{"msg":"f845fd61-0eb2-446a-a3d3-f6ca309c1df1 is now active with session: 6331a993-ca35-4e3d-a1ea-7235bed756ae","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:44:44.966471229Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1200}
8272023-10-13T04:44:49.794Z{"msg":"Notify all downstairs, region set compare is done.","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:44:44.966488924Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1200}
8282023-10-13T04:44:49.799Z{"msg":"Set check for repair","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:44:44.966505851Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1200}
8292023-10-13T04:44:49.805Z{"msg":"[0] received reconcile message","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:44:44.966522897Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1200}
8302023-10-13T04:44:49.812Z{"msg":"[2] received reconcile message","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:44:44.966540123Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1200}
8312023-10-13T04:44:49.820Z{"msg":"[1] received reconcile message","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:44:44.966557224Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1200}
8322023-10-13T04:44:49.832Z{"msg":"[0] All repairs completed, exit","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:44:44.966574141Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1200}
8332023-10-13T04:44:49.845Z{"msg":"[0] Starts cmd_loop","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:44:44.96659098Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1200}
8342023-10-13T04:44:49.857Z{"msg":"[2] All repairs completed, exit","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:44:44.966608171Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1200}
8352023-10-13T04:44:49.862Z{"msg":"[2] Starts cmd_loop","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:44:44.966624684Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1200}
8362023-10-13T04:44:49.878Z{"msg":"[1] All repairs completed, exit","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:44:44.966641749Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1200}
8372023-10-13T04:44:49.891Z{"msg":"[1] Starts cmd_loop","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:44:44.96665886Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1200}
8382023-10-13T04:44:49.899Z{"msg":"Checking if live repair is needed","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:44:44.966676102Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1200}
8392023-10-13T04:44:49.907Z{"msg":"No Live Repair required at this time","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:44:44.966693521Z","hostname":"ip-10-150-1-198.us-west-2.compute.internal","pid":1200}
8402023-10-13T04:44:49.922ZRepair part 2 passed
8412023-10-13T04:44:49.941Z/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
8422023-10-13T04:44:49.952ZEXT BLOCKS GEN0 GEN1 GEN2 FL0 FL1 FL2 D0 D1 D2 DIFF
8432023-10-13T04:44:50.384Z 0 000-009 27 27 27 1615 1615 1615 F F F
8442023-10-13T04:44:50.400Z 1 010-019 27 27 27 1615 1615 1615 F F F
8452023-10-13T04:44:50.410Z 2 020-029 27 27 27 1615 1615 1615 F F F
8462023-10-13T04:44:50.428Z 3 030-039 27 27 27 1615 1615 1615 F F F
8472023-10-13T04:44:50.447Z 4 040-049 27 27 27 1615 1615 1615 F F F
8482023-10-13T04:44:50.454ZMax gen: 27, Max flush: 1615
8492023-10-13T04:44:50.462Zdump test passed
8502023-10-13T04:44:50.484Z/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
8512023-10-13T04:44:50.494Z Extent 1
8522023-10-13T04:44:50.506ZGEN 27 27 27
8532023-10-13T04:44:50.527ZFLUSH_ID 1615 1615 1615
8542023-10-13T04:44:50.541ZDIRTY
8552023-10-13T04:44:50.558Z
8562023-10-13T04:44:50.566ZBLOCK D0 D1 D2 C0 C1 C2 DIFF
8572023-10-13T04:44:50.580Z010 A A A A A A
8582023-10-13T04:44:50.589Z011 A A A A A A
8592023-10-13T04:44:51.010Z012 A A A A A A
8602023-10-13T04:44:51.042Z013 A A A A A A
8612023-10-13T04:44:51.460Z014 A A A A A A
8622023-10-13T04:44:51.488Z015 A A A A A A
8632023-10-13T04:44:52.043Z016 A A A A A A
8642023-10-13T04:44:52.048Z017 A A A A A A
8652023-10-13T04:44:52.053Z018 A A A A A A
8662023-10-13T04:44:52.058Z019 A A A A A A
8672023-10-13T04:44:52.070Zdump extent test passed
8682023-10-13T04:44:52.078Z/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
8692023-10-13T04:44:52.085ZExtent 2 Block in extent 0 Actual block 20
8702023-10-13T04:44:52.099Z
8712023-10-13T04:44:52.113Z DATA SHA256 VER
8722023-10-13T04:44:52.126Z------ ---------------------------------------------------------------- ---
8732023-10-13T04:44:52.144Z 0 7c06d6ec4d4a970d4585f526f5400d8405c63d6f6b1424682e1fab6d3a776079 A
8742023-10-13T04:44:52.156Z 1 7c06d6ec4d4a970d4585f526f5400d8405c63d6f6b1424682e1fab6d3a776079 A
8752023-10-13T04:44:52.174Z 2 7c06d6ec4d4a970d4585f526f5400d8405c63d6f6b1424682e1fab6d3a776079 A
8762023-10-13T04:44:52.183Z
8772023-10-13T04:44:52.197ZNONCES 0 1 2 DIFF
8782023-10-13T04:44:52.216Z------ ------------------------ ------------------------ ------------------------ -----
8792023-10-13T04:44:52.630Z 0 <---
8802023-10-13T04:44:52.638Z
8812023-10-13T04:44:52.644Z TAGS 0 1 2 DIFF
8822023-10-13T04:44:52.649Z------ -------------------------------- -------------------------------- -------------------------------- -----
8832023-10-13T04:44:52.653Z 0 <---
8842023-10-13T04:44:52.658Z
8852023-10-13T04:44:52.670ZHASHES 0 1 2 DIFF
8862023-10-13T04:44:52.685Z------ ---------------- ---------------- ---------------- -----
8872023-10-13T04:44:52.690Z 0 a0d586716ee487f5 a0d586716ee487f5 a0d586716ee487f5
8882023-10-13T04:44:52.695Z
8892023-10-13T04:44:52.699Zdump block test passed
8902023-10-13T04:44:52.704ZUpstairs tests have completed, stopping all downstairs
8912023-10-13T04:44:52.708Z
8922023-10-13T04:44:52.717ZAll Tests have passed
8932023-10-13T04:44:52.724Z2:02 Test duration
8942023-10-13T04:44:53.145Zprocess exited: duration 133565 ms, exit code 0
 
8952023-10-13T04:44:53.167Zfound 5 output files
8962023-10-13T04:44:53.176Zuploading: /tmp/test_up/dsc-out.txt (4471 bytes)
8972023-10-13T04:44:54.202Zuploaded: /tmp/test_up/dsc-out.txt
8982023-10-13T04:44:54.227Zuploading: /tmp/test_up/test_up_out.txt (5030556 bytes)
8992023-10-13T04:44:57.670Zuploaded: /tmp/test_up/test_up_out.txt
9002023-10-13T04:44:57.679Zuploading: /tmp/test_up/dsc/downstairs-8810.txt (69653 bytes)
9012023-10-13T04:44:59.275Zuploaded: /tmp/test_up/dsc/downstairs-8810.txt
9022023-10-13T04:44:59.279Zuploading: /tmp/test_up/dsc/downstairs-8820.txt (61796 bytes)
9032023-10-13T04:45:00.469Zuploaded: /tmp/test_up/dsc/downstairs-8820.txt
9042023-10-13T04:45:00.491Zuploading: /tmp/test_up/dsc/downstairs-8830.txt (10997 bytes)
9052023-10-13T04:45:01.972Zuploaded: /tmp/test_up/dsc/downstairs-8830.txt