01HCKKW0YDYZH1FKKBJ6Y6CWN6: test-up-encrypted

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

Buildomat Job: 01HCKKY9YG4RDAJFY32YP6MTST

Tags:

Artefacts:

Output:

SEQ GLOBAL TIME DETAILS
12023-10-13T04:38:17.740Zjob dependencies complete; ready to run (waiting for 22 m 45 s)
22023-10-13T04:39:43.356Zjob assigned to worker 01HCKN814A5T8B9STRGDBRMVAD (queued for 1 m 25 s)
32023-10-13T04:39:43.786Zdownloading input: /input/build/work/bins/crucible-downstairs.gz
42023-10-13T04:40:26.949Zdownloaded input: /input/build/work/bins/crucible-downstairs.gz
52023-10-13T04:40:26.967Zdownloading input: /input/build/work/bins/crucible-hammer.gz
62023-10-13T04:40:58.821Zdownloaded input: /input/build/work/bins/crucible-hammer.gz
72023-10-13T04:40:58.830Zdownloading input: /input/build/work/bins/crutest.gz
82023-10-13T04:41:28.361Zdownloaded input: /input/build/work/bins/crutest.gz
92023-10-13T04:41:28.369Zdownloading input: /input/build/work/bins/dsc.gz
102023-10-13T04:41:51.340Zdownloaded input: /input/build/work/bins/dsc.gz
112023-10-13T04:41:51.350Zdownloading input: /input/build/work/scripts/test_ds.sh
122023-10-13T04:41:51.374Zdownloaded input: /input/build/work/scripts/test_ds.sh
132023-10-13T04:41:51.386Zdownloading input: /input/build/work/scripts/test_live_repair.sh
142023-10-13T04:41:51.400Zdownloaded input: /input/build/work/scripts/test_live_repair.sh
152023-10-13T04:41:51.411Zdownloading input: /input/build/work/scripts/test_repair.sh
162023-10-13T04:41:51.433Zdownloaded input: /input/build/work/scripts/test_repair.sh
172023-10-13T04:41:51.447Zdownloading input: /input/build/work/scripts/test_replay.sh
182023-10-13T04:41:51.472Zdownloaded input: /input/build/work/scripts/test_replay.sh
192023-10-13T04:41:51.490Zdownloading input: /input/build/work/scripts/test_up.sh
202023-10-13T04:41:51.501Zdownloaded input: /input/build/work/scripts/test_up.sh
212023-10-13T04:41:51.518Zdownloading input: /input/build/tmp/cargo-test-out.log
222023-10-13T04:41:52.034Zdownloaded input: /input/build/tmp/cargo-test-out.log
 
232023-10-13T04:41:52.042Zstarting task 0: "setup"
242023-10-13T04:41:52.270Z++ uname -s
252023-10-13T04:41:52.280Z+ kern=SunOS
262023-10-13T04:41:52.285Z+ case "$kern" in
272023-10-13T04:41:52.292Z+ groupadd -g 12345 build
282023-10-13T04:41:52.307Z+ useradd -u 12345 -g build -d /home/build -s /bin/bash -c build -P 'Primary Administrator' build
292023-10-13T04:41:54.286Z+ zfs create -o mountpoint=/work rpool/work
302023-10-13T04:41:54.453Z++ awk '$2 == "/home" { print $3 }' /etc/mnttab
312023-10-13T04:41:54.873Z+ home_fs=zfs
322023-10-13T04:41:54.889Z+ [[ zfs == autofs ]]
332023-10-13T04:41:54.904Z+ mkdir -p /home/build
342023-10-13T04:41:54.918Z+ chown build:build /home/build /work
352023-10-13T04:41:56.461Z+ chmod 0700 /home/build /work
362023-10-13T04:41:56.470Zprocess exited: duration 4412 ms, exit code 0
 
372023-10-13T04:41:56.914Zstarting task 1: "authentication"
382023-10-13T04:41:57.364Zprocess exited: duration 35 ms, exit code 0
 
392023-10-13T04:41:57.372Zstarting task 2: "build"
402023-10-13T04:41:57.386Z+ banner cores
412023-10-13T04:41:57.522Z
422023-10-13T04:41:57.533Z #### #### ##### ###### ####
432023-10-13T04:41:57.539Z # # # # # # # #
442023-10-13T04:41:57.549Z # # # # # ##### ####
452023-10-13T04:41:57.555Z # # # ##### # #
462023-10-13T04:41:57.563Z # # # # # # # # #
472023-10-13T04:41:57.568Z #### #### # # ###### ####
482023-10-13T04:41:57.577Z
492023-10-13T04:41:57.586Z+ 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:41:57.596Z+ echo 'input bins dir contains:'
512023-10-13T04:41:57.603Zinput bins dir contains:
522023-10-13T04:41:57.612Z+ ls -ltr /input/build/work/bins
532023-10-13T04:41:57.623Ztotal 697495
542023-10-13T04:41:57.634Z-rw-r--r-- 1 root root 107725299 Oct 13 04:40 crucible-downstairs.gz
552023-10-13T04:41:57.642Z-rw-r--r-- 1 root root 85722441 Oct 13 04:40 crucible-hammer.gz
562023-10-13T04:41:57.656Z-rw-r--r-- 1 root root 95189178 Oct 13 04:41 crutest.gz
572023-10-13T04:41:58.077Z-rw-r--r-- 1 root root 68233986 Oct 13 04:41 dsc.gz
582023-10-13T04:41:58.088Z+ banner unpack
592023-10-13T04:41:58.099Z
602023-10-13T04:41:58.107Z # # # # ##### ## #### # #
612023-10-13T04:41:58.115Z # # ## # # # # # # # # #
622023-10-13T04:41:58.129Z # # # # # # # # # # ####
632023-10-13T04:41:58.554Z # # # # # ##### ###### # # #
642023-10-13T04:41:58.977Z # # # ## # # # # # # #
652023-10-13T04:41:58.990Z #### # # # # # #### # #
662023-10-13T04:41:59.003Z
672023-10-13T04:41:59.011Z+ mkdir -p /var/tmp/bins
682023-10-13T04:41:59.019Z+ for t in "$input/bins/"*.gz
692023-10-13T04:41:59.033Z++ basename /input/build/work/bins/crucible-downstairs.gz
702023-10-13T04:41:59.036Z+ b=crucible-downstairs.gz
712023-10-13T04:41:59.041Z+ b=crucible-downstairs
722023-10-13T04:41:59.044Z+ gunzip
732023-10-13T04:42:01.328Z+ chmod +x /var/tmp/bins/crucible-downstairs
742023-10-13T04:42:01.341Z+ for t in "$input/bins/"*.gz
752023-10-13T04:42:01.359Z++ basename /input/build/work/bins/crucible-hammer.gz
762023-10-13T04:42:01.376Z+ b=crucible-hammer.gz
772023-10-13T04:42:01.387Z+ b=crucible-hammer
782023-10-13T04:42:01.402Z+ gunzip
792023-10-13T04:42:04.341Z+ chmod +x /var/tmp/bins/crucible-hammer
802023-10-13T04:42:04.356Z+ for t in "$input/bins/"*.gz
812023-10-13T04:42:04.370Z++ basename /input/build/work/bins/crutest.gz
822023-10-13T04:42:04.384Z+ b=crutest.gz
832023-10-13T04:42:04.401Z+ b=crutest
842023-10-13T04:42:04.414Z+ gunzip
852023-10-13T04:42:07.509Z+ chmod +x /var/tmp/bins/crutest
862023-10-13T04:42:07.525Z+ for t in "$input/bins/"*.gz
872023-10-13T04:42:07.544Z++ basename /input/build/work/bins/dsc.gz
882023-10-13T04:42:07.563Z+ b=dsc.gz
892023-10-13T04:42:07.995Z+ b=dsc
902023-10-13T04:42:08.010Z+ gunzip
912023-10-13T04:42:09.884Z+ chmod +x /var/tmp/bins/dsc
922023-10-13T04:42:09.893Z+ export BINDIR=/var/tmp/bins
932023-10-13T04:42:09.906Z+ BINDIR=/var/tmp/bins
942023-10-13T04:42:09.915Z+ banner test_up_encrypted
952023-10-13T04:42:09.926Z
962023-10-13T04:42:09.941Z ##### ###### #### ##### # # ##### ###### # #
972023-10-13T04:42:09.950Z # # # # # # # # # ## #
982023-10-13T04:42:09.960Z # ##### #### # # # # # ##### # # #
992023-10-13T04:42:09.977Z # # # # # # ##### # # # #
1002023-10-13T04:42:09.991Z # # # # # # # # # # ##
1012023-10-13T04:42:10.005Z # ###### #### # ####### #### # ####### ###### # #
1022023-10-13T04:42:10.024Z
1032023-10-13T04:42:10.038Z+ ptime -m bash /input/build/work/scripts/test_up.sh -N encrypted
1042023-10-13T04:42:10.054Z/input/build/work
1052023-10-13T04:42:10.066ZTurn off color for downstairs dump
1062023-10-13T04:42:10.086ZUpstairs using key: gm/eQY6h0eO1gSiLzIru0vqTwbs58pEKYo6e23CctA4=
1072023-10-13T04:42:10.505Zdsc output goes to /tmp/test_up/dsc-out.txt
1082023-10-13T04:42:10.514ZCreating three downstairs regions
1092023-10-13T04:42:11.017ZStarting three downstairs
1102023-10-13T04:42:15.614ZDisable automatic restart on all downstairs
1112023-10-13T04:42:15.773Z
1122023-10-13T04:42:15.776ZBegin tests, output goes to /tmp/test_up/test_up_out.txt
1132023-10-13T04:42:15.780ZRunning test: span
1142023-10-13T04:42:19.924ZCompleted test: span
1152023-10-13T04:42:19.932ZRunning test: big
1162023-10-13T04:42:25.418ZCompleted test: big
1172023-10-13T04:42:25.917ZRunning test: dep
1182023-10-13T04:44:21.116ZCompleted test: dep
1192023-10-13T04:44:21.333ZRunning test: balloon
1202023-10-13T04:46:27.880ZCompleted test: balloon
1212023-10-13T04:46:27.888ZRunning test: deactivate
1222023-10-13T04:46:43.214ZCompleted test: deactivate
1232023-10-13T04:46:43.236ZRunning hammer
1242023-10-13T04:47:10.067ZRun repair tests
1252023-10-13T04:47:10.083Z/var/tmp/bins/crutest fill -g 26 -q --key gm/eQY6h0eO1gSiLzIru0vqTwbs58pEKYo6e23CctA4= -t 127.0.0.1:8810 -t 127.0.0.1:8820 -t 127.0.0.1:8830 --verify-out /var/tmp/test_up/verify_file
1262023-10-13T04:47:10.104Z{"msg":"Upstairs starts","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:47:09.687151197Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1191}
1272023-10-13T04:47:10.132Z{"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:47:09.687586228Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1191}
1282023-10-13T04:47:10.144Z{"msg":"Upstairs <-> Downstairs Message Version: 4","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:47:09.687641644Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1191}
1292023-10-13T04:47:10.165Z{"msg":"Upstairs opts: Upstairs UUID: 41b754e8-c80b-4fc0-9712-891f9087f615, Targets: [127.0.0.1:8810, 127.0.0.1:8820, 127.0.0.1:8830], lossy: false, flush_timeout: None, key populated: true, cert_pem populated: false, key_pem populated: false, root_cert_pem populated: false, Control: None, read_only: false","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:47:09.687695639Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1191}
1302023-10-13T04:47:10.178Z{"msg":"Crucible stats registered with UUID: 41b754e8-c80b-4fc0-9712-891f9087f615","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:47:09.687718457Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1191}
1312023-10-13T04:47:10.195Z{"msg":"Crucible 41b754e8-c80b-4fc0-9712-891f9087f615 has session id: f2ddd668-dd56-4a4a-b828-a7cb75a9b457","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:47:09.687763647Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1191}
1322023-10-13T04:47:10.212ZCrucible runtime is spawned
1332023-10-13T04:47:10.227ZThe guest has requested activation with gen:26
1342023-10-13T04:47:10.652Z{"msg":"up_listen starts","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:47:09.688109311Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1191,"task":"up_listen"}
1352023-10-13T04:47:10.673Z{"msg":"Wait for all three downstairs to come online","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:47:09.688216374Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1191}
1362023-10-13T04:47:10.699Z{"msg":"Flush timeout: 0.5","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:47:09.688353422Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1191}
1372023-10-13T04:47:10.716Z{"msg":"[0] connecting to 127.0.0.1:8810","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:47:09.688399252Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1191,"looper":"0"}
1382023-10-13T04:47:11.238Z{"msg":"[2] connecting to 127.0.0.1:8830","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:47:09.688725667Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1191,"looper":"2"}
1392023-10-13T04:47:11.274Z{"msg":"[0] 41b754e8-c80b-4fc0-9712-891f9087f615 looper connected","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:47:09.688852313Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1191,"looper":"0"}
1402023-10-13T04:47:11.299Z{"msg":"[1] connecting to 127.0.0.1:8820","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:47:09.688931346Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1191,"looper":"1"}
1412023-10-13T04:47:11.327Z{"msg":"[2] 41b754e8-c80b-4fc0-9712-891f9087f615 looper connected","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:47:09.68901339Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1191,"looper":"2"}
1422023-10-13T04:47:11.757Z{"msg":"[1] 41b754e8-c80b-4fc0-9712-891f9087f615 looper connected","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:47:09.689109265Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1191,"looper":"1"}
1432023-10-13T04:47:11.768Z{"msg":"[0] Proc runs for 127.0.0.1:8810 in state New","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:47:09.689454156Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1191}
1442023-10-13T04:47:12.199Z{"msg":"41b754e8-c80b-4fc0-9712-891f9087f615 active request set","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:47:09.689510237Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1191}
1452023-10-13T04:47:12.208Z{"msg":"Set desired generation to :26","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:47:09.689555506Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1191}
1462023-10-13T04:47:12.218Z{"msg":"[2] Proc runs for 127.0.0.1:8830 in state New","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:47:09.689788663Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1191}
1472023-10-13T04:47:12.234Z{"msg":"[1] Proc runs for 127.0.0.1:8820 in state New","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:47:09.689834724Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1191}
1482023-10-13T04:47:12.243Z{"msg":"[2] 41b754e8-c80b-4fc0-9712-891f9087f615 (64dcd0cd-eb65-48e0-ae43-bb9737155be2) New New New ds_transition to WaitActive","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:47:09.69036434Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1191}
1492023-10-13T04:47:12.253Z{"msg":"[2] Transition from New to WaitActive","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:47:09.690425721Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1191}
1502023-10-13T04:47:12.273Z{"msg":"[2] client is_active_req TRUE, promote! session 64dcd0cd-eb65-48e0-ae43-bb9737155be2","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:47:09.690452715Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1191}
1512023-10-13T04:47:12.287Z{"msg":"[1] 41b754e8-c80b-4fc0-9712-891f9087f615 (64dcd0cd-eb65-48e0-ae43-bb9737155be2) New New WaitActive ds_transition to WaitActive","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:47:09.690583307Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1191}
1522023-10-13T04:47:12.308Z{"msg":"[1] Transition from New to WaitActive","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:47:09.690646208Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1191}
1532023-10-13T04:47:12.329Z{"msg":"[0] 41b754e8-c80b-4fc0-9712-891f9087f615 (64dcd0cd-eb65-48e0-ae43-bb9737155be2) New WaitActive WaitActive ds_transition to WaitActive","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:47:09.690725635Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1191}
1542023-10-13T04:47:12.351Z{"msg":"[0] Transition from New to WaitActive","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:47:09.690829128Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1191}
1552023-10-13T04:47:12.371Z{"msg":"[1] client is_active_req TRUE, promote! session 64dcd0cd-eb65-48e0-ae43-bb9737155be2","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:47:09.690968119Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1191}
1562023-10-13T04:47:12.394Z{"msg":"[0] client is_active_req TRUE, promote! session 64dcd0cd-eb65-48e0-ae43-bb9737155be2","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:47:09.691012977Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1191}
1572023-10-13T04:47:12.435Z{"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:47:09.691332107Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1191}
1582023-10-13T04:47:12.451Z{"msg":"[2] Got region def RegionDefinition { block_size: 4096, extent_size: Block { value: 10, shift: 12 }, extent_count: 5, uuid: 12345678-0000-0000-0000-000000008830, encrypted: true, database_read_version: 1, database_write_version: 1 }","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:47:09.691463812Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1191}
1592023-10-13T04:47:12.880Z{"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:47:09.691555265Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1191}
1602023-10-13T04:47:12.893Z{"msg":"[1] Got region def RegionDefinition { block_size: 4096, extent_size: Block { value: 10, shift: 12 }, extent_count: 5, uuid: 12345678-0000-0000-0000-000000008820, encrypted: true, database_read_version: 1, database_write_version: 1 }","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:47:09.691616589Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1191}
1612023-10-13T04:47:12.905Z{"msg":"41b754e8-c80b-4fc0-9712-891f9087f615 WaitActive WaitActive WaitActive","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:47:09.691665223Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1191}
1622023-10-13T04:47:12.922Z{"msg":"41b754e8-c80b-4fc0-9712-891f9087f615 WaitActive WaitActive WaitActive","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:47:09.691686954Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1191}
1632023-10-13T04:47:12.937Z{"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:47:09.69175385Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1191}
1642023-10-13T04:47:12.970Z{"msg":"[0] Got region def RegionDefinition { block_size: 4096, extent_size: Block { value: 10, shift: 12 }, extent_count: 5, uuid: 12345678-0000-0000-0000-000000008810, encrypted: true, database_read_version: 1, database_write_version: 1 }","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:47:09.691793453Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1191}
1652023-10-13T04:47:12.988Z{"msg":"41b754e8-c80b-4fc0-9712-891f9087f615 WaitActive WaitActive WaitActive","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:47:09.691834946Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1191}
1662023-10-13T04:47:13.007Z{"msg":"[1] 41b754e8-c80b-4fc0-9712-891f9087f615 (64dcd0cd-eb65-48e0-ae43-bb9737155be2) WaitActive WaitActive WaitActive ds_transition to WaitQuorum","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:47:09.692069038Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1191}
1672023-10-13T04:47:13.093Z{"msg":"[1] Transition from WaitActive to WaitQuorum","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:47:09.692146952Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1191}
1682023-10-13T04:47:13.119Z{"msg":"[1] new RM replaced this: None","v":0,"name":"crucible","level":40,"time":"2023-10-13T04:47:09.692213195Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1191}
1692023-10-13T04:47:13.140Z{"msg":"[1] Starts reconcile loop","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:47:09.692277961Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1191}
1702023-10-13T04:47:13.161Z{"msg":"[1] 127.0.0.1:8820 task reports connection:true","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:47:09.692383204Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1191}
1712023-10-13T04:47:13.176Z{"msg":"41b754e8-c80b-4fc0-9712-891f9087f615 WaitActive WaitQuorum WaitActive","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:47:09.69246024Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1191}
1722023-10-13T04:47:13.188Z{"msg":"Waiting for 2 more clients to be ready","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:47:09.692540859Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1191}
1732023-10-13T04:47:13.203Z{"msg":"Set check for repair","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:47:09.692621725Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1191}
1742023-10-13T04:47:13.220Z{"msg":"[2] 41b754e8-c80b-4fc0-9712-891f9087f615 (64dcd0cd-eb65-48e0-ae43-bb9737155be2) WaitActive WaitQuorum WaitActive ds_transition to WaitQuorum","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:47:09.692707495Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1191}
1752023-10-13T04:47:13.238Z{"msg":"[2] Transition from WaitActive to WaitQuorum","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:47:09.692785272Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1191}
1762023-10-13T04:47:13.252Z{"msg":"[2] new RM replaced this: None","v":0,"name":"crucible","level":40,"time":"2023-10-13T04:47:09.692856704Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1191}
1772023-10-13T04:47:13.279Z{"msg":"[2] Starts reconcile loop","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:47:09.692894037Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1191}
1782023-10-13T04:47:13.298Z{"The guest has finished waiting for activation with:26
1792023-10-13T04:47:13.330Zmsg"Wait for a query_work_queue command to finish before sending IO
1802023-10-13T04:47:13.769Z:"[2] 127.0.0.1:8830 task reports connection:true","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:47:09.692972581Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1191}
1812023-10-13T04:47:13.792Z{"msg":"41b754e8-c80b-4fc0-9712-891f9087f615 WaitActive WaitQuorum WaitQuorum","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:47:09.69305364Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1191}
1822023-10-13T04:47:13.933Z{"msg":"Waiting for 1 more clients to be ready","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:47:09.693136428Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1191}
1832023-10-13T04:47:13.942Z{"msg":"Set check for repair","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:47:09.693242388Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1191}
1842023-10-13T04:47:13.955Z{"msg":"[0] 41b754e8-c80b-4fc0-9712-891f9087f615 (64dcd0cd-eb65-48e0-ae43-bb9737155be2) WaitActive WaitQuorum WaitQuorum ds_transition to WaitQuorum","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:47:09.693322854Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1191}
1852023-10-13T04:47:13.962Z{"msg":"[0] Transition from WaitActive to WaitQuorum","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:47:09.693404419Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1191}
1862023-10-13T04:47:13.971Z{"msg":"[0] new RM replaced this: None","v":0,"name":"crucible","level":40,"time":"2023-10-13T04:47:09.693458066Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1191}
1872023-10-13T04:47:13.980Z{"msg":"[0] Starts reconcile loop","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:47:09.693478544Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1191}
1882023-10-13T04:47:13.995Z{"msg":"[0] 127.0.0.1:8810 task reports connection:true","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:47:09.693522261Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1191}
1892023-10-13T04:47:14.012Z{"msg":"41b754e8-c80b-4fc0-9712-891f9087f615 WaitQuorum WaitQuorum WaitQuorum","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:47:09.693544694Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1191}
1902023-10-13T04:47:14.029Z{"msg":"[0]R flush_numbers: [1928, 1928, 1928, 1928, 1928]","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:47:09.693588272Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1191}
1912023-10-13T04:47:14.044Z{"msg":"[0]R generation: [20, 20, 20, 20, 20]","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:47:09.693607914Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1191}
1922023-10-13T04:47:14.066Z{"msg":"[0]R dirty: [false, false, false, false, false]","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:47:09.69362574Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1191}
1932023-10-13T04:47:14.080Z{"msg":"[1]R flush_numbers: [1928, 1928, 1928, 1928, 1928]","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:47:09.693643513Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1191}
1942023-10-13T04:47:14.095Z{"msg":"[1]R generation: [20, 20, 20, 20, 20]","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:47:09.693660995Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1191}
1952023-10-13T04:47:14.113Z{"msg":"[1]R dirty: [false, false, false, false, false]","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:47:09.693678586Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1191}
1962023-10-13T04:47:14.128Z{"msg":"[2]R flush_numbers: [1928, 1928, 1928, 1928, 1928]","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:47:09.693696428Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1191}
1972023-10-13T04:47:14.143Z{"msg":"[2]R generation: [20, 20, 20, 20, 20]","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:47:09.69371399Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1191}
1982023-10-13T04:47:14.158Z{"msg":"[2]R dirty: [false, false, false, false, false]","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:47:09.693732105Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1191}
1992023-10-13T04:47:14.177Z{"msg":"Max found gen is 21","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:47:09.693749112Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1191}
2002023-10-13T04:47:14.207Z{"msg":"Generation requested: 26 >= found:21","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:47:09.693766726Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1191}
2012023-10-13T04:47:14.222Z{"msg":"Next flush: 1929","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:47:09.693783659Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1191}
2022023-10-13T04:47:14.240Z{"msg":"All extents match","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:47:09.6938008Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1191}
2032023-10-13T04:47:14.261Z{"msg":"No downstairs repair required","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:47:09.693818101Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1191}
2042023-10-13T04:47:14.690Z{"msg":"No initial repair work was required","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:47:09.693838762Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1191}
2052023-10-13T04:47:14.716Z{"msg":"Set Downstairs and Upstairs active","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:47:09.693870642Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1191}
2062023-10-13T04:47:14.738Z{"msg":"41b754e8-c80b-4fc0-9712-891f9087f615 is now active with session: 64dcd0cd-eb65-48e0-ae43-bb9737155be2","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:47:09.693901623Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1191}
2072023-10-13T04:47:15.169Z{"msg":"41b754e8-c80b-4fc0-9712-891f9087f615 Set Active after no repair","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:47:09.693920979Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1191}
2082023-10-13T04:47:15.183Z{"msg":"Notify all downstairs, region set compare is done.","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:47:09.693938846Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1191}
2092023-10-13T04:47:15.205Z{"msg":"Set check for repair","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:47:09.693956211Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1191}
2102023-10-13T04:47:15.227Z{"msg":"[0] received reconcile message","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:47:09.693976899Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1191}
2112023-10-13T04:47:15.640Z{"msg":"[1] received reconcile message","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:47:09.694008477Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1191}
2122023-10-13T04:47:15.645Z{"msg":"[2] received reconcile message","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:47:09.694043695Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1191}
2132023-10-13T04:47:15.658Z{"msg":"[0] All repairs completed, exit","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:47:09.694077719Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1191}
2142023-10-13T04:47:15.668Z{"msg":"[0] Starts cmd_loop","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:47:09.694113081Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1191}
2152023-10-13T04:47:15.681Z{"msg":"[1] All repairs completed, exit","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:47:09.694147009Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1191}
2162023-10-13T04:47:15.696Z{"msg":"[1] Starts cmd_loop","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:47:09.694178997Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1191}
2172023-10-13T04:47:15.708ZRegion: es:10 ec:5 bs:4096 ts:204800 tb:50 max_io:50 or 204800
2182023-10-13T04:47:16.134Z{"msg":"[2] All repairs completed, exit","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:47:09.694285605Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal",Fill test
2192023-10-13T04:47:16.151Z"pid":1191}
2202023-10-13T04:47:16.158Z{"msg":"[2] Starts cmd_loop","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:47:09.694393885Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1191}
2212023-10-13T04:47:16.165ZRead and Verify all blocks (0..50 range:false)
2222023-10-13T04:47:16.178ZWrote out file "/var/tmp/test_up/verify_file"
2232023-10-13T04:47:16.187ZCLIENT: Tests done. All submitted work has been ACK'd
2242023-10-13T04:47:16.192Z----------------------------------------------------------------
2252023-10-13T04:47:16.204Z Crucible gen:26 GIO:true work queues: Upstairs:0 downstairs:1
2262023-10-13T04:47:16.212ZGW_ID ACK DSID TYPE BLOCKS DS:0 DS:1 DS:2 REPLAY
2272023-10-13T04:47:16.223Z 3 Acked 1002 Read 50 Done Done Done false
2282023-10-13T04:47:16.234Z STATES DS:0 DS:1 DS:2 TOTAL
2292023-10-13T04:47:16.240Z New 0 0 0 0
2302023-10-13T04:47:16.253Z Sent 0 0 0 0
2312023-10-13T04:47:16.259Z Done 1 1 1 3
2322023-10-13T04:47:16.266Z Skipped 0 0 0 0
2332023-10-13T04:47:16.275Z Error 0 0 0 0
2342023-10-13T04:47:16.279ZLast Flush: 1001 1001 1001
2352023-10-13T04:47:16.283ZDownstairs last five completed: 1001 1000
2362023-10-13T04:47:16.288ZUpstairs last five completed: 3 2 1
2372023-10-13T04:47:16.294ZCLIENT: Up:0 ds:1 act:3
2382023-10-13T04:47:16.298Z{"msg":"Checking if live repair is needed","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:47:10.69425905Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1191}
2392023-10-13T04:47:16.307Z{"msg":"No Live Repair required at this time","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:47:10.694317675Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1191}
2402023-10-13T04:47:16.315Z----------------------------------------------------------------
2412023-10-13T04:47:16.322Z Crucible gen:26 GIO:true work queues: Upstairs:0 downstairs:0
2422023-10-13T04:47:16.327ZDownstairs last five completed: 1003 1002 1001 1000
2432023-10-13T04:47:16.331ZUpstairs last five completed: 4 3 2 1
2442023-10-13T04:47:16.343ZCLIENT: Up:0 ds:0 act:3
2452023-10-13T04:47:16.352ZCLIENT: All crucible jobs finished, exiting program
2462023-10-13T04:47:16.360ZRepair setup passed
2472023-10-13T04:47:16.377ZCopy the 8830 file
2482023-10-13T04:47:16.387Zcp -r /var/tmp/test_up/8830 /var/tmp/test_up/previous
2492023-10-13T04:47:16.392Z/var/tmp/bins/crutest repair -g 27 -q --key gm/eQY6h0eO1gSiLzIru0vqTwbs58pEKYo6e23CctA4= -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
2502023-10-13T04:47:16.396Z{"msg":"Upstairs starts","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:47:14.039264513Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1197}
2512023-10-13T04:47:16.402Z{"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:47:14.039691909Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1197}
2522023-10-13T04:47:16.411Z{"msg":"Upstairs <-> Downstairs Message Version: 4","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:47:14.039746476Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1197}
2532023-10-13T04:47:16.426Z{"msg":"Upstairs opts: Upstairs UUID: 3d3a5ed4-8354-4b9c-bba4-caad90e7ea30, Targets: [127.0.0.1:8810, 127.0.0.1:8820, 127.0.0.1:8830], lossy: false, flush_timeout: None, key populated: true, cert_pem populated: false, key_pem populated: false, root_cert_pem populated: false, Control: None, read_only: false","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:47:14.039775391Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1197}
2542023-10-13T04:47:16.439Z{"msg":"Crucible stats registered with UUID: 3d3a5ed4-8354-4b9c-bba4-caad90e7ea30","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:47:14.039797008Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1197}
2552023-10-13T04:47:16.461Z{"msg":"Crucible 3d3a5ed4-8354-4b9c-bba4-caad90e7ea30 has session id: 3b1fd1b7-5290-4221-bb6c-9b21ecb5f386","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:47:14.039817689Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1197}
2562023-10-13T04:47:16.479ZCrucible runtime is spawned
2572023-10-13T04:47:16.485ZThe guest has requested activation with gen:27
2582023-10-13T04:47:16.492Z{"msg":"up_listen starts","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:47:14.040382917Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1197,"task":"up_listen"}
2592023-10-13T04:47:16.514Z{"msg":"Wait for all three downstairs to come online","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:47:14.040566659Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1197}
2602023-10-13T04:47:16.526Z{"msg":"Flush timeout: 0.5","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:47:14.040596174Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1197}
2612023-10-13T04:47:16.533Z{"msg":"[1] connecting to 127.0.0.1:8820","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:47:14.040615095Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1197,"looper":"1"}
2622023-10-13T04:47:16.551Z{"msg":"[0] connecting to 127.0.0.1:8810","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:47:14.041008001Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1197,"looper":"0"}
2632023-10-13T04:47:16.558Z{"msg":"[1] 3d3a5ed4-8354-4b9c-bba4-caad90e7ea30 looper connected","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:47:14.041062636Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1197,"looper":"1"}
2642023-10-13T04:47:16.568Z{"msg":"[2] connecting to 127.0.0.1:8830","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:47:14.041104137Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1197,"looper":"2"}
2652023-10-13T04:47:16.993Z{"msg":"[0] 3d3a5ed4-8354-4b9c-bba4-caad90e7ea30 looper connected","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:47:14.041239038Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1197,"looper":"0"}
2662023-10-13T04:47:17.004Z{"msg":"[2] 3d3a5ed4-8354-4b9c-bba4-caad90e7ea30 looper connected","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:47:14.041289578Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1197,"looper":"2"}
2672023-10-13T04:47:17.013Z{"msg":"3d3a5ed4-8354-4b9c-bba4-caad90e7ea30 active request set","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:47:14.041545113Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1197}
2682023-10-13T04:47:17.020Z{"msg":"Set desired generation to :27","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:47:14.041570872Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1197}
2692023-10-13T04:47:17.026ZError: Difference in extent metadata found!
2702023-10-13T04:47:17.038Z{"msg":"[1] Proc runs for 127.0.0.1:8820 in state New","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:47:14.04175162Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1197}
2712023-10-13T04:47:17.050Z{"msg":"[0] Proc runs for 127.0.0.1:8810 in state New","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:47:14.042054026Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1197}
2722023-10-13T04:47:17.060Z{"msg":"[2] Proc runs for 127.0.0.1:8830 in state New","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:47:14.042243539Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1197}
2732023-10-13T04:47:17.074Z{"msg":"[1] 3d3a5ed4-8354-4b9c-bba4-caad90e7ea30 (7e38724d-94c0-44b1-a3c4-02f34be4ed18) New New New ds_transition to WaitActive","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:47:14.042456135Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1197}
2742023-10-13T04:47:17.085Z{"msg":"[1] Transition from New to WaitActive","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:47:14.042503784Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1197}
2752023-10-13T04:47:17.099Z{"msg":"[1] client is_active_req TRUE, promote! session 7e38724d-94c0-44b1-a3c4-02f34be4ed18","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:47:14.042543097Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1197}
2762023-10-13T04:47:17.119Z{"msg":"[0] 3d3a5ed4-8354-4b9c-bba4-caad90e7ea30 (7e38724d-94c0-44b1-a3c4-02f34be4ed18) New WaitActive New ds_transition to WaitActive","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:47:14.042717744Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1197}
2772023-10-13T04:47:17.131Z{"msg":"[0] Transition from New to WaitActive","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:47:14.042758244Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1197}
2782023-10-13T04:47:17.141Z{"msg":"[0] client is_active_req TRUE, promote! session 7e38724d-94c0-44b1-a3c4-02f34be4ed18","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:47:14.042779211Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1197}
2792023-10-13T04:47:17.156Z{"msg":"[2] 3d3a5ed4-8354-4b9c-bba4-caad90e7ea30 (7e38724d-94c0-44b1-a3c4-02f34be4ed18) WaitActive WaitActive New ds_transition to WaitActive","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:47:14.042799589Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1197}
2802023-10-13T04:47:17.167Z{"msg":"[2] Transition from New to WaitActive","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:47:14.042817381Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1197}
2812023-10-13T04:47:17.187Z{"msg":"[2] client is_active_req TRUE, promote! session 7e38724d-94c0-44b1-a3c4-02f34be4ed18","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:47:14.042907267Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1197}
2822023-10-13T04:47:17.202Z{"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:47:14.043308487Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1197}
2832023-10-13T04:47:17.211Z{"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:47:14.043340546Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1197}
2842023-10-13T04:47:17.228Z{"msg":"[0] Got region def RegionDefinition { block_size: 4096, extent_size: Block { value: 10, shift: 12 }, extent_count: 5, uuid: 12345678-0000-0000-0000-000000008810, encrypted: true, database_read_version: 1, database_write_version: 1 }","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:47:14.043364173Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1197}
2852023-10-13T04:47:17.648Z{"msg":"[1] Got region def RegionDefinition { block_size: 4096, extent_size: Block { value: 10, shift: 12 }, extent_count: 5, uuid: 12345678-0000-0000-0000-000000008820, encrypted: true, database_read_version: 1, database_write_version: 1 }","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:47:14.043386607Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1197}
2862023-10-13T04:47:17.653Z{"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:47:14.04340542Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1197}
2872023-10-13T04:47:17.658Z{"msg":"[2] Got region def RegionDefinition { block_size: 4096, extent_size: Block { value: 10, shift: 12 }, extent_count: 5, uuid: 12345678-0000-0000-0000-000000008830, encrypted: true, database_read_version: 1, database_write_version: 1 }","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:47:14.043428293Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1197}
2882023-10-13T04:47:17.668Z{"msg":"3d3a5ed4-8354-4b9c-bba4-caad90e7ea30 WaitActive WaitActive WaitActive","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:47:14.043598461Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1197}
2892023-10-13T04:47:17.674Z{"msg":"3d3a5ed4-8354-4b9c-bba4-caad90e7ea30 WaitActive WaitActive WaitActive","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:47:14.043646684Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1197}
2902023-10-13T04:47:17.682Z{"msg":"3d3a5ed4-8354-4b9c-bba4-caad90e7ea30 WaitActive WaitActive WaitActive","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:47:14.043686495Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1197}
2912023-10-13T04:47:17.692Z{"msg":"[0] 3d3a5ed4-8354-4b9c-bba4-caad90e7ea30 (7e38724d-94c0-44b1-a3c4-02f34be4ed18) WaitActive WaitActive WaitActive ds_transition to WaitQuorum","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:47:14.043940412Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1197}
2922023-10-13T04:47:17.700Z{"msg":"[0] Transition from WaitActive to WaitQuorum","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:47:14.043993024Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1197}
2932023-10-13T04:47:17.718Z{"msg":"[0] new RM replaced this: None","v":0,"name":"crucible","level":40,"time":"2023-10-13T04:47:14.04403087Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1197}
2942023-10-13T04:47:17.728Z{"msg":"[0] Starts reconcile loop","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:47:14.044066371Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1197}
2952023-10-13T04:47:17.734Z{"msg":"[0] 127.0.0.1:8810 task reports connection:true","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:47:14.044099807Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1197}
2962023-10-13T04:47:17.738Z{"msg":"3d3a5ed4-8354-4b9c-bba4-caad90e7ea30 WaitQuorum WaitActive WaitActive","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:47:14.044121386Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1197}
2972023-10-13T04:47:17.743Z{"msg":"Waiting for 2 more clients to be ready","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:47:14.044139149Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1197}
2982023-10-13T04:47:17.749Z{"msg":"Set check for repair","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:47:14.044156092Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1197}
2992023-10-13T04:47:17.754Z{"msg":"[2] 3d3a5ed4-8354-4b9c-bba4-caad90e7ea30 (7e38724d-94c0-44b1-a3c4-02f34be4ed18) WaitQuorum WaitActive WaitActive ds_transition to WaitQuorum","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:47:14.044307557Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1197}
3002023-10-13T04:47:17.763Z{"msg":"[2] Transition from WaitActive to WaitQuorum","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:47:14.044332788Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1197}
3012023-10-13T04:47:18.178Z{"msg":"[2] new RM replaced this: None","v":0,"name":"crucible","level":40,"time":"2023-10-13T04:47:14.044350521Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1197}
3022023-10-13T04:47:18.183Z{"msg":"[2] Starts reconcile loop","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:47:14.044367706Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1197}
3032023-10-13T04:47:18.193Z{"msg":"[2] 127.0.0.1:8830 task reports connection:true","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:47:14.044385477Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1197}
3042023-10-13T04:47:18.201Z{"msg":"3d3a5ed4-8354-4b9c-bba4-caad90e7ea30 WaitQuorum WaitActive WaitQuorum","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:47:14.044403558Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1197}
3052023-10-13T04:47:18.210Z{"msg":"[1] 3d3a5ed4-8354-4b9c-bba4-caad90e7ea30 (7e38724d-94c0-44b1-a3c4-02f34be4ed18) WaitQuorum WaitActive WaitQuorum ds_transition to WaitQuorum","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:47:14.044423904Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1197}
3062023-10-13T04:47:18.218Z{"msg":"[1] Transition from WaitActive to WaitQuorum","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:47:14.044441302Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1197}
3072023-10-13T04:47:18.230Z{"msg":"[1] new RM replaced this: None","v":0,"name":"crucible","level":40,"time":"2023-10-13T04:47:14.044458302Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1197}
3082023-10-13T04:47:18.236Z{"msg":"[0]R flush_numbers: [1929, 1929, 1929, 1929, 1929]","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:47:14.044484038Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1197}
3092023-10-13T04:47:18.254Z{"msg":"[0]R generation: [26, 26, 26, 26, 26]","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:47:14.044502083Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1197}
3102023-10-13T04:47:18.264Z{"msg":"[0]R dirty: [false, false, false, false, false]","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:47:14.04451992Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1197}
3112023-10-13T04:47:18.272Z{"msg":"[1]R flush_numbers: [1929, 1929, 1929, 1929, 1929]","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:47:14.044538021Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1197}
3122023-10-13T04:47:18.287Z{"msg":"[1]R generation: [26, 26, 26, 26, 26]","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:47:14.044556229Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1197}
3132023-10-13T04:47:18.301Z{"msg":"[1]R dirty: [false, false, false, false, false]","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:47:14.044574082Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1197}
3142023-10-13T04:47:18.721Z{"msg":"[2]R flush_numbers: [1929, 1929, 1929, 1929, 1929]","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:47:14.044591863Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1197}
3152023-10-13T04:47:18.755Z{"msg":"[2]R generation: [26, 26, 26, 26, 26]","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:47:14.044609001Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1197}
3162023-10-13T04:47:18.768Z{"msg":"[2]R dirty: [false, false, false, false, false]","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:47:14.044626355Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1197}
3172023-10-13T04:47:18.774Z{"msg":"Max found gen is 27","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:47:14.044642985Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1197}
3182023-10-13T04:47:18.781Z{"msg":"Generation requested: 27 >= found:27","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:47:14.044660037Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1197}
3192023-10-13T04:47:18.788Z{"msg":"Next flush: 1930","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:47:14.044676802Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1197}
3202023-10-13T04:47:18.796Z{"msg":"All extents match","v":0,"name":"crucible","level":30The guest has finished waiting for activation with:27
3212023-10-13T04:47:18.803Z,"time":"Wait for a query_work_queue command to finish before sending IO
3222023-10-13T04:47:18.810Z2023-10-13T04:47:14.044693645Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1197}
3232023-10-13T04:47:18.821Z{"msg":"No downstairs repair required","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:47:14.044715637Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1197}
3242023-10-13T04:47:18.833Z{"msg":"[1] Starts reconcile loop","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:47:14.044732742Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1197}
3252023-10-13T04:47:18.842Z{"msg":"No initial repair work was required","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:47:14.044750052Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1197}
3262023-10-13T04:47:18.854Z{"msg":"Set Downstairs and Upstairs active","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:47:14.044767166Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1197}
3272023-10-13T04:47:19.272Z{"msg":"3d3a5ed4-8354-4b9c-bba4-caad90e7ea30 is now active with session: 7e38724d-94c0-44b1-a3c4-02f34be4ed18","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:47:14.044786107Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1197}
3282023-10-13T04:47:19.281Z{"msg":"3d3a5ed4-8354-4b9c-bba4-caad90e7ea30 Set Active after no repair","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:47:14.044804192Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1197}
3292023-10-13T04:47:19.287Z{"msg":"Notify all downstairs, region set compare is done.","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:47:14.044822393Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1197}
3302023-10-13T04:47:19.292Z{"msg":"Set check for repair","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:47:14.044846547Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1197}
3312023-10-13T04:47:19.297Z{"msg":"[1] 127.0.0.1:8820 task reports connection:true","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:47:14.04486539Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1197}
3322023-10-13T04:47:19.301Z{"msg":"3d3a5ed4-8354-4b9c-bba4-caad90e7ea30 Active Active Active","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:47:14.044883405Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1197}
3332023-10-13T04:47:19.305Z{"msg":"Set check for repair","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:47:14.044900176Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1197}
3342023-10-13T04:47:19.318Z{"msg":"[1] received reconcile message","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:47:14.044917456Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1197}
3352023-10-13T04:47:19.324Z{"msg":"[1] All repairs completed, exit","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:47:14.044934565Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1197}
3362023-10-13T04:47:19.332Z{"msg":"[1] Starts cmd_loop","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:47:14.044951362Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1197}
3372023-10-13T04:47:19.339Z{"msg":"[2] received reconcile message","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:47:14.044968523Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1197}
3382023-10-13T04:47:19.346Z{"msg":"[2] All repairs completed, exit","v":0,"name":"crucible","level":30Region: es:10 ec:5 bs:4096 ts:204800 tb:50 max_io:50 or 204800
3392023-10-13T04:47:19.355Z,"time":"2023-10-13T04:47:14.049200973Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1197}
3402023-10-13T04:47:19.364Z{"msg":"[2] Starts cmd_loop","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:47:14.049234889Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1197}
3412023-10-13T04:47:19.376Z{"msg":"[0] received reconcile message","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:47:14.049252812Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1197}
3422023-10-13T04:47:19.390Z{"msg":"[0] All repairs completed, exit","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:47:14.049269601Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1197}
3432023-10-13T04:47:19.400Z{"msg":"[0] Starts cmd_loop","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:47:14.049286271Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1197}
3442023-10-13T04:47:19.413ZLoading write count information from file "/var/tmp/test_up/verify_file"
3452023-10-13T04:47:19.419ZRun Repair workload
3462023-10-13T04:47:19.426Z01/10 Write block 20 len 8192 data: 2 2
3472023-10-13T04:47:19.429Z02/10 Write block 34 len 28672 data: 2 2 2 2 2 2 2
3482023-10-13T04:47:19.433Z03/10 Write block 9 len 16384 data: 2 2 2 2
3492023-10-13T04:47:19.438Z04/10 Flush
3502023-10-13T04:47:19.442Z05/10 Write block 31 len 40960 data: 2 2 2 3 3 3 3 3 3 3
3512023-10-13T04:47:19.447Z06/10 Read block 41 len 32768
3522023-10-13T04:47:19.458Z07/10 Read block 26 len 40960
3532023-10-13T04:47:19.464Z08/10 Write block 37 len 4096 data: 4
3542023-10-13T04:47:19.470Z09/10 Read block 29 len 20480
3552023-10-13T04:47:19.473Z10/10 Write block 0 len 32768 data: 2 2 2 2 2 2 2 2
3562023-10-13T04:47:19.477Z----------------------------------------------------------------
3572023-10-13T04:47:19.481Z Crucible gen:27 GIO:true work queues: Upstairs:0 downstairs:6
3582023-10-13T04:47:19.485ZGW_ID ACK DSID TYPE BLOCKS DS:0 DS:1 DS:2 REPLAY
3592023-10-13T04:47:19.489Z 5 Acked 1004 Write 10 Done Done Done false
3602023-10-13T04:47:19.494Z 6 Acked 1005 Read 8 Done Done Done false
3612023-10-13T04:47:19.498Z 7 Acked 1006 Read 10 Done Done Done false
3622023-10-13T04:47:19.502Z 8 Acked 1007 Write 1 Done Done Done false
3632023-10-13T04:47:19.506Z 9 Acked 1008 Read 5 Done Done Done false
3642023-10-13T04:47:19.510Z 10 Acked 1009 Write 8 Sent Sent Sent false
3652023-10-13T04:47:19.514Z STATES DS:0 DS:1 DS:2 TOTAL
3662023-10-13T04:47:19.518Z New 0 0 0 0
3672023-10-13T04:47:19.527Z Sent 1 1 1 3
3682023-10-13T04:47:19.545Z Done 5 5 5 15
3692023-10-13T04:47:19.549Z Skipped 0 0 0 0
3702023-10-13T04:47:19.553Z Error 0 0 0 0
3712023-10-13T04:47:19.558ZLast Flush: 1003 1003 1003
3722023-10-13T04:47:19.565ZDownstairs last five completed: 1003 1002 1001 1000
3732023-10-13T04:47:19.574ZUpstairs last five completed: 10 9 8 7 6 5
3742023-10-13T04:47:19.584ZWrote out file "/var/tmp/test_up/verify_file"
3752023-10-13T04:47:19.598ZRepair part 1 passed
3762023-10-13T04:47:20.032Z
3772023-10-13T04:47:20.448ZKill the current downstairs
3782023-10-13T04:47:20.457Zrm -rf /var/tmp/test_up/8830
3792023-10-13T04:47:20.475ZNow put back the original so we have a mismatch
3802023-10-13T04:47:20.899Zmv /var/tmp/test_up/previous /var/tmp/test_up/8830
3812023-10-13T04:47:20.914ZRestart downstairs with old directory
3822023-10-13T04:47:20.930Z/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:47:20.942ZEXT BLOCKS GEN0 GEN1 GEN2 FL0 FL1 FL2 D0 D1 D2 DIFF
3842023-10-13T04:47:21.350Z 0 000-009 27 27 26 1930 1930 1929 T T F <---
3852023-10-13T04:47:21.355Z 1 010-019 27 27 26 1930 1930 1929 F F F <---
3862023-10-13T04:47:21.363Z 2 020-029 27 27 26 1930 1930 1929 F F F <---
3872023-10-13T04:47:21.377Z 3 030-039 27 27 26 1930 1930 1929 T T F <---
3882023-10-13T04:47:21.385Z 4 040-049 27 27 26 1930 1930 1929 T T F <---
3892023-10-13T04:47:21.389ZMax gen: 27, Max flush: 1930
3902023-10-13T04:47:21.392Zdump test found error as expected
3912023-10-13T04:47:21.395Z
3922023-10-13T04:47:21.398Z
3932023-10-13T04:47:21.402Z/var/tmp/bins/crutest deactivate --range -g 28 -q --key gm/eQY6h0eO1gSiLzIru0vqTwbs58pEKYo6e23CctA4= -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:47:21.406Z{"msg":"Upstairs starts","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:47:14.609987223Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1204}
3952023-10-13T04:47:21.411Z{"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:47:14.610396188Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1204}
3962023-10-13T04:47:21.420Z{"msg":"Upstairs <-> Downstairs Message Version: 4","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:47:14.610422606Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1204}
3972023-10-13T04:47:21.432Z{"msg":"Upstairs opts: Upstairs UUID: f58152dd-3142-45dc-8d0d-61caea3d878b, Targets: [127.0.0.1:8810, 127.0.0.1:8820, 127.0.0.1:8830], lossy: false, flush_timeout: None, key populated: true, cert_pem populated: false, key_pem populated: false, root_cert_pem populated: false, Control: None, read_only: false","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:47:14.610448435Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1204}
3982023-10-13T04:47:21.452Z{"msg":"Crucible stats registered with UUID: f58152dd-3142-45dc-8d0d-61caea3d878b","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:47:14.610468149Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1204}
3992023-10-13T04:47:21.467Z{"msg":"Crucible f58152dd-3142-45dc-8d0d-61caea3d878b has session id: 49e22de8-80c3-4265-bcd8-662e963518b5","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:47:14.610488241Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1204}
4002023-10-13T04:47:21.483ZCrucible runtime is spawned
4012023-10-13T04:47:21.495ZThe guest has requested activation with gen:28
4022023-10-13T04:47:21.506Z{"msg":"up_listen starts","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:47:14.611058186Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1204,"task":"up_listen"}
4032023-10-13T04:47:21.924Z{"msg":"Wait for all three downstairs to come online","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:47:14.611093025Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1204}
4042023-10-13T04:47:21.932Z{"msg":"Flush timeout: 0.5","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:47:14.61111202Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1204}
4052023-10-13T04:47:21.945Z{"msg":"[1] connecting to 127.0.0.1:8820","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:47:14.61113005Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1204,"looper":"1"}
4062023-10-13T04:47:21.964Z{"msg":"[0] connecting to 127.0.0.1:8810","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:47:14.611458598Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1204,"looper":"0"}
4072023-10-13T04:47:21.974Z{"msg":"[1] f58152dd-3142-45dc-8d0d-61caea3d878b looper connected","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:47:14.611507227Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1204,"looper":"1"}
4082023-10-13T04:47:21.981Z{"msg":"[2] connecting to 127.0.0.1:8830","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:47:14.611543588Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1204,"looper":"2"}
4092023-10-13T04:47:21.991Z{"msg":"[0] f58152dd-3142-45dc-8d0d-61caea3d878b looper connected","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:47:14.611581268Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1204,"looper":"0"}
4102023-10-13T04:47:22.000Z{"msg":"f58152dd-3142-45dc-8d0d-61caea3d878b active request set","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:47:14.612056158Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1204}
4112023-10-13T04:47:22.023Z{"msg":"Set desired generation to :28","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:47:14.61208236Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1204}
4122023-10-13T04:47:22.031Z{"msg":"[1] Proc runs for 127.0.0.1:8820 in state New","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:47:14.612178166Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1204}
4132023-10-13T04:47:22.043Z{"msg":"[0] Proc runs for 127.0.0.1:8810 in state New","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:47:14.612491507Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1204}
4142023-10-13T04:47:22.052Z{"msg":"[1] f58152dd-3142-45dc-8d0d-61caea3d878b (742a6a92-7e50-4ceb-9065-7a5b381dcb08) New New New ds_transition to WaitActive","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:47:14.6128469Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1204}
4152023-10-13T04:47:22.116Z{"msg":"[1] Transition from New to WaitActive","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:47:14.612928899Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1204}
4162023-10-13T04:47:22.130Z{"msg":"[1] client is_active_req TRUE, promote! session 742a6a92-7e50-4ceb-9065-7a5b381dcb08","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:47:16.242877327Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1204}
4172023-10-13T04:47:22.144Z{"msg":"[0] f58152dd-3142-45dc-8d0d-61caea3d878b (742a6a92-7e50-4ceb-9065-7a5b381dcb08) New WaitActive New ds_transition to WaitActive","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:47:16.242940935Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1204}
4182023-10-13T04:47:22.156Z{"msg":"[0] Transition from New to WaitActive","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:47:16.242961234Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1204}
4192023-10-13T04:47:22.168Z{"msg":"[0] client is_active_req TRUE, promote! session 742a6a92-7e50-4ceb-9065-7a5b381dcb08","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:47:16.242980579Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1204}
4202023-10-13T04:47:22.178Z{"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:47:16.242999526Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1204}
4212023-10-13T04:47:22.187Z{"msg":"[1] Got region def RegionDefinition { block_size: 4096, extent_size: Block { value: 10, shift: 12 }, extent_count: 5, uuid: 12345678-0000-0000-0000-000000008820, encrypted: true, database_read_version: 1, database_write_version: 1 }","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:47:16.243022116Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1204}
4222023-10-13T04:47:22.196Z{"msg":"f58152dd-3142-45dc-8d0d-61caea3d878b WaitActive WaitActive New","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:47:16.243041122Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1204}
4232023-10-13T04:47:22.210Z{"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:47:16.24305966Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1204}
4242023-10-13T04:47:22.228Z{"msg":"[0] Got region def RegionDefinition { block_size: 4096, extent_size: Block { value: 10, shift: 12 }, extent_count: 5, uuid: 12345678-0000-0000-0000-000000008810, encrypted: true, database_read_version: 1, database_write_version: 1 }","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:47:16.243082727Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1204}
4252023-10-13T04:47:22.243Z{"msg":"f58152dd-3142-45dc-8d0d-61caea3d878b WaitActive WaitActive New","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:47:16.243101114Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1204}
4262023-10-13T04:47:22.257Z{"msg":"[1] f58152dd-3142-45dc-8d0d-61caea3d878b (742a6a92-7e50-4ceb-9065-7a5b381dcb08) WaitActive WaitActive New ds_transition to WaitQuorum","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:47:16.243120781Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1204}
4272023-10-13T04:47:22.266Z{"msg":"[1] Transition from WaitActive to WaitQuorum","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:47:16.243138652Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1204}
4282023-10-13T04:47:22.277Z{"msg":"[1] new RM replaced this: None","v":0,"name":"crucible","level":40,"time":"2023-10-13T04:47:16.243155598Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1204}
4292023-10-13T04:47:22.290Z{"msg":"[1] Starts reconcile loop","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:47:16.243172333Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1204}
4302023-10-13T04:47:22.298Z{"msg":"[1] 127.0.0.1:8820 task reports connection:true","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:47:16.243189674Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1204}
4312023-10-13T04:47:22.310Z{"msg":"f58152dd-3142-45dc-8d0d-61caea3d878b WaitActive WaitQuorum New","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:47:16.243207307Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1204}
4322023-10-13T04:47:22.322Z{"msg":"Waiting for 2 more clients to be ready","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:47:16.243224614Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1204}
4332023-10-13T04:47:22.338Z{"msg":"Set check for repair","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:47:16.243241207Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1204}
4342023-10-13T04:47:22.345Z{"msg":"[0] f58152dd-3142-45dc-8d0d-61caea3d878b (742a6a92-7e50-4ceb-9065-7a5b381dcb08) WaitActive WaitQuorum New ds_transition to WaitQuorum","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:47:16.243260957Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1204}
4352023-10-13T04:47:22.358Z{"msg":"[0] Transition from WaitActive to WaitQuorum","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:47:16.243278601Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1204}
4362023-10-13T04:47:22.374Z{"msg":"[0] new RM replaced this: None","v":0,"name":"crucible","level":40,"time":"2023-10-13T04:47:16.243295563Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1204}
4372023-10-13T04:47:22.392Z{"msg":"[0] Starts reconcile loop","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:47:16.243312346Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1204}
4382023-10-13T04:47:22.403Z{"msg":"[0] 127.0.0.1:8810 task reports connection:true","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:47:16.243329783Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1204}
4392023-10-13T04:47:22.414Z{"msg":"f58152dd-3142-45dc-8d0d-61caea3d878b WaitQuorum WaitQuorum New","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:47:16.243347403Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1204}
4402023-10-13T04:47:22.418Z{"msg":"Waiting for 1 more clients to be ready","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:47:16.243365348Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1204}
4412023-10-13T04:47:22.423Z{"msg":"Set check for repair","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:47:16.243381917Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1204}
4422023-10-13T04:47:22.434Z{"msg":"Checking if live repair is needed","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:47:16.243399052Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1204}
4432023-10-13T04:47:22.440Z{"msg":"[2] f58152dd-3142-45dc-8d0d-61caea3d878b looper connected","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:47:16.614036326Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1204,"looper":"2"}
4442023-10-13T04:47:22.446Z{"msg":"[2] Proc runs for 127.0.0.1:8830 in state New","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:47:16.614098107Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1204}
4452023-10-13T04:47:22.456Z{"msg":"[2] f58152dd-3142-45dc-8d0d-61caea3d878b (742a6a92-7e50-4ceb-9065-7a5b381dcb08) WaitQuorum WaitQuorum New ds_transition to WaitActive","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:47:16.615035024Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1204}
4462023-10-13T04:47:22.468Z{"msg":"[2] Transition from New to WaitActive","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:47:16.615066864Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1204}
4472023-10-13T04:47:22.478Z{"msg":"[2] client is_active_req TRUE, promote! session 742a6a92-7e50-4ceb-9065-7a5b381dcb08","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:47:16.615100961Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1204}
4482023-10-13T04:47:22.488Z{"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:47:16.615825427Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1204}
4492023-10-13T04:47:22.501Z{"msg":"[2] Got region def RegionDefinition { block_size: 4096, extent_size: Block { value: 10, shift: 12 }, extent_count: 5, uuid: 12345678-0000-0000-0000-000000008830, encrypted: true, database_read_version: 1, database_write_version: 1 }","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:47:16.61586885Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1204}
4502023-10-13T04:47:22.513Z{"msg":"f58152dd-3142-45dc-8d0d-61caea3d878b WaitQuorum WaitQuorum WaitActive","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:47:16.615963682Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1204}
4512023-10-13T04:47:22.524Z{"msg":"[2] f58152dd-3142-45dc-8d0d-61caea3d878b (742a6a92-7e50-4ceb-9065-7a5b381dcb08) WaitQuorum WaitQuorum WaitActive ds_transition to WaitQuorum","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:47:17.057141882Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1204}
4522023-10-13T04:47:22.540Z{"msg":"[2] Transition from WaitActive to WaitQuorum","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:47:17.057227028Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1204}
4532023-10-13T04:47:22.548Z{"msg":"[2] new RM replaced this: None","v":0,"name":"crucible","level":40,"time":"2023-10-13T04:47:17.05727782Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1204}
4542023-10-13T04:47:22.558Z{"msg":"[2] Starts reconcile loop","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:47:17.057326322Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1204}
4552023-10-13T04:47:22.580Z{"msg":"[2] 127.0.0.1:8830 task reports connection:true","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:47:17.057374933Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1204}
4562023-10-13T04:47:22.595Z{"msg":"f58152dd-3142-45dc-8d0d-61caea3d878b WaitQuorum WaitQuorum WaitQuorum","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:47:17.057422415Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1204}
4572023-10-13T04:47:23.008Z{"msg":"[0]R flush_numbers: [1930, 1930, 1930, 1930, 1930]","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:47:17.057470906Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1204}
4582023-10-13T04:47:23.012Z{"msg":"[0]R generation: [27, 27, 27, 27, 27]","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:47:17.057517124Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1204}
4592023-10-13T04:47:23.017Z{"msg":"[0]R dirty: [true, false, false, true, true]","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:47:17.057538116Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1204}
4602023-10-13T04:47:23.024Z{"msg":"[1]R flush_numbers: [1930, 1930, 1930, 1930, 1930]","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:47:17.057556058Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1204}
4612023-10-13T04:47:23.045Z{"msg":"[1]R generation: [27, 27, 27, 27, 27]","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:47:17.05757386Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1204}
4622023-10-13T04:47:23.068Z{"msg":"[1]R dirty: [true, false, false, true, true]","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:47:17.057591637Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1204}
4632023-10-13T04:47:23.075Z{"msg":"[2]R flush_numbers: [1929, 1929, 1929, 1929, 1929]","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:47:17.057609316Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1204}
4642023-10-13T04:47:23.086Z{"msg":"[2]R generation: [26, 26, 26, 26, 26]","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:47:17.057627057Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1204}
4652023-10-13T04:47:23.154Z{"msg":"[2]R dirty: [false, false, false, false, false]","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:47:17.057644646Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1204}
4662023-10-13T04:47:23.165Z{"msg":"Max found gen is 28","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:47:17.057662005Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1204}
4672023-10-13T04:47:23.175Z{"msg":"Generation requested: 28 >= found:28","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:47:17.057679419Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1204}
4682023-10-13T04:47:23.182Z{"msg":"Next flush: 1931","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:47:17.057696202Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1204}
4692023-10-13T04:47:23.189Z{"msg":"Extents 0 dirty","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:47:17.057713009Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1204,"":"mend"}
4702023-10-13T04:47:23.199Z{"msg":"First source client ID for extent 0","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:47:17.057732302Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1204,"mrl":"dirty","":"mend"}
4712023-10-13T04:47:23.208Z{"msg":"extent:0 gens: 27 27 26","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:47:17.057751806Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1204,"mrl":"dirty","":"mend"}
4722023-10-13T04:47:23.219Z{"msg":"extent:0 flush: 1930 1930 1929 scs: [ClientId(0), ClientId(1)]","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:47:17.057772913Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1204,"mrl":"dirty","":"mend"}
4732023-10-13T04:47:23.228Z{"msg":"max_flush now has: [ClientId(0), ClientId(1)]","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:47:17.057792581Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1204,"mrl":"dirty","":"mend"}
4742023-10-13T04:47:23.236Z{"msg":"extent:0 dirty: true true false","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:47:17.057811641Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1204,"mrl":"dirty","":"mend"}
4752023-10-13T04:47:23.247Z{"msg":"find dest for source 0 for extent at index 0","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:47:17.057849563Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1204,"mrl":"dirty","":"mend"}
4762023-10-13T04:47:23.260Z{"msg":"source 0, add dest 1 source flush","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:47:17.057870849Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1204,"mrl":"dirty","":"mend"}
4772023-10-13T04:47:23.271Z{"msg":"source 0, add dest 2 gen","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:47:17.057890165Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1204,"mrl":"dirty","":"mend"}
4782023-10-13T04:47:23.282Z{"msg":"Extents 3 dirty","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:47:17.057910064Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1204,"":"mend"}
4792023-10-13T04:47:23.296Z{"msg":"First source client ID for extent 3","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:47:17.057928349Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1204,"mrl":"dirty","":"mend"}
4802023-10-13T04:47:23.305Z{"msg":"extent:3 gens: 27 27 26","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:47:17.057948049Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1204,"mrl":"dirty","":"mend"}
4812023-10-13T04:47:23.314Z{"msg":"extent:3 flush: 1930 1930 1929 scs: [ClientId(0), ClientId(1)]","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:47:17.057975628Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1204,"mrl":"dirty","":"mend"}
4822023-10-13T04:47:23.728Z{"msg":"max_flush now has: [ClientId(0), ClientId(1)]","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:47:17.057996184Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1204,"mrl":"dirty","":"mend"}
4832023-10-13T04:47:23.736Z{"msg":"extent:3 dirty: true true false","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:47:17.058015132Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1204,"mrl":"dirty","":"mend"}
4842023-10-13T04:47:23.751Z{"msg":"find dest for source 0 for extent at index 3","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:47:17.05803443Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1204,"mrl":"dirty","":"mend"}
4852023-10-13T04:47:23.779Z{"msg":"source 0, add dest 1 source flush","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:47:17.058053762Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1204,"mrl":"dirty","":"mend"}
4862023-10-13T04:47:23.787Z{"msg":"source 0, add dest 2 gen","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:47:17.05807269Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1204,"mrl":"dirty","":"mend"}
4872023-10-13T04:47:23.790Z{"msg":"Extents 4 dirty","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:47:17.058091697Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1204,"":"mend"}
4882023-10-13T04:47:23.794Z{"msg":"First source client ID for extent 4","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:47:17.05810986Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1204,"mrl":"dirty","":"mend"}
4892023-10-13T04:47:23.798Z{"msg":"extent:4 gens: 27 27 26","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:47:17.058128818Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1204,"mrl":"dirty","":"mend"}
4902023-10-13T04:47:23.801Z{"msg":"extent:4 flush: 1930 1930 1929 scs: [ClientId(0), ClientId(1)]","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:47:17.058148581Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1204,"mrl":"dirty","":"mend"}
4912023-10-13T04:47:23.803Z{"msg":"max_flush now has: [ClientId(0), ClientId(1)]","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:47:19.452273057Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1204,"mrl":"dirty","":"mend"}
4922023-10-13T04:47:23.807Z{"msg":"extent:4 dirty: true true false","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:47:19.452358424Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1204,"mrl":"dirty","":"mend"}
4932023-10-13T04:47:23.810Z{"msg":"find dest for source 0 for extent at index 4","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:47:19.452412192Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1204,"mrl":"dirty","":"mend"}
4942023-10-13T04:47:23.813Z{"msg":"source 0, add dest 1 source flush","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:47:19.452461987Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1204,"mrl":"dirty","":"mend"}
4952023-10-13T04:47:23.816Z{"msg":"source 0, add dest 2 gen","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:47:19.452510736Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1204,"mrl":"dirty","":"mend"}
4962023-10-13T04:47:23.820Z{"msg":"Extent 1 has flush number mismatch","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:47:19.452560541Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1204,"":"mend"}
4972023-10-13T04:47:23.823Z{"msg":"First source client ID for extent 1","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:47:19.452586374Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1204,"mrl":"flush_mismatch","":"mend"}
4982023-10-13T04:47:23.828Z{"msg":"extent:1 gens: 27 27 26","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:47:19.452607243Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1204,"mrl":"flush_mismatch","":"mend"}
4992023-10-13T04:47:23.836Z{"msg":"extent:1 flush: 1930 1930 1929 scs: [ClientId(0), ClientId(1)]","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:47:19.452627812Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1204,"mrl":"flush_mismatch","":"mend"}
5002023-10-13T04:47:23.863Z{"msg":"max_flush now has: [ClientId(0), ClientId(1)]","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:47:19.452647199Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1204,"mrl":"flush_mismatch","":"mend"}
5012023-10-13T04:47:23.878Z{"msg":"extent:1 dirty: false false false","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:47:19.452667139Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1204,"mrl":"flush_mismatch","":"mend"}
5022023-10-13T04:47:23.882Z{"msg":"No maxes found, left with: [ClientId(0), ClientId(1)]","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:47:19.452687582Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1204,"mrl":"flush_mismatch","":"mend"}
5032023-10-13T04:47:23.886Z{"msg":"find dest for source 0 for extent at index 1","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:47:19.452716912Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1204,"mrl":"flush_mismatch","":"mend"}
5042023-10-13T04:47:23.896Z{"msg":"source 0, add dest 2 gen","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:47:19.452737065Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1204,"mrl":"flush_mismatch","":"mend"}
5052023-10-13T04:47:23.901Z{"msg":"Extent 2 has flush number mismatch","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:47:19.452756846Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1204,"":"mend"}
5062023-10-13T04:47:23.904Z{"msg":"First source client ID for extent 2","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:47:19.452774645Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1204,"mrl":"flush_mismatch","":"mend"}
5072023-10-13T04:47:23.907Z{"msg":"extent:2 gens: 27 27 26","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:47:19.452793766Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1204,"mrl":"flush_mismatch","":"mend"}
5082023-10-13T04:47:23.912Z{"msg":"extent:2 flush: 1930 1930 1929 scs: [ClientId(0), ClientId(1)]","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:47:19.452813897Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1204,"mrl":"flush_mismatch","":"mend"}
5092023-10-13T04:47:23.920Z{"msg":"max_flush now has: [ClientId(0), ClientId(1)]","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:47:19.452915967Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1204,"mrl":"flush_mismatch","":"mend"}
5102023-10-13T04:47:23.927Z{"msg":"extent:2 dirty: false false false","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:47:19.452956863Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1204,"mrl":"flush_mismatch","":"mend"}
5112023-10-13T04:47:23.932Z{"msg":"No maxes found, left with: [ClientId(0), ClientId(1)]","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:47:19.452994753Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1204,"mrl":"flush_mismatch","":"mend"}
5122023-10-13T04:47:23.937Z{"msg":"find dest for source 0 for extent at index 2","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:47:19.453030488Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1204,"mrl":"flush_mismatch","":"mend"}
5132023-10-13T04:47:23.942Z{"msg":"source 0, add dest 2 gen","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:47:19.453068294Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1204,"mrl":"flush_mismatch","":"mend"}
5142023-10-13T04:47:23.949Z{"msg":"Transition from WaitQuorum to Repair","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:47:19.453112729Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1204}
5152023-10-13T04:47:23.956Z{"msg":"Transition from WaitQuorum to Repair","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:47:19.453148154Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1204}
5162023-10-13T04:47:23.969Z{"msg":"Transition from WaitQuorum to Repair","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:47:19.453181677Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1204}
5172023-10-13T04:47:23.975Z{"msg":"Found 5 extents that need repair","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:47:19.453213467Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1204}
5182023-10-13T04:47:23.980Z{"msg":"Full repair list: {0: ExtentFix { source: ClientId(0), dest: [ClientId(1), ClientId(2)] }, 1: ExtentFix { source: ClientId(0), dest: [ClientId(2)] }, 2: ExtentFix { source: ClientId(0), dest: [ClientId(2)] }, 4: ExtentFix { source: ClientId(0), dest: [ClientId(1), ClientId(2)] }, 3: ExtentFix { source: ClientId(0), dest: [ClientId(1), ClientId(2)] }}","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:47:19.453260295Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1204,"":"downstairs"}
5192023-10-13T04:47:23.994Z{"msg":"Task list: [ReconcileIO { id: ReconciliationId(0), op: ExtentFlush { repair_id: ReconciliationId(0), extent_id: 0, client_id: ClientId(0), flush_number: 1931, gen_number: 28 }, state: ClientData([New, New, New]) }, ReconcileIO { id: ReconciliationId(1), op: ExtentClose { repair_id: ReconciliationId(1), extent_id: 0 }, state: ClientData([New, New, New]) }, ReconcileIO { id: ReconciliationId(2), op: ExtentRepair { repair_id: ReconciliationId(2), extent_id: 0, source_client_id: ClientId(0), source_repair_address: 0.0.0.0:12810, dest_clients: [ClientId(1), ClientId(2)] }, state: ClientData([New, New, New]) }, ReconcileIO { id: ReconciliationId(3), op: ExtentReopen { repair_id: ReconciliationId(3), extent_id: 0 }, state: ClientData([New, New, New]) }, ReconcileIO { id: ReconciliationId(4), op: ExtentFlush { repair_id: ReconciliationId(4), extent_id: 1, client_id: ClientId(0), flush_number: 1931, gen_number: 28 }, 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(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: 2, client_id: ClientId(0), flush_number: 1931, gen_number: 28 }, state: ClientData([New, New, New]) }, ReconcileIO { id: ReconciliationId(9), op: ExtentClose { repair_id: ReconciliationId(9), extent_id: 2 }, state: ClientData([New, New, New]) }, ReconcileIO { id: ReconciliationId(10), op: ExtentRepair { repair_id: ReconciliationId(10), extent_id: 2, source_client_id: ClientId(0), source_repair_address: 0.0.0.0:12810, dest_clients: [ClientId(2)] }, state: ClientData([New, New, New]) }, ReconcileIO { id: ReconciliationId(11), op: ExtentReopen { repair_id: ReconciliationId(11), extent_id: 2 }, state: ClientData([New, New, New]) }, ReconcileIO { id: ReconciliationId(12), op: ExtentFlush { repair_id: ReconciliationId(12), extent_id: 4, client_id: ClientId(0), flush_number: 1931, gen_number: 28 }, state: ClientData([New, New, New]) }, ReconcileIO { id: ReconciliationId(13), op: ExtentClose { repair_id: ReconciliationId(13), extent_id: 4 }, state: ClientData([New, New, New]) }, ReconcileIO { id: ReconciliationId(14), op: ExtentRepair { repair_id: ReconciliationId(14), 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(15), op: ExtentReopen { repair_id: ReconciliationId(15), extent_id: 4 }, state: ClientData([New, New, New]) }, ReconcileIO { id: ReconciliationId(16), op: ExtentFlush { repair_id: ReconciliationId(16), extent_id: 3, client_id: ClientId(0), flush_number: 1931, gen_number: 28 }, state: ClientData([New, New, New]) }, ReconcileIO { id: ReconciliationId(17), op: ExtentClose { repair_id: ReconciliationId(17), extent_id: 3 }, state: ClientData([New, New, New]) }, ReconcileIO { id: ReconciliationId(18), op: ExtentRepair { repair_id: ReconciliationId(18), 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(19), op: ExtentReopen { repair_id: ReconciliationId(19), extent_id: 3 }, state: ClientData([New, New, New]) }]","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:47:19.453482722Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1204,"":"downstairs"}
5202023-10-13T04:47:24.006Z{"msg":"Begin repair with 20 commands","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:47:21.364636646Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1204}
5212023-10-13T04:47:24.010Z{"msg":"Pop front: ReconcileIO { id: ReconciliationId(0), op: ExtentFlush { repair_id: ReconciliationId(0), extent_id: 0, client_id: ClientId(0), flush_number: 1931, gen_number: 28 }, state: ClientData([New, New, New]) }","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:47:21.364703074Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1204}
5222023-10-13T04:47:24.013Z{"msg":"Sent repair work, now wait for resp","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:47:21.364754422Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1204}
5232023-10-13T04:47:24.016Z{"msg":"[2] received reconcile message","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:47:21.364776259Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1204}
5242023-10-13T04:47:24.019Z{"msg":"[2] rep_in_progress: return ReconcileIO { id: ReconciliationId(0), op: ExtentFlush { repair_id: ReconciliationId(0), extent_id: 0, client_id: ClientId(0), flush_number: 1931, gen_number: 28 }, state: ClientData([New, New, InProgress]) }","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:47:21.364799706Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1204,"":"downstairs"}
5252023-10-13T04:47:24.022Z{"msg":"[2] client ExtentFlush { repair_id: ReconciliationId(0), extent_id: 0, client_id: ClientId(0), flush_number: 1931, gen_number: 28 }","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:47:21.364822552Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1204}
5262023-10-13T04:47:24.025Z{"msg":"[0] received reconcile message","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:47:21.36484099Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1204}
5272023-10-13T04:47:24.028Z{"msg":"[0] rep_in_progress: return ReconcileIO { id: ReconciliationId(0), op: ExtentFlush { repair_id: ReconciliationId(0), extent_id: 0, client_id: ClientId(0), flush_number: 1931, gen_number: 28 }, state: ClientData([InProgress, New, Done]) }","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:47:21.36486407Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1204,"":"downstairs"}
5282023-10-13T04:47:24.031Z{"msg":"[1] received reconcile message","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:47:21.364882796Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1204}
5292023-10-13T04:47:24.034Z{"msg":"[0] client ExtentFlush { repair_id: ReconciliationId(0), extent_id: 0, client_id: ClientId(0), flush_number: 1931, gen_number: 28 }","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:47:21.364902511Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1204}
5302023-10-13T04:47:24.040Z{"msg":"[1] rep_in_progress: return ReconcileIO { id: ReconciliationId(0), op: ExtentFlush { repair_id: ReconciliationId(0), extent_id: 0, client_id: ClientId(0), flush_number: 1931, gen_number: 28 }, state: ClientData([InProgress, InProgress, Done]) }","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:47:21.364925849Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1204,"":"downstairs"}
5312023-10-13T04:47:24.043Z{"msg":"[1] client ExtentFlush { repair_id: ReconciliationId(0), extent_id: 0, client_id: ClientId(0), flush_number: 1931, gen_number: 28 }","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:47:21.364947559Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1204}
5322023-10-13T04:47:24.046Z{"msg":"Completion from [0] id:0 status:true","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:47:21.364965237Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1204}
5332023-10-13T04:47:24.051Z{"msg":"[1/20] Repair commands completed","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:47:21.364982395Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1204}
5342023-10-13T04:47:24.469Z{"msg":"Pop front: ReconcileIO { id: ReconciliationId(1), op: ExtentClose { repair_id: ReconciliationId(1), extent_id: 0 }, state: ClientData([New, New, New]) }","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:47:21.36500276Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1204}
5352023-10-13T04:47:24.487Z{"msg":"Sent repair work, now wait for resp","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:47:21.36502011Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1204}
5362023-10-13T04:47:24.496Z{"msg":"[2] received reconcile message","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:47:21.365037193Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1204}
5372023-10-13T04:47:24.508Z{"msg":"[2] rep_in_progress: return ReconcileIO { id: ReconciliationId(1), op: ExtentClose { repair_id: ReconciliationId(1), extent_id: 0 }, state: ClientData([New, New, InProgress]) }","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:47:21.365057771Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1204,"":"downstairs"}
5382023-10-13T04:47:24.519Z{"msg":"[2] client ExtentClose { repair_id: ReconciliationId(1), extent_id: 0 }","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:47:21.365077794Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1204}
5392023-10-13T04:47:24.524Z{"msg":"[0] received reconcile message","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:47:21.365095453Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1204}
5402023-10-13T04:47:24.536Z{"msg":"[0] rep_in_progress: return ReconcileIO { id: ReconciliationId(1), op: ExtentClose { repair_id: ReconciliationId(1), extent_id: 0 }, state: ClientData([InProgress, New, InProgress]) }","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:47:21.365142133Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1204,"":"downstairs"}
5412023-10-13T04:47:25.959Z{"msg":"[0] client ExtentClose { repair_id: ReconciliationId(1), extent_id: 0 }","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:47:21.365165458Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1204}
5422023-10-13T04:47:25.971Z{"msg":"[1] received reconcile message","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:47:21.365183292Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1204}
5432023-10-13T04:47:26.008Z{"msg":"[1] rep_in_progress: return ReconcileIO { id: ReconciliationId(1), op: ExtentClose { repair_id: ReconciliationId(1), extent_id: 0 }, state: ClientData([InProgress, InProgress, InProgress]) }","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:47:21.365204381Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1204,"":"downstairs"}
5442023-10-13T04:47:26.034Z{"msg":"[1] client ExtentClose { repair_id: ReconciliationId(1), extent_id: 0 }","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:47:22.233287243Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1204}
5452023-10-13T04:47:26.046Z{"msg":"Completion from [1] id:1 status:true","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:47:22.233343856Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1204}
5462023-10-13T04:47:26.064Z{"msg":"[2/20] Repair commands completed","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:47:22.233363209Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1204}
5472023-10-13T04:47:26.079Z{"msg":"Pop front: ReconcileIO { id: ReconciliationId(2), op: ExtentRepair { repair_id: ReconciliationId(2), extent_id: 0, source_client_id: ClientId(0), source_repair_address: 0.0.0.0:12810, dest_clients: [ClientId(1), ClientId(2)] }, state: ClientData([New, New, New]) }","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:47:22.23338686Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1204}
5482023-10-13T04:47:26.513Z{"msg":"Sent repair work, now wait for resp","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:47:22.233405336Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1204}
5492023-10-13T04:47:26.530Z{"msg":"[2] received reconcile message","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:47:22.23342239Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1204}
5502023-10-13T04:47:26.543Z{"msg":"[2] rep_in_progress: return ReconcileIO { id: ReconciliationId(2), op: ExtentRepair { repair_id: ReconciliationId(2), extent_id: 0, source_client_id: ClientId(0), source_repair_address: 0.0.0.0:12810, dest_clients: [ClientId(1), ClientId(2)] }, state: ClientData([New, New, InProgress]) }","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:47:22.233446108Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1204,"":"downstairs"}
5512023-10-13T04:47:26.961Z{"msg":"[2] client ExtentRepair { repair_id: ReconciliationId(2), extent_id: 0, source_client_id: ClientId(0), source_repair_address: 0.0.0.0:12810, dest_clients: [ClientId(1), ClientId(2)] }","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:47:22.233470237Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1204}
5522023-10-13T04:47:26.978Z{"msg":"[2] Sending repair request ReconciliationId(2)","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:47:22.233501049Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1204}
5532023-10-13T04:47:26.992Z{"msg":"[0] received reconcile message","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:47:22.233534204Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1204}
5542023-10-13T04:47:27.011Z{"msg":"[0] rep_in_progress: return ReconcileIO { id: ReconciliationId(2), op: ExtentRepair { repair_id: ReconciliationId(2), extent_id: 0, source_client_id: ClientId(0), source_repair_address: 0.0.0.0:12810, dest_clients: [ClientId(1), ClientId(2)] }, state: ClientData([InProgress, New, InProgress]) }","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:47:22.23357745Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1204,"":"downstairs"}
5552023-10-13T04:47:27.033Z{"msg":"[0] client ExtentRepair { repair_id: ReconciliationId(2), extent_id: 0, source_client_id: ClientId(0), source_repair_address: 0.0.0.0:12810, dest_clients: [ClientId(1), ClientId(2)] }","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:47:22.233621163Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1204}
5562023-10-13T04:47:27.458Z{"msg":"[0] No action required ReconciliationId(2)","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:47:22.233658953Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1204}
5572023-10-13T04:47:27.463Z{"msg":"[1] received reconcile message","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:47:22.233691983Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1204}
5582023-10-13T04:47:27.466Z{"msg":"[1] rep_in_progress: return ReconcileIO { id: ReconciliationId(2), op: ExtentRepair { repair_id: ReconciliationId(2), extent_id: 0, source_client_id: ClientId(0), source_repair_address: 0.0.0.0:12810, dest_clients: [ClientId(1), ClientId(2)] }, state: ClientData([Done, InProgress, InProgress]) }","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:47:22.233733734Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1204,"":"downstairs"}
5592023-10-13T04:47:27.471Z{"msg":"[1] client ExtentRepair { repair_id: ReconciliationId(2), extent_id: 0, source_client_id: ClientId(0), source_repair_address: 0.0.0.0:12810, dest_clients: [ClientId(1), ClientId(2)] }","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:47:22.233759894Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1204}
5602023-10-13T04:47:27.489Z{"msg":"[1] Sending repair request ReconciliationId(2)","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:47:22.233777751Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1204}
5612023-10-13T04:47:27.498Z{"msg":"Completion from [1] id:2 status:true","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:47:22.233795427Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1204}
5622023-10-13T04:47:27.511Z{"msg":"[3/20] Repair commands completed","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:47:22.233813014Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1204}
5632023-10-13T04:47:27.533Z{"msg":"Pop front: ReconcileIO { id: ReconciliationId(3), op: ExtentReopen { repair_id: ReconciliationId(3), extent_id: 0 }, state: ClientData([New, New, New]) }","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:47:22.233833821Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1204}
5642023-10-13T04:47:27.549Z{"msg":"Sent repair work, now wait for resp","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:47:22.233851791Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1204}
5652023-10-13T04:47:27.557Z{"msg":"[2] received reconcile message","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:47:22.233869287Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1204}
5662023-10-13T04:47:27.571Z{"msg":"[2] rep_in_progress: return ReconcileIO { id: ReconciliationId(3), op: ExtentReopen { repair_id: ReconciliationId(3), extent_id: 0 }, state: ClientData([New, New, InProgress]) }","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:47:22.233890648Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1204,"":"downstairs"}
5672023-10-13T04:47:27.576Z{"msg":"[2] client ExtentReopen { repair_id: ReconciliationId(3), extent_id: 0 }","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:47:22.233910382Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1204}
5682023-10-13T04:47:27.587Z{"msg":"[0] received reconcile message","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:47:22.233927462Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1204}
5692023-10-13T04:47:27.597Z{"msg":"[0] rep_in_progress: return ReconcileIO { id: ReconciliationId(3), op: ExtentReopen { repair_id: ReconciliationId(3), extent_id: 0 }, state: ClientData([InProgress, New, InProgress]) }","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:47:22.233948667Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1204,"":"downstairs"}
5702023-10-13T04:47:27.611Z{"msg":"[0] client ExtentReopen { repair_id: ReconciliationId(3), extent_id: 0 }","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:47:22.233967876Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1204}
5712023-10-13T04:47:27.622Z{"msg":"[1] received reconcile message","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:47:22.233984754Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1204}
5722023-10-13T04:47:27.636Z{"msg":"[1] rep_in_progress: return ReconcileIO { id: ReconciliationId(3), op: ExtentReopen { repair_id: ReconciliationId(3), extent_id: 0 }, state: ClientData([InProgress, InProgress, InProgress]) }","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:47:22.234006099Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1204,"":"downstairs"}
5732023-10-13T04:47:28.063Z{"msg":"[1] client ExtentReopen { repair_id: ReconciliationId(3), extent_id: 0 }","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:47:22.234025747Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1204}
5742023-10-13T04:47:28.081Z{"msg":"Completion from [1] id:3 status:true","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:47:22.234042704Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1204}
5752023-10-13T04:47:28.500Z{"msg":"[4/20] Repair commands completed","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:47:22.569795654Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1204}
5762023-10-13T04:47:28.514Z{"msg":"Pop front: ReconcileIO { id: ReconciliationId(4), op: ExtentFlush { repair_id: ReconciliationId(4), extent_id: 1, client_id: ClientId(0), flush_number: 1931, gen_number: 28 }, state: ClientData([New, New, New]) }","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:47:22.569888263Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1204}
5772023-10-13T04:47:28.530Z{"msg":"Sent repair work, now wait for resp","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:47:22.56994199Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1204}
5782023-10-13T04:47:28.543Z{"msg":"[2] received reconcile message","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:47:22.569964086Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1204}
5792023-10-13T04:47:28.558Z{"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: 1931, gen_number: 28 }, state: ClientData([New, New, InProgress]) }","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:47:22.569988048Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1204,"":"downstairs"}
5802023-10-13T04:47:28.571Z{"msg":"[0] received reconcile message","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:47:22.570009314Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1204}
5812023-10-13T04:47:28.586Z{"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: 1931, gen_number: 28 }, state: ClientData([InProgress, New, InProgress]) }","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:47:22.570062377Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1204,"":"downstairs"}
5822023-10-13T04:47:29.003Z{"msg":"[1] received reconcile message","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:47:22.570084616Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1204}
5832023-10-13T04:47:29.032Z{"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: 1931, gen_number: 28 }, state: ClientData([InProgress, InProgress, InProgress]) }","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:47:22.570108057Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1204,"":"downstairs"}
5842023-10-13T04:47:29.042Z{"msg":"[0] client ExtentFlush { repair_id: ReconciliationId(4), extent_id: 1, client_id: ClientId(0), flush_number: 1931, gen_number: 28 }","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:47:22.570129331Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1204}
5852023-10-13T04:47:29.469Z{"msg":"[1] client ExtentFlush { repair_id: ReconciliationId(4), extent_id: 1, client_id: ClientId(0), flush_number: 1931, gen_number: 28 }","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:47:22.57014978Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1204}
5862023-10-13T04:47:29.487Z{"msg":"[2] client ExtentFlush { repair_id: ReconciliationId(4), extent_id: 1, client_id: ClientId(0), flush_number: 1931, gen_number: 28 }","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:47:22.570170249Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1204}
5872023-10-13T04:47:29.506Z{"msg":"Completion from [0] id:4 status:true","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:47:22.570188082Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1204}
5882023-10-13T04:47:29.527Z{"msg":"[5/20] Repair commands completed","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:47:22.570205304Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1204}
5892023-10-13T04:47:29.545Z{"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:47:22.570225541Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1204}
5902023-10-13T04:47:30.095Z{"msg":"Sent repair work, now wait for resp","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:47:22.570243549Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1204}
5912023-10-13T04:47:30.565Z{"msg":"[2] received reconcile message","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:47:22.570260755Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1204}
5922023-10-13T04:47:30.710Z{"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:47:22.570281661Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1204,"":"downstairs"}
5932023-10-13T04:47:30.753Z{"msg":"[2] client ExtentClose { repair_id: ReconciliationId(5), extent_id: 1 }","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:47:22.570301441Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1204}
5942023-10-13T04:47:30.761Z{"msg":"[0] received reconcile message","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:47:22.570319276Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1204}
5952023-10-13T04:47:30.771Z{"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:47:22.570340549Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1204,"":"downstairs"}
5962023-10-13T04:47:30.782Z{"msg":"[0] client ExtentClose { repair_id: ReconciliationId(5), extent_id: 1 }","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:47:22.570360078Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1204}
5972023-10-13T04:47:30.788Z{"msg":"[1] received reconcile message","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:47:22.570382613Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1204}
5982023-10-13T04:47:30.798Z{"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:47:22.570404175Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1204,"":"downstairs"}
5992023-10-13T04:47:30.818Z{"msg":"[1] client ExtentClose { repair_id: ReconciliationId(5), extent_id: 1 }","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:47:22.570423632Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1204}
6002023-10-13T04:47:30.828Z{"msg":"Completion from [1] id:5 status:true","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:47:22.57044112Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1204}
6012023-10-13T04:47:30.834Z{"msg":"[6/20] Repair commands completed","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:47:22.570459029Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1204}
6022023-10-13T04:47:30.840Z{"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(2)] }, state: ClientData([New, New, New]) }","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:47:22.570482233Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1204}
6032023-10-13T04:47:30.854Z{"msg":"Sent repair work, now wait for resp","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:47:22.57049976Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1204}
6042023-10-13T04:47:30.865Z{"msg":"[2] received reconcile message","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:47:22.570516974Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1204}
6052023-10-13T04:47:30.874Z{"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(2)] }, state: ClientData([New, New, InProgress]) }","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:47:22.570540501Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1204,"":"downstairs"}
6062023-10-13T04:47:30.885Z{"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(2)] }","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:47:22.57056282Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1204}
6072023-10-13T04:47:30.892Z{"msg":"[2] Sending repair request ReconciliationId(6)","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:47:23.283346607Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1204}
6082023-10-13T04:47:30.900Z{"msg":"[0] received reconcile message","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:47:23.283432252Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1204}
6092023-10-13T04:47:30.909Z{"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(2)] }, state: ClientData([InProgress, New, InProgress]) }","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:47:23.283461269Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1204,"":"downstairs"}
6102023-10-13T04:47:30.927Z{"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(2)] }","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:47:23.283485568Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1204}
6112023-10-13T04:47:30.932Z{"msg":"[0] No action required ReconciliationId(6)","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:47:23.283503272Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1204}
6122023-10-13T04:47:30.942Z{"msg":"[1] received reconcile message","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:47:23.283520222Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1204}
6132023-10-13T04:47:30.952Z{"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(2)] }, state: ClientData([Done, InProgress, InProgress]) }","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:47:23.283543702Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1204,"":"downstairs"}
6142023-10-13T04:47:30.956Z{"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(2)] }","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:47:23.283565825Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1204}
6152023-10-13T04:47:30.959Z{"msg":"[1] No action required ReconciliationId(6)","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:47:23.283583468Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1204}
6162023-10-13T04:47:30.963Z{"msg":"Completion from [2] id:6 status:true","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:47:23.283600745Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1204}
6172023-10-13T04:47:30.967Z{"msg":"[7/20] Repair commands completed","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:47:23.283617695Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1204}
6182023-10-13T04:47:30.970Z{"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:47:23.283637858Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1204}
6192023-10-13T04:47:30.984Z{"msg":"Sent repair work, now wait for resp","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:47:23.283655349Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1204}
6202023-10-13T04:47:30.987Z{"msg":"[2] received reconcile message","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:47:23.28367227Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1204}
6212023-10-13T04:47:30.991Z{"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:47:23.283693471Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1204,"":"downstairs"}
6222023-10-13T04:47:30.995Z{"msg":"[0] received reconcile message","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:47:23.283711474Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1204}
6232023-10-13T04:47:30.998Z{"msg":"[2] client ExtentReopen { repair_id: ReconciliationId(7), extent_id: 1 }","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:47:23.283729771Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1204}
6242023-10-13T04:47:31.012Z{"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:47:23.28375126Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1204,"":"downstairs"}
6252023-10-13T04:47:31.016Z{"msg":"[0] client ExtentReopen { repair_id: ReconciliationId(7), extent_id: 1 }","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:47:23.283770588Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1204}
6262023-10-13T04:47:31.019Z{"msg":"[1] received reconcile message","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:47:23.283787758Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1204}
6272023-10-13T04:47:31.023Z{"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:47:23.283808976Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1204,"":"downstairs"}
6282023-10-13T04:47:31.027Z{"msg":"[1] client ExtentReopen { repair_id: ReconciliationId(7), extent_id: 1 }","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:47:23.283828161Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1204}
6292023-10-13T04:47:31.030Z{"msg":"Completion from [2] id:7 status:true","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:47:23.283845517Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1204}
6302023-10-13T04:47:31.033Z{"msg":"[8/20] Repair commands completed","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:47:23.28386366Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1204}
6312023-10-13T04:47:31.036Z{"msg":"Pop front: ReconcileIO { id: ReconciliationId(8), op: ExtentFlush { repair_id: ReconciliationId(8), extent_id: 2, client_id: ClientId(0), flush_number: 1931, gen_number: 28 }, state: ClientData([New, New, New]) }","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:47:23.283885859Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1204}
6322023-10-13T04:47:31.039Z{"msg":"Sent repair work, now wait for resp","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:47:23.283903092Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1204}
6332023-10-13T04:47:31.042Z{"msg":"[2] received reconcile message","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:47:23.283920436Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1204}
6342023-10-13T04:47:31.045Z{"msg":"[2] rep_in_progress: return ReconcileIO { id: ReconciliationId(8), op: ExtentFlush { repair_id: ReconciliationId(8), extent_id: 2, client_id: ClientId(0), flush_number: 1931, gen_number: 28 }, state: ClientData([New, New, InProgress]) }","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:47:23.28394289Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1204,"":"downstairs"}
6352023-10-13T04:47:31.051Z{"msg":"[2] client ExtentFlush { repair_id: ReconciliationId(8), extent_id: 2, client_id: ClientId(0), flush_number: 1931, gen_number: 28 }","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:47:23.283963923Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1204}
6362023-10-13T04:47:31.067Z{"msg":"[0] received reconcile message","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:47:23.283980905Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1204}
6372023-10-13T04:47:31.077Z{"msg":"[0] rep_in_progress: return ReconcileIO { id: ReconciliationId(8), op: ExtentFlush { repair_id: ReconciliationId(8), extent_id: 2, client_id: ClientId(0), flush_number: 1931, gen_number: 28 }, state: ClientData([InProgress, New, Done]) }","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:47:23.284003459Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1204,"":"downstairs"}
6382023-10-13T04:47:31.084Z{"msg":"[0] client ExtentFlush { repair_id: ReconciliationId(8), extent_id: 2, client_id: ClientId(0), flush_number: 1931, gen_number: 28 }","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:47:23.284024171Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1204}
6392023-10-13T04:47:31.088Z{"msg":"[1] received reconcile message","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:47:23.925558645Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1204}
6402023-10-13T04:47:31.097Z{"msg":"[1] rep_in_progress: return ReconcileIO { id: ReconciliationId(8), op: ExtentFlush { repair_id: ReconciliationId(8), extent_id: 2, client_id: ClientId(0), flush_number: 1931, gen_number: 28 }, state: ClientData([InProgress, InProgress, Done]) }","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:47:23.925618775Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1204,"":"downstairs"}
6412023-10-13T04:47:31.104Z{"msg":"[1] client ExtentFlush { repair_id: ReconciliationId(8), extent_id: 2, client_id: ClientId(0), flush_number: 1931, gen_number: 28 }","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:47:23.925642937Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1204}
6422023-10-13T04:47:31.113Z{"msg":"Completion from [0] id:8 status:true","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:47:23.925660898Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1204}
6432023-10-13T04:47:31.123Z{"msg":"[9/20] Repair commands completed","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:47:23.925678121Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1204}
6442023-10-13T04:47:31.135Z{"msg":"Pop front: ReconcileIO { id: ReconciliationId(9), op: ExtentClose { repair_id: ReconciliationId(9), extent_id: 2 }, state: ClientData([New, New, New]) }","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:47:23.925698362Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1204}
6452023-10-13T04:47:31.153Z{"msg":"Sent repair work, now wait for resp","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:47:23.925716125Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1204}
6462023-10-13T04:47:31.183Z{"msg":"[2] received reconcile message","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:47:23.92573349Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1204}
6472023-10-13T04:47:31.207Z{"msg":"[2] rep_in_progress: return ReconcileIO { id: ReconciliationId(9), op: ExtentClose { repair_id: ReconciliationId(9), extent_id: 2 }, state: ClientData([New, New, InProgress]) }","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:47:23.925754662Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1204,"":"downstairs"}
6482023-10-13T04:47:31.223Z{"msg":"[2] client ExtentClose { repair_id: ReconciliationId(9), extent_id: 2 }","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:47:23.925774852Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1204}
6492023-10-13T04:47:31.238Z{"msg":"[1] received reconcile message","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:47:23.925792575Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1204}
6502023-10-13T04:47:31.255Z{"msg":"[0] received reconcile message","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:47:23.925809444Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1204}
6512023-10-13T04:47:31.263Z{"msg":"[1] rep_in_progress: return ReconcileIO { id: ReconciliationId(9), op: ExtentClose { repair_id: ReconciliationId(9), extent_id: 2 }, state: ClientData([New, InProgress, InProgress]) }","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:47:23.925830705Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1204,"":"downstairs"}
6522023-10-13T04:47:31.273Z{"msg":"[1] client ExtentClose { repair_id: ReconciliationId(9), extent_id: 2 }","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:47:23.925864145Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1204}
6532023-10-13T04:47:31.282Z{"msg":"[0] rep_in_progress: return ReconcileIO { id: ReconciliationId(9), op: ExtentClose { repair_id: ReconciliationId(9), extent_id: 2 }, state: ClientData([InProgress, InProgress, InProgress]) }","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:47:23.925899468Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1204,"":"downstairs"}
6542023-10-13T04:47:31.290Z{"msg":"[0] client ExtentClose { repair_id: ReconciliationId(9), extent_id: 2 }","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:47:23.925931327Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1204}
6552023-10-13T04:47:31.299Z{"msg":"Completion from [1] id:9 status:true","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:47:23.925960211Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1204}
6562023-10-13T04:47:31.305Z{"msg":"[10/20] Repair commands completed","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:47:23.925990749Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1204}
6572023-10-13T04:47:31.311Z{"msg":"Pop front: ReconcileIO { id: ReconciliationId(10), op: ExtentRepair { repair_id: ReconciliationId(10), extent_id: 2, source_client_id: ClientId(0), source_repair_address: 0.0.0.0:12810, dest_clients: [ClientId(2)] }, state: ClientData([New, New, New]) }","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:47:23.926027855Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1204}
6582023-10-13T04:47:31.316Z{"msg":"Sent repair work, now wait for resp","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:47:23.926061691Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1204}
6592023-10-13T04:47:31.325Z{"msg":"[2] received reconcile message","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:47:23.926093721Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1204}
6602023-10-13T04:47:31.334Z{"msg":"[2] rep_in_progress: return ReconcileIO { id: ReconciliationId(10), op: ExtentRepair { repair_id: ReconciliationId(10), extent_id: 2, source_client_id: ClientId(0), source_repair_address: 0.0.0.0:12810, dest_clients: [ClientId(2)] }, state: ClientData([New, New, InProgress]) }","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:47:23.926134249Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1204,"":"downstairs"}
6612023-10-13T04:47:31.340Z{"msg":"[2] client ExtentRepair { repair_id: ReconciliationId(10), extent_id: 2, source_client_id: ClientId(0), source_repair_address: 0.0.0.0:12810, dest_clients: [ClientId(2)] }","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:47:23.926175403Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1204}
6622023-10-13T04:47:31.348Z{"msg":"[2] Sending repair request ReconciliationId(10)","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:47:23.926210305Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1204}
6632023-10-13T04:47:31.358Z{"msg":"[0] received reconcile message","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:47:23.926242678Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1204}
6642023-10-13T04:47:31.366Z{"msg":"[1] received reconcile message","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:47:23.926276191Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1204}
6652023-10-13T04:47:31.373Z{"msg":"[1] rep_in_progress: return ReconcileIO { id: ReconciliationId(10), op: ExtentRepair { repair_id: ReconciliationId(10), extent_id: 2, source_client_id: ClientId(0), source_repair_address: 0.0.0.0:12810, dest_clients: [ClientId(2)] }, state: ClientData([New, InProgress, InProgress]) }","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:47:23.926317936Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1204,"":"downstairs"}
6662023-10-13T04:47:31.395Z{"msg":"[1] client ExtentRepair { repair_id: ReconciliationId(10), extent_id: 2, source_client_id: ClientId(0), source_repair_address: 0.0.0.0:12810, dest_clients: [ClientId(2)] }","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:47:23.926360372Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1204}
6672023-10-13T04:47:31.405Z{"msg":"[1] No action required ReconciliationId(10)","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:47:23.926393099Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1204}
6682023-10-13T04:47:31.415Z{"msg":"[0] rep_in_progress: return ReconcileIO { id: ReconciliationId(10), op: ExtentRepair { repair_id: ReconciliationId(10), extent_id: 2, source_client_id: ClientId(0), source_repair_address: 0.0.0.0:12810, dest_clients: [ClientId(2)] }, state: ClientData([InProgress, InProgress, InProgress]) }","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:47:23.926434514Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1204,"":"downstairs"}
6692023-10-13T04:47:31.423Z{"msg":"[0] client ExtentRepair { repair_id: ReconciliationId(10), extent_id: 2, source_client_id: ClientId(0), source_repair_address: 0.0.0.0:12810, dest_clients: [ClientId(2)] }","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:47:23.926473113Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1204}
6702023-10-13T04:47:31.432Z{"msg":"[0] No action required ReconciliationId(10)","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:47:24.544742339Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1204}
6712023-10-13T04:47:31.439Z{"msg":"Completion from [2] id:10 status:true","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:47:24.54480025Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1204}
6722023-10-13T04:47:31.460Z{"msg":"[11/20] Repair commands completed","v":0,"name":"crucible","level":30The guest has finished waiting for activation with:28
6732023-10-13T04:47:31.563Z,"time"Wait for a query_work_queue command to finish before sending IO
6742023-10-13T04:47:31.588Z:"2023-10-13T04:47:24.544819989Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1204}
6752023-10-13T04:47:31.669Z{"msg":"Pop front: ReconcileIO { id: ReconciliationId(11), op: ExtentReopen { repair_id: ReconciliationId(11), extent_id: 2 }, state: ClientData([New, New, New]) }","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:47:24.544850153Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1204}
6762023-10-13T04:47:31.730Z{"msg":"Sent repair work, now wait for resp","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:47:24.544868173Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1204}
6772023-10-13T04:47:31.749Z{"msg":"[2] received reconcile message","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:47:24.544885514Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1204}
6782023-10-13T04:47:31.762Z{"msg":"[2] rep_in_progress: return ReconcileIO { id: ReconciliationId(11), op: ExtentReopen { repair_id: ReconciliationId(11), extent_id: 2 }, state: ClientData([New, New, InProgress]) }","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:47:24.544906713Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1204,"":"downstairs"}
6792023-10-13T04:47:32.232Z{"msg":"[2] client ExtentReopen { repair_id: ReconciliationId(11), extent_id: 2 }","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:47:24.544928397Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1204}
6802023-10-13T04:47:32.243Z{"msg":"[0] received reconcile message","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:47:24.544946291Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1204}
6812023-10-13T04:47:32.272Z{"msg":"[0] rep_in_progress: return ReconcileIO { id: ReconciliationId(11), op: ExtentReopen { repair_id: ReconciliationId(11), extent_id: 2 }, state: ClientData([InProgress, New, InProgress]) }","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:47:24.544967266Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1204,"":"downstairs"}
6822023-10-13T04:47:32.300Z{"msg":"[0] client ExtentReopen { repair_id: ReconciliationId(11), extent_id: 2 }","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:47:24.544987218Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1204}
6832023-10-13T04:47:32.329Z{"msg":"[1] received reconcile message","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:47:24.545004832Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1204}
6842023-10-13T04:47:32.350Z{"msg":"[1] rep_in_progress: return ReconcileIO { id: ReconciliationId(11), op: ExtentReopen { repair_id: ReconciliationId(11), extent_id: 2 }, state: ClientData([InProgress, InProgress, InProgress]) }","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:47:24.545026116Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1204,"":"downstairs"}
6852023-10-13T04:47:32.367Z{"msg":"[1] client ExtentReopen { repair_id: ReconciliationId(11), extent_id: 2 }","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:47:24.545051744Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1204}
6862023-10-13T04:47:32.380Z{"msg":"Completion from [1] id:11 status:true","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:47:24.545084705Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1204}
6872023-10-13T04:47:32.393Z{"msg":"[12/20] Repair commands completed","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:47:24.545118669Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1204}
6882023-10-13T04:47:32.405Z{"msg":"Pop front: ReconcileIO { id: ReconciliationId(12), op: ExtentFlush { repair_id: ReconciliationId(12), extent_id: 4, client_id: ClientId(0), flush_number: 1931, gen_number: 28 }, state: ClientData([New, New, New]) }","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:47:24.545144183Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1204}
6892023-10-13T04:47:32.426Z{"msg":"Sent repair work, now wait for resp","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:47:24.545161849Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1204}
6902023-10-13T04:47:32.441Z{"msg":"[2] received reconcile message","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:47:24.545178956Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1204}
6912023-10-13T04:47:32.454Z{"msg":"[2] rep_in_progress: return ReconcileIO { id: ReconciliationId(12), op: ExtentFlush { repair_id: ReconciliationId(12), extent_id: 4, client_id: ClientId(0), flush_number: 1931, gen_number: 28 }, state: ClientData([New, New, InProgress]) }","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:47:24.5452017Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1204,"":"downstairs"}
6922023-10-13T04:47:32.458Z{"msg":"[2] client ExtentFlush { repair_id: ReconciliationId(12), extent_id: 4, client_id: ClientId(0), flush_number: 1931, gen_number: 28 }","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:47:24.545224046Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1204}
6932023-10-13T04:47:32.464Z{"msg":"[1] received reconcile message","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:47:24.545241546Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1204}
6942023-10-13T04:47:32.469Z{"msg":"[0] received reconcile message","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:47:24.545258531Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1204}
6952023-10-13T04:47:32.474Z{"msg":"[1] rep_in_progress: return ReconcileIO { id: ReconciliationId(12), op: ExtentFlush { repair_id: ReconciliationId(12), extent_id: 4, client_id: ClientId(0), flush_number: 1931, gen_number: 28 }, state: ClientData([New, InProgress, Done]) }","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:47:24.545281227Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1204,"":"downstairs"}
6962023-10-13T04:47:32.479Z{"msg":"[1] client ExtentFlush { repair_id: ReconciliationId(12), extent_id: 4, client_id: ClientId(0), flush_number: 1931, gen_number: 28 }","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:47:24.545302106Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1204}
6972023-10-13T04:47:32.484Z{"msg":"[0] rep_in_progress: return ReconcileIO { id: ReconciliationId(12), op: ExtentFlush { repair_id: ReconciliationId(12), extent_id: 4, client_id: ClientId(0), flush_number: 1931, gen_number: 28 }, state: ClientData([InProgress, InProgress, Done]) }","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:47:24.545325321Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1204,"":"downstairs"}
6982023-10-13T04:47:32.490Z{"msg":"[0] client ExtentFlush { repair_id: ReconciliationId(12), extent_id: 4, client_id: ClientId(0), flush_number: 1931, gen_number: 28 }","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:47:24.545346167Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1204}
6992023-10-13T04:47:32.495Z{"msg":"Completion from [0] id:12 status:true","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:47:24.545363601Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1204}
7002023-10-13T04:47:32.499Z{"msg":"[13/20] Repair commands completed","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:47:24.545380908Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1204}
7012023-10-13T04:47:32.506Z{"msg":"Pop front: ReconcileIO { id: ReconciliationId(13), op: ExtentClose { repair_id: ReconciliationId(13), extent_id: 4 }, state: ClientData([New, New, New]) }","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:47:24.545401489Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1204}
7022023-10-13T04:47:32.511Z{"msg":"Sent repair work, now wait for resp","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:47:24.545419075Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1204}
7032023-10-13T04:47:32.514Z{Region: es:10 ec:5 bs:4096 ts:204800 tb:50 max_io:50 or 204800
7042023-10-13T04:47:32.937Z"msg":"[2] received reconcile message","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:47:27.64424825Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1204}
7052023-10-13T04:47:33.361Z{"msg":"[2] rep_in_progress: return ReconcileIO { id: ReconciliationId(13), op: ExtentClose { repair_id: ReconciliationId(13), extent_id: 4 }, state: ClientData([New, New, InProgress]) }","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:47:27.644306401Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1204,"":"downstairs"}
7062023-10-13T04:47:33.370Z{"msg":"[2] client ExtentClose { repair_id: ReconciliationId(13), extent_id: 4 }","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:47:27.644330535Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1204}
7072023-10-13T04:47:33.385Z{"msg":"[0] received reconcile message","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:47:27.644348792Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1204}
7082023-10-13T04:47:33.390Z{"msg":"[0] rep_in_progress: return ReconcileIO { id: ReconciliationId(13), op: ExtentClose { repair_id: ReconciliationId(13), extent_id: 4 }, state: ClientData([InProgress, New, InProgress]) }","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:47:27.644370172Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1204,"":"downstairs"}
7092023-10-13T04:47:33.398Z{"msg":"[1] received reconcile message","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:47:27.644388918Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1204}
7102023-10-13T04:47:33.404Z{"msg":"[1] rep_in_progress: return ReconcileIO { id: ReconciliationId(13), op: ExtentClose { repair_id: ReconciliationId(13), extent_id: 4 }, state: ClientData([InProgress, InProgress, InProgress]) }","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:47:27.644410352Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1204,"":"downstairs"}
7112023-10-13T04:47:33.411Z{"msg":"[0] client ExtentClose { repair_id: ReconciliationId(13), extent_id: 4 }","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:47:27.644429699Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1204}
7122023-10-13T04:47:33.417Z{"msg":"[1] client ExtentClose { repair_id: ReconciliationId(13), extent_id: 4 }","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:47:27.644447952Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1204}
7132023-10-13T04:47:33.426Z{"msg":"Completion from [1] id:13 status:true","v":0,"name":"crucible","level":30Loading write count information from file "/var/tmp/test_up/verify_file"
7142023-10-13T04:47:33.434Z,"time":"2023-10-13T04:47:27.644465755Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1204}
7152023-10-13T04:47:33.447Z{"msg":"[14/20] Repair commands completed","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:47:27.644490961Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1204}
7162023-10-13T04:47:33.460Z{"msg":"Pop front: ReconcileIO { id: ReconciliationId(14), op: ExtentRepair { repair_id: ReconciliationId(14), 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","Read and Verify all blocks (0..50 range:true)
7172023-10-13T04:47:33.470Zlevel":30,"time":"2023-10-13T04:47:27.644517756Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1204}
7182023-10-13T04:47:33.485Z{"msg":"Sent repair work, now wait for resp","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:47:27.644535726Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1204}
7192023-10-13T04:47:33.497Z{"msg":"[2] received reconcile message","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:47:27.644553233Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1204}
7202023-10-13T04:47:33.516Z{"msg":"[2] rep_in_progress: return ReconcileIO { id: ReconciliationId(14), op: ExtentRepair { repair_id: ReconciliationId(14), 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:47:27.644577014Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1204,"":"downstairs"}
7212023-10-13T04:47:33.542Z{"msg":"[2] client ExtentRepair { repair_id: ReconciliationId(14), 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:47:27.644600054Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1204}
7222023-10-13T04:47:33.567Z{"msg":"[2] Sending repair request ReconciliationId(14)","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:47:27.644618561Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1204}
7232023-10-13T04:47:33.585Z{"msg":"[0] received reconcile message","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:47:27.644635685Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1204}
7242023-10-13T04:47:33.596Z{"msg":"[0] rep_in_progress: return ReconcileIO { id: ReconciliationId(14), op: ExtentRepair { repair_id: ReconciliationId(14), 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:47:27.644659538Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1204,"":"downstairs"}
7252023-10-13T04:47:33.603Z{"msg":"[0] client ExtentRepair { repair_id: ReconciliationId(14), 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:47:27.644681937Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1204}
7262023-10-13T04:47:33.616Z{"msg":"[0] No action required ReconciliationId(14)","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:47:27.644699482Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1204}
7272023-10-13T04:47:33.622Z{"msg":"[1] received reconcile message","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:47:27.644716498Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1204}
7282023-10-13T04:47:33.637Z{"msg":"[1] rep_in_progress: return ReconcileIO { id: ReconciliationId(14), op: ExtentRepair { repair_id: ReconciliationId(14), extent_id: 4, source_client_id: ClientId(0), source_repair_address: 0.0.0.0:12810, dest_clients: [ClientId(1), ClientId(2)] }, state: ClientData([Done, InProgress, InProgress]) }","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:47:27.64474065Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1204,"":"downstairs"}
7292023-10-13T04:47:33.647Z{"msg":"[1] client ExtentRepair { repair_id: ReconciliationId(14), 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:47:27.644763035Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1204}
7302023-10-13T04:47:33.663Z{"msg":"[1] Sending repair request ReconciliationId(14)","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:47:27.644780809Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1204}
7312023-10-13T04:47:33.690Z{"msg":"Completion from [1] id:14 status:true","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:47:27.644798377Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1204}
7322023-10-13T04:47:33.763Z{"msg":"[15/20] Repair commands completed","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:47:27.644815602Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1204}
7332023-10-13T04:47:33.787Z{"msg":"Pop front: ReconcileIO { id: ReconciliationId(15), op: ExtentReopen { repair_id: ReconciliationId(15), extent_id: 4 }, state: ClientData([New, New, New]) }","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:47:27.644836381Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1204}
7342023-10-13T04:47:34.225Z{"msg":"Sent repair work, now wait for resp","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:47:27.644854211Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1204}
7352023-10-13T04:47:34.249Z{"msg":"[2] received reconcile message","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:47:27.644871468Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1204}
7362023-10-13T04:47:34.708Z{Wrote out file "/var/tmp/test_up/verify_file"
7372023-10-13T04:47:34.720Z"msg"Verify test completed
7382023-10-13T04:47:34.724Z:"[2] rep_in_progress: return ReconcileIO { id: ReconciliationId(15), op: ExtentReopen { repair_id: ReconciliationId(15), extent_id: 4 }, state: ClientData([New, New, InProgress]) }","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:47:30.862037022Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1204,"":"downstairs"}
7392023-10-13T04:47:34.728Z{"msg":"[2] client ExtentReopen { repair_id: ReconciliationId(15), extent_id: 4 }","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:47:30.862094508Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1204}
7402023-10-13T04:47:34.737Z{"msg":"[0] received reconcile message","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:47:30.862114451Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1204}
7412023-10-13T04:47:34.802Z
7422023-10-13T04:47:34.811Z{"msg":"[0] rep_in_progress: return ReconcileIO { id: ReconciliationId(15), op: ExtentReopen { repair_id: ReconciliationId(15), extent_id: 4 }, state: ClientData([InProgress, New, InProgress]) }","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:47:30.862136714Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1204,"":"downstairs"}
7432023-10-13T04:47:34.829Zreal 5:21.813120174
7442023-10-13T04:47:35.254Z{"msg":"[0] client ExtentReopen { repair_id: ReconciliationId(15), extent_id: 4 }","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:47:30.86215677Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1204}
7452023-10-13T04:47:35.264Zuser 4:28.846115850
7462023-10-13T04:47:35.280Z{"msg":"[1] received reconcile message","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:47:30.862174895Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1204}
7472023-10-13T04:47:35.289Zsys 22.385251211
7482023-10-13T04:47:35.311Z{"msg":"[1] rep_in_progress: return ReconcileIO { id: ReconciliationId(15), op: ExtentReopen { repair_id: ReconciliationId(15), extent_id: 4 }, state: ClientData([InProgress, InProgress, Done]) }","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:47:30.862196364Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1204,"":"downstairs"}
7492023-10-13T04:47:35.330Ztrap 0.345118113
7502023-10-13T04:47:35.360Z{"msg":"[1] client ExtentReopen { repair_id: ReconciliationId(15), extent_id: 4 }","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:47:30.862215654Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1204}
7512023-10-13T04:47:35.371Ztflt 0.146682950
7522023-10-13T04:47:35.393Z{"msg":"Completion from [1] id:15 status:true","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:47:30.862233301Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1204}
7532023-10-13T04:47:35.408Zdflt 0.045029970
7542023-10-13T04:47:35.465Z{"msg":"[16/20] Repair commands completed","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:47:30.86225043Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1204}
7552023-10-13T04:47:35.497Zkflt 0.002912415
7562023-10-13T04:47:35.521Z{"msg":"Pop front: ReconcileIO { id: ReconciliationId(16), op: ExtentFlush { repair_id: ReconciliationId(16), extent_id: 3, client_id: ClientId(0), flush_number: 1931, gen_number: 28 }, state: ClientData([New, New, New]) }","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:47:30.862272342Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1204}
7572023-10-13T04:47:35.533Zlock 49:30.588285364
7582023-10-13T04:47:35.543Z{"msg":"Wrote out file "/var/tmp/test_up/verify_file"
7592023-10-13T04:47:35.556Zslp 10:16.161028785
7602023-10-13T04:47:35.562ZSent repair work, now wait for resp"CLIENT: Tests done. All submitted work has been ACK'd
7612023-10-13T04:47:35.570Zlat 18.089575979
7622023-10-13T04:47:35.580Z,"v":0,"name":"crucible","level":30,"time":"2023-10-13T04:47:30.862295092Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1204}
7632023-10-13T04:47:35.589Zstop 0.034690190
7642023-10-13T04:47:35.604Z{"msg":"[2] received reconcile message","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:47:30.8623123Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1204}
7652023-10-13T04:47:36.024Z{"msg":"[2] rep_in_progress: return ReconcileIO { id: ReconciliationId(16), op: ExtentFlush { repair_id: ReconciliationId(16), extent_id: 3, client_id: ClientId(0), flush_number: 1931, gen_number: 28 }, state: ClientData([New, New, InProgress]) }","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:47:30.862335374Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1204,"":"downstairs"}
7662023-10-13T04:47:36.030Z{"msg":"[2] client ExtentFlush { repair_id: ReconciliationId(16), extent_id: 3, client_id: ClientId(0), flush_number: 1931, gen_number: 28 }","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:47:30.862356827Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1204}
7672023-10-13T04:47:36.035Z{"msg":"[1] received reconcile message","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:47:30.862374801Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1204}
7682023-10-13T04:47:36.465Z{"msg":"[0] received reconcile message","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:47:30.862391994Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1204}
7692023-10-13T04:47:36.487Z{"msg":"[1] rep_in_progress: return ReconcileIO { id: ReconciliationId(16), op: ExtentFlush { repair_id: ReconciliationId(16), extent_id: 3, client_id: ClientId(0), flush_number: 1931, gen_number: 28 }, state: ClientData([New, InProgress, Done]) }","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:47:30.862414215Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1204,"":"downstairs"}
7702023-10-13T04:47:36.939Z{"msg":"[1] client ExtentFlush { repair_id: ReconciliationId(16), extent_id: 3, client_id: ClientId(0), flush_number: 1931, gen_number: 28 }","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:47:30.862435505Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1204}
7712023-10-13T04:47:37.764Z{"msg":"[0] rep_in_progress: return ReconcileIO { id: ReconciliationId(16), op: ExtentFlush { repair_id: ReconciliationId(16), extent_id: 3, client_id: ClientId(0), flush_number: 1931, gen_number: 28 }, state: ClientData([InProgress, InProgress, Done]) }","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:47:30.862458723Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1204,"":"downstairs"}
7722023-10-13T04:47:38.188Z{"msg":"[0] client ExtentFlush { repair_id: ReconciliationId(16), extent_id: 3, client_id: ClientId(0), flush_number: 1931, gen_number: 28 }","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:47:30.862480105Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1204}
7732023-10-13T04:47:38.200Z{"msg":"Completion from [0] id:16 status:true","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:47:30.862497817Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1204}
7742023-10-13T04:47:38.207Z{"msg":"[17/20] Repair commands completed","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:47:30.862514956Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1204}
7752023-10-13T04:47:38.215Z{"msg":"----------------------------------------------------------------
7762023-10-13T04:47:38.226ZPop front: ReconcileIO { id: ReconciliationId(17), op: ExtentClose { repair_id: ReconciliationId(17), extent_id: 3 }, state: ClientData([New, New, New]) }"," Crucible gen:28 GIO:true work queues: Upstairs:0 downstairs:0
7772023-10-13T04:47:38.242Zv":0,"name":"crucible","level":30,"time":"2023-10-13T04:47:30.862541015Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1204}
7782023-10-13T04:47:38.259ZDownstairs last five completed:{"msg":"Sent repair work, now wait for resp","v":0,"name":" 1001crucible" 1000,"
7792023-10-13T04:47:38.269Zlevel":30,"time":"2023-10-13T04:47:30.862562933Z","hostname":"Upstairs last five completed: ip-10-150-1-242.us-west-2.compute.internal","pid":1204}
7802023-10-13T04:47:38.278Z{"msg":"[2] received reconcile message","v":0,"name":"crucible","level":30 2 1
7812023-10-13T04:47:38.295Z,"time":"2023-10-13T04:47:30.862581482Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1204}
7822023-10-13T04:47:38.303Z{"msg":"[2] rep_in_progress: return ReconcileIO { id: ReconciliationId(17), op: ExtentClose { repair_id: ReconciliationId(17), extent_id: 3 }, state: ClientData([New, New, InProgress]) }","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:47:30.862603636Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1204,"":"downstairs"}
7832023-10-13T04:47:38.318Z{"msg":"[2] client ExtentClose { repair_id: ReconciliationId(17), extent_id: 3 }","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:47:30.862623583Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1204}
7842023-10-13T04:47:39.293Z{"msg":"[0] received reconcile message","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:47:30.862641394Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1204}
7852023-10-13T04:47:39.301Z{"msg":"CLIENT: Up:0 ds:0 act:3
7862023-10-13T04:47:39.317Z[0] rep_in_progress: return ReconcileIO { id: ReconciliationId(17), op: ExtentClose { repair_id: ReconciliationId(17), extent_id: 3 }, state: ClientData([InProgress, New, InProgress]) }"CLIENT: All crucible jobs finished, exiting program
7872023-10-13T04:47:39.334Z,"v":0,"name":"crucible","level":30,"time":"2023-10-13T04:47:31.075406032Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1204,"":"downstairs"}
7882023-10-13T04:47:39.348Z{"msg":"[0] client ExtentClose { repair_id: ReconciliationId(17), extent_id: 3 }","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:47:31.075480702Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1204}
7892023-10-13T04:47:39.369Z{"msg":"[1] received reconcile message","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:47:31.075501037Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1204}
7902023-10-13T04:47:39.390Z{"msg":"[1] rep_in_progress: return ReconcileIO { id: ReconciliationId(17), op: ExtentClose { repair_id: ReconciliationId(17), extent_id: 3 }, state: ClientData([InProgress, InProgress, InProgress]) }","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:47:31.075523097Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1204,"":"downstairs"}
7912023-10-13T04:47:39.816Z{"msg":"[1] client ExtentClose { repair_id: ReconciliationId(17), extent_id: 3 }","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:47:31.075543584Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1204}
7922023-10-13T04:47:39.830Z{"msg":"Completion from [1] id:17 status:true","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:47:31.075566099Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1204}
7932023-10-13T04:47:39.854Z{"msg":"[18/20] Repair commands completed","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:47:31.075597501Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1204}
7942023-10-13T04:47:39.871Z{"msg":"Pop front: ReconcileIO { id: ReconciliationId(18), op: ExtentRepair { repair_id: ReconciliationId(18), 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:47:31.075642065Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1204}
7952023-10-13T04:47:39.886Z{"msg":"Sent repair work, now wait for resp","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:47:31.075678557Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1204}
7962023-10-13T04:47:39.935Z{"msg":"[2] received reconcile message","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:47:31.075713149Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1204}
7972023-10-13T04:47:39.947Z{"msg":"[2] rep_in_progress: return ReconcileIO { id: ReconciliationId(18), op: ExtentRepair { repair_id: ReconciliationId(18), 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:47:31.075758845Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1204,"":"downstairs"}
7982023-10-13T04:47:39.960Z{"msg":"[2] client ExtentRepair { repair_id: ReconciliationId(18), 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:47:31.075803924Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1204}
7992023-10-13T04:47:39.969Z{"msg":"[2] Sending repair request ReconciliationId(18)","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:47:31.075839568Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1204}
8002023-10-13T04:47:39.979Z{"msg":"[0] received reconcile message","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:47:31.075871178Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1204}
8012023-10-13T04:47:39.992Z{"msg":"[0] rep_in_progress: return ReconcileIO { id: ReconciliationId(18), op: ExtentRepair { repair_id: ReconciliationId(18), 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:47:31.075910438Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1204,"":"downstairs"}
8022023-10-13T04:47:40.056Z{"msg":"[1] received reconcile message","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:47:31.075943174Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1204}
8032023-10-13T04:47:40.072Z{"msg":"[0] client ExtentRepair { repair_id: ReconciliationId(18), 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:47:31.075980966Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1204}
8042023-10-13T04:47:40.086Z{"msg":"[0] No action required ReconciliationId(18)","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:47:31.076014472Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1204}
8052023-10-13T04:47:40.090Z{"msg":"[1] rep_in_progress: return ReconcileIO { id: ReconciliationId(18), op: ExtentRepair { repair_id: ReconciliationId(18), 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, InProgress, InProgress]) }","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:47:31.076055701Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1204,"":"downstairs"}
8062023-10-13T04:47:40.095Z{"msg":"[1] client ExtentRepair { repair_id: ReconciliationId(18), 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:47:31.076101417Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1204}
8072023-10-13T04:47:40.101Z{"msg":"[1] Sending repair request ReconciliationId(18)","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:47:31.076196062Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1204}
8082023-10-13T04:47:40.104Z{"msg":"Completion from [1] id:18 status:true","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:47:31.076220186Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1204}
8092023-10-13T04:47:40.108Z{"msg":"[19/20] Repair commands completed","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:47:31.076237968Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1204}
8102023-10-13T04:47:40.114Z{"msg":"Pop front: ReconcileIO { id: ReconciliationId(19), op: ExtentReopen { repair_id: ReconciliationId(19), extent_id: 3 }, state: ClientData([New, New, New]) }","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:47:31.076259223Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1204}
8112023-10-13T04:47:40.119Z{"msg":"Sent repair work, now wait for resp","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:47:31.076277542Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1204}
8122023-10-13T04:47:40.122Z{"msg":"[2] received reconcile message","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:47:31.076295283Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1204}
8132023-10-13T04:47:40.125Z{"msg":"[2] rep_in_progress: return ReconcileIO { id: ReconciliationId(19), op: ExtentReopen { repair_id: ReconciliationId(19), extent_id: 3 }, state: ClientData([New, New, InProgress]) }","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:47:31.076316779Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1204,"":"downstairs"}
8142023-10-13T04:47:40.128Z{"msg":"[2] client ExtentReopen { repair_id: ReconciliationId(19), extent_id: 3 }","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:47:31.076337043Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1204}
8152023-10-13T04:47:40.131Z{"msg":"[0] received reconcile message","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:47:31.076354477Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1204}
8162023-10-13T04:47:40.135Z{"msg":"[0] rep_in_progress: return ReconcileIO { id: ReconciliationId(19), op: ExtentReopen { repair_id: ReconciliationId(19), extent_id: 3 }, state: ClientData([InProgress, New, InProgress]) }","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:47:31.076376063Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1204,"":"downstairs"}
8172023-10-13T04:47:40.138Z{"msg":"[0] client ExtentReopen { repair_id: ReconciliationId(19), extent_id: 3 }","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:47:31.07639583Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1204}
8182023-10-13T04:47:40.142Z{"msg":"[1] received reconcile message","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:47:31.07641373Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1204}
8192023-10-13T04:47:40.145Z{"msg":"[1] rep_in_progress: return ReconcileIO { id: ReconciliationId(19), op: ExtentReopen { repair_id: ReconciliationId(19), extent_id: 3 }, state: ClientData([InProgress, InProgress, InProgress]) }","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:47:31.436207725Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1204,"":"downstairs"}
8202023-10-13T04:47:40.148Z{"msg":"[1] client ExtentReopen { repair_id: ReconciliationId(19), extent_id: 3 }","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:47:31.436265435Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1204}
8212023-10-13T04:47:40.151Z{"msg":"Completion from [1] id:19 status:true","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:47:31.436284819Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1204}
8222023-10-13T04:47:40.157Z{"msg":"[20/20] Repair commands completed","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:47:31.436302411Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1204}
8232023-10-13T04:47:40.161Z{"msg":"5 extents repaired in 7.392 ave:1.4785","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:47:31.436320108Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1204}
8242023-10-13T04:47:40.164Z{"msg":"All required repair work is completed","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:47:31.436337306Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1204}
8252023-10-13T04:47:40.170Z{"msg":"Set Downstairs and Upstairs active after repairs","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:47:31.436354691Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1204}
8262023-10-13T04:47:40.176Z{"msg":"f58152dd-3142-45dc-8d0d-61caea3d878b is now active with session: 742a6a92-7e50-4ceb-9065-7a5b381dcb08","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:47:31.436374049Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1204}
8272023-10-13T04:47:40.182Z{"msg":"Notify all downstairs, region set compare is done.","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:47:31.436392164Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1204}
8282023-10-13T04:47:40.186Z{"msg":"Set check for repair","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:47:31.436408954Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1204}
8292023-10-13T04:47:40.193Z{"msg":"[0] received reconcile message","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:47:31.436426075Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1204}
8302023-10-13T04:47:40.201Z{"msg":"[0] All repairs completed, exit","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:47:31.436443038Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1204}
8312023-10-13T04:47:40.220Z{"msg":"[0] Starts cmd_loop","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:47:31.436459701Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1204}
8322023-10-13T04:47:40.226Z{"msg":"[1] received reconcile message","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:47:31.436476714Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1204}
8332023-10-13T04:47:40.231Z{"msg":"[1] All repairs completed, exit","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:47:31.436493601Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1204}
8342023-10-13T04:47:40.236Z{"msg":"[1] Starts cmd_loop","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:47:31.436510332Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1204}
8352023-10-13T04:47:40.243Zprocess exited: duration 334329 ms, exit code 0
8362023-10-13T04:47:40.251Z{"msg":"[2] received reconcile message","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:47:31.436527377Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1204}
8372023-10-13T04:47:40.260Zexec warning: stdio descriptors remain open after task exit; waiting 60 seconds for them to close
8382023-10-13T04:47:40.271Z{"msg":"[2] All repairs completed, exit","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:47:31.436544187Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1204}
8392023-10-13T04:47:40.291Z{"msg":"[2] Starts cmd_loop","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:47:31.436561413Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1204}
8402023-10-13T04:47:40.311Z{"msg":"Checking if live repair is needed","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:47:31.436578797Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1204}
8412023-10-13T04:47:40.344Z{"msg":"No Live Repair required at this time","v":0,"name":"crucible","level":30,"time":"2023-10-13T04:47:31.436596169Z","hostname":"ip-10-150-1-242.us-west-2.compute.internal","pid":1204}
8422023-10-13T04:47:40.361ZRepair part 2 passed
8432023-10-13T04:47:40.382Z/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
8442023-10-13T04:47:40.403ZEXT BLOCKS GEN0 GEN1 GEN2 FL0 FL1 FL2 D0 D1 D2 DIFF
8452023-10-13T04:47:40.844Z 0 000-009 28 28 28 1931 1931 1931 F F F
8462023-10-13T04:47:40.858Z 1 010-019 27 27 27 1930 1930 1930 F F F
8472023-10-13T04:47:40.881Z 2 020-029 27 27 27 1930 1930 1930 F F F
8482023-10-13T04:47:40.892Z 3 030-039 28 28 28 1931 1931 1931 F F F
8492023-10-13T04:47:40.904Z 4 040-049 28 28 28 1931 1931 1931 F F F
8502023-10-13T04:47:41.023ZMax gen: 28, Max flush: 1931
8512023-10-13T04:47:41.175Zdump test passed
8522023-10-13T04:47:44.652Z/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
8532023-10-13T04:47:45.121Z Extent 1
8542023-10-13T04:47:45.748ZGEN 27 27 27
8552023-10-13T04:47:45.780ZFLUSH_ID 1930 1930 1930
8562023-10-13T04:47:45.808ZDIRTY
8572023-10-13T04:47:45.823Z
8582023-10-13T04:47:45.836ZBLOCK D0 D1 D2 C0 C1 C2 DIFF
8592023-10-13T04:47:45.855Z010 A A A A A A
8602023-10-13T04:47:45.873Z011 A A A A A A
8612023-10-13T04:47:45.880Z012 A A A A A A
8622023-10-13T04:47:45.890Z013 A A A A A A
8632023-10-13T04:47:45.899Z014 A A A A A A
8642023-10-13T04:47:45.907Z015 A A A A A A
8652023-10-13T04:47:45.919Z016 A A A A A A
8662023-10-13T04:47:45.926Z017 A A A A A A
8672023-10-13T04:47:45.932Z018 A A A A A A
8682023-10-13T04:47:45.938Z019 A A A A A A
8692023-10-13T04:47:45.945Zdump extent test passed
8702023-10-13T04:47:45.959Z/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
8712023-10-13T04:47:45.968ZExtent 2 Block in extent 0 Actual block 20
8722023-10-13T04:47:45.978Z
8732023-10-13T04:47:45.993Z DATA SHA256 VER
8742023-10-13T04:47:46.008Z------ ---------------------------------------------------------------- ---
8752023-10-13T04:47:46.040Z 0 f99638aea0e8846541bb749044cbda0582e364c05760b2d7099b401b1cc17900 A
8762023-10-13T04:47:46.060Z 1 f99638aea0e8846541bb749044cbda0582e364c05760b2d7099b401b1cc17900 A
8772023-10-13T04:47:46.086Z 2 f99638aea0e8846541bb749044cbda0582e364c05760b2d7099b401b1cc17900 A
8782023-10-13T04:47:46.142Z
8792023-10-13T04:47:46.163ZNONCES 0 1 2 DIFF
8802023-10-13T04:47:46.181Z------ ------------------------ ------------------------ ------------------------ -----
8812023-10-13T04:47:46.619Z 0 f745603074bfa60f017b9c50 f745603074bfa60f017b9c50 f745603074bfa60f017b9c50
8822023-10-13T04:47:46.652Z
8832023-10-13T04:47:47.082Z TAGS 0 1 2 DIFF
8842023-10-13T04:47:47.103Z------ -------------------------------- -------------------------------- -------------------------------- -----
8852023-10-13T04:47:47.125Z 0 e1ff1f472d53c465a216391a10ba7df3 e1ff1f472d53c465a216391a10ba7df3 e1ff1f472d53c465a216391a10ba7df3
8862023-10-13T04:47:47.550Z
8872023-10-13T04:47:47.561ZHASHES 0 1 2 DIFF
8882023-10-13T04:47:47.574Z------ ---------------- ---------------- ---------------- -----
8892023-10-13T04:47:47.588Z 0 0a804697888746d4 0a804697888746d4 0a804697888746d4
8902023-10-13T04:47:47.603Z
8912023-10-13T04:47:47.619Zdump block test passed
8922023-10-13T04:47:47.640ZUpstairs tests have completed, stopping all downstairs
8932023-10-13T04:47:48.070Z
8942023-10-13T04:47:48.520ZAll Tests have passed
8952023-10-13T04:47:48.543Z5:22 Test duration
 
8962023-10-13T04:47:48.597Zfound 5 output files
8972023-10-13T04:47:48.651Zuploading: /tmp/test_up/dsc-out.txt (4483 bytes)
8982023-10-13T04:47:50.200Zuploaded: /tmp/test_up/dsc-out.txt
8992023-10-13T04:47:50.228Zuploading: /tmp/test_up/test_up_out.txt (3442653 bytes)
9002023-10-13T04:47:54.923Zuploaded: /tmp/test_up/test_up_out.txt
9012023-10-13T04:47:54.933Zuploading: /tmp/test_up/dsc/downstairs-8810.txt (66966 bytes)
9022023-10-13T04:47:55.967Zuploaded: /tmp/test_up/dsc/downstairs-8810.txt
9032023-10-13T04:47:55.976Zuploading: /tmp/test_up/dsc/downstairs-8820.txt (59635 bytes)
9042023-10-13T04:47:57.096Zuploaded: /tmp/test_up/dsc/downstairs-8820.txt
9052023-10-13T04:47:57.109Zuploading: /tmp/test_up/dsc/downstairs-8830.txt (10996 bytes)
9062023-10-13T04:48:00.181Zuploaded: /tmp/test_up/dsc/downstairs-8830.txt