01H7EZ4CSYDDPVSZT1P9VDJ6HF: test-up-encrypted

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

Buildomat Job: 01H7EZ4NX6Y3CEYCDF2S3EVQ4M

Tags:

Artefacts:

Output:

SEQ GLOBAL TIME DETAILS
12023-08-10T05:59:03.690Zjob dependencies complete; ready to run (waiting for 22 m 29 s)
22023-08-10T06:00:23.830Zjob assigned to worker 01H7F0E7GTC8H88H6D0K5G3VSY (queued for 1 m 20 s)
32023-08-10T06:00:24.029Zdownloading input: /input/build/work/bins/crucible-downstairs.gz
42023-08-10T06:00:37.865Zdownloaded input: /input/build/work/bins/crucible-downstairs.gz
52023-08-10T06:00:37.879Zdownloading input: /input/build/work/bins/crucible-hammer.gz
62023-08-10T06:00:48.742Zdownloaded input: /input/build/work/bins/crucible-hammer.gz
72023-08-10T06:00:48.758Zdownloading input: /input/build/work/bins/crutest.gz
82023-08-10T06:01:02.234Zdownloaded input: /input/build/work/bins/crutest.gz
92023-08-10T06:01:02.238Zdownloading input: /input/build/work/bins/dsc.gz
102023-08-10T06:01:09.326Zdownloaded input: /input/build/work/bins/dsc.gz
112023-08-10T06:01:09.329Zdownloading input: /input/build/work/scripts/test_ds.sh
122023-08-10T06:01:09.341Zdownloaded input: /input/build/work/scripts/test_ds.sh
132023-08-10T06:01:09.344Zdownloading input: /input/build/work/scripts/test_live_repair.sh
142023-08-10T06:01:09.357Zdownloaded input: /input/build/work/scripts/test_live_repair.sh
152023-08-10T06:01:09.360Zdownloading input: /input/build/work/scripts/test_repair.sh
162023-08-10T06:01:09.375Zdownloaded input: /input/build/work/scripts/test_repair.sh
172023-08-10T06:01:09.378Zdownloading input: /input/build/work/scripts/test_up.sh
182023-08-10T06:01:09.393Zdownloaded input: /input/build/work/scripts/test_up.sh
192023-08-10T06:01:09.397Zdownloading input: /input/build/tmp/cargo-test-out.log
202023-08-10T06:01:10.321Zdownloaded input: /input/build/tmp/cargo-test-out.log
 
212023-08-10T06:01:10.325Zstarting task 0: "setup"
222023-08-10T06:01:10.459Z++ uname -s
232023-08-10T06:01:10.462Z+ kern=SunOS
242023-08-10T06:01:10.465Z+ case "$kern" in
252023-08-10T06:01:10.468Z+ groupadd -g 12345 build
262023-08-10T06:01:10.471Z+ useradd -u 12345 -g build -d /home/build -s /bin/bash -c build -P 'Primary Administrator' build
272023-08-10T06:01:12.477Z+ zfs create -o mountpoint=/work rpool/work
282023-08-10T06:01:14.106Z++ awk '$2 == "/home" { print $3 }' /etc/mnttab
292023-08-10T06:01:14.110Z+ home_fs=zfs
302023-08-10T06:01:14.112Z+ [[ zfs == autofs ]]
312023-08-10T06:01:14.115Z+ mkdir -p /home/build
322023-08-10T06:01:14.118Z+ chown build:build /home/build /work
332023-08-10T06:01:14.121Z+ chmod 0700 /home/build /work
342023-08-10T06:01:14.124Zprocess exited: duration 3791 ms, exit code 0
 
352023-08-10T06:01:14.130Zstarting task 1: "authentication"
362023-08-10T06:01:14.159Zprocess exited: duration 25 ms, exit code 0
 
372023-08-10T06:01:14.165Zstarting task 2: "build"
382023-08-10T06:01:14.175Z+ echo 'input bins dir contains:'
392023-08-10T06:01:14.178Zinput bins dir contains:
402023-08-10T06:01:14.180Z+ ls -ltr /input/build/work/bins
412023-08-10T06:01:14.183Ztotal 673744
422023-08-10T06:01:14.186Z-rw-r--r-- 1 root root 108899860 Aug 10 06:00 crucible-downstairs.gz
432023-08-10T06:01:14.189Z-rw-r--r-- 1 root root 69594543 Aug 10 06:00 crucible-hammer.gz
442023-08-10T06:01:14.192Z-rw-r--r-- 1 root root 97531181 Aug 10 06:01 crutest.gz
452023-08-10T06:01:14.195Z-rw-r--r-- 1 root root 68703972 Aug 10 06:01 dsc.gz
462023-08-10T06:01:14.198Z+ banner unpack
472023-08-10T06:01:14.241Z
482023-08-10T06:01:14.244Z # # # # ##### ## #### # #
492023-08-10T06:01:14.248Z # # ## # # # # # # # # #
502023-08-10T06:01:14.251Z # # # # # # # # # # ####
512023-08-10T06:01:14.253Z # # # # # ##### ###### # # #
522023-08-10T06:01:14.256Z # # # ## # # # # # # #
532023-08-10T06:01:14.259Z #### # # # # # #### # #
542023-08-10T06:01:14.262Z
552023-08-10T06:01:14.265Z+ mkdir -p /var/tmp/bins
562023-08-10T06:01:14.268Z+ for t in "$input/bins/"*.gz
572023-08-10T06:01:14.271Z++ basename /input/build/work/bins/crucible-downstairs.gz
582023-08-10T06:01:14.273Z+ b=crucible-downstairs.gz
592023-08-10T06:01:14.276Z+ b=crucible-downstairs
602023-08-10T06:01:14.279Z+ gunzip
612023-08-10T06:01:18.055Z+ chmod +x /var/tmp/bins/crucible-downstairs
622023-08-10T06:01:18.058Z+ for t in "$input/bins/"*.gz
632023-08-10T06:01:18.061Z++ basename /input/build/work/bins/crucible-hammer.gz
642023-08-10T06:01:18.063Z+ b=crucible-hammer.gz
652023-08-10T06:01:18.066Z+ b=crucible-hammer
662023-08-10T06:01:18.069Z+ gunzip
672023-08-10T06:01:20.527Z+ chmod +x /var/tmp/bins/crucible-hammer
682023-08-10T06:01:20.530Z+ for t in "$input/bins/"*.gz
692023-08-10T06:01:20.533Z++ basename /input/build/work/bins/crutest.gz
702023-08-10T06:01:20.536Z+ b=crutest.gz
712023-08-10T06:01:20.539Z+ b=crutest
722023-08-10T06:01:20.542Z+ gunzip
732023-08-10T06:01:23.861Z+ chmod +x /var/tmp/bins/crutest
742023-08-10T06:01:23.864Z+ for t in "$input/bins/"*.gz
752023-08-10T06:01:23.867Z++ basename /input/build/work/bins/dsc.gz
762023-08-10T06:01:23.869Z+ b=dsc.gz
772023-08-10T06:01:23.872Z+ b=dsc
782023-08-10T06:01:23.875Z+ gunzip
792023-08-10T06:01:26.263Z+ chmod +x /var/tmp/bins/dsc
802023-08-10T06:01:26.266Z+ export BINDIR=/var/tmp/bins
812023-08-10T06:01:26.269Z+ BINDIR=/var/tmp/bins
822023-08-10T06:01:26.272Z+ banner test_up_encrypted
832023-08-10T06:01:26.275Z
842023-08-10T06:01:26.278Z ##### ###### #### ##### # # ##### ###### # #
852023-08-10T06:01:26.281Z # # # # # # # # # ## #
862023-08-10T06:01:26.284Z # ##### #### # # # # # ##### # # #
872023-08-10T06:01:26.287Z # # # # # # ##### # # # #
882023-08-10T06:01:26.290Z # # # # # # # # # # ##
892023-08-10T06:01:26.293Z # ###### #### # ####### #### # ####### ###### # #
902023-08-10T06:01:26.296Z
912023-08-10T06:01:26.299Z+ ptime -m bash /input/build/work/scripts/test_up.sh -N encrypted
922023-08-10T06:01:26.302Z/input/build/work
932023-08-10T06:01:26.304ZTurn off color for downstairs dump
942023-08-10T06:01:26.459ZUpstairs using key: uUNQZMLN6+7Z1bxrX+G3ctqq/MPXkUp3G36OWVCYmCQ=
952023-08-10T06:01:26.462Zdsc output goes to /tmp/test_up/dsc-out.txt
962023-08-10T06:01:26.465ZCreating three downstairs regions
972023-08-10T06:01:26.876ZStarting three downstairs
982023-08-10T06:01:31.883ZDisable automatic restart on all downstairs
992023-08-10T06:01:31.999Z
1002023-08-10T06:01:32.002ZBegin tests, output goes to /tmp/test_up/test_up_out.txt
1012023-08-10T06:01:32.005ZRunning test: span
1022023-08-10T06:01:36.159ZCompleted test: span
1032023-08-10T06:01:36.163ZRunning test: big
1042023-08-10T06:01:40.923ZCompleted test: big
1052023-08-10T06:01:40.927ZRunning test: dep
1062023-08-10T06:03:33.132ZCompleted test: dep
1072023-08-10T06:03:33.136ZRunning test: balloon
1082023-08-10T06:06:03.295ZCompleted test: balloon
1092023-08-10T06:06:03.299ZRunning test: deactivate
1102023-08-10T06:06:28.655ZCompleted test: deactivate
1112023-08-10T06:06:28.660ZRunning hammer
1122023-08-10T06:06:57.145ZRun repair tests
1132023-08-10T06:06:57.149Z/var/tmp/bins/crutest fill -g 26 -q --key uUNQZMLN6+7Z1bxrX+G3ctqq/MPXkUp3G36OWVCYmCQ= -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
1142023-08-10T06:06:57.170Z{"msg":"Upstairs starts","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:06:57.279369693Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1188}
1152023-08-10T06:06:57.175Z{"msg":"Crucible Version: BuildInfo {\n version: \"0.0.1\",\n git_sha: \"9f9f88bb1717d2b86fef41798471b705ff437b87\",\n git_commit_timestamp: \"2023-08-10T05:35:49.000000000Z\",\n git_branch: \"alan/wip-for-vcr\",\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-08-10T06:06:57.279786503Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1188}
1162023-08-10T06:06:57.177Z{"msg":"Upstairs <-> Downstairs Message Version: 4","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:06:57.279838765Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1188}
1172023-08-10T06:06:57.180Z{"msg":"Crucible stats registered with UUID: 88c1d1d4-5443-42be-8500-ffdf9afad768","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:06:57.279862822Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1188}
1182023-08-10T06:06:57.183Z{"msg":"Crucible 88c1d1d4-5443-42be-8500-ffdf9afad768 has session id: 84247556-58be-425d-8f7a-6366880ae9d4","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:06:57.27988502Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1188}
1192023-08-10T06:06:57.185ZCrucible runtime is spawned
1202023-08-10T06:06:57.188ZThe guest has requested activation with gen:26
1212023-08-10T06:06:57.191Z{"msg":"up_listen starts","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:06:57.280461839Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1188,"task":"up_listen"}
1222023-08-10T06:06:57.193Z{"msg":"Wait for all three downstairs to come online","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:06:57.280542577Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1188}
1232023-08-10T06:06:57.196Z{"msg":"Flush timeout: 0.5","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:06:57.280607651Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1188}
1242023-08-10T06:06:57.199Z{"msg":"[1] connecting to 127.0.0.1:8820","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:06:57.28067326Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1188,"looper":"1"}
1252023-08-10T06:06:57.201Z{"msg":"[0] connecting to 127.0.0.1:8810","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:06:57.280878462Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1188,"looper":"0"}
1262023-08-10T06:06:57.204Z{"msg":"[1] 88c1d1d4-5443-42be-8500-ffdf9afad768 looper connected","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:06:57.280970223Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1188,"looper":"1"}
1272023-08-10T06:06:57.207Z{"msg":"[2] connecting to 127.0.0.1:8830","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:06:57.281034716Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1188,"looper":"2"}
1282023-08-10T06:06:57.210Z{"msg":"[0] 88c1d1d4-5443-42be-8500-ffdf9afad768 looper connected","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:06:57.281100201Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1188,"looper":"0"}
1292023-08-10T06:06:57.213Z{"msg":"[2] 88c1d1d4-5443-42be-8500-ffdf9afad768 looper connected","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:06:57.281199587Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1188,"looper":"2"}
1302023-08-10T06:06:57.216Z{"msg":"88c1d1d4-5443-42be-8500-ffdf9afad768 active request set","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:06:57.281661949Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1188}
1312023-08-10T06:06:57.218Z{"msg":"Set desired generation to :26","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:06:57.281731974Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1188}
1322023-08-10T06:06:57.221Z{"msg":"[1] Proc runs for 127.0.0.1:8820 in state New","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:06:57.281922284Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1188}
1332023-08-10T06:06:57.224Z{"msg":"[0] Proc runs for 127.0.0.1:8810 in state New","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:06:57.282209537Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1188}
1342023-08-10T06:06:57.226Z{"msg":"[2] Proc runs for 127.0.0.1:8830 in state New","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:06:57.282261754Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1188}
1352023-08-10T06:06:57.229Z{"msg":"[1] 88c1d1d4-5443-42be-8500-ffdf9afad768 (56c24d0d-910f-48eb-a997-1aae37399f7c) New New New ds_transition to WaitActive","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:06:57.282565737Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1188}
1362023-08-10T06:06:57.232Z{"msg":"[1] Transition from New to WaitActive","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:06:57.282630805Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1188}
1372023-08-10T06:06:57.234Z{"msg":"[1] client is_active_req TRUE, promote! session 56c24d0d-910f-48eb-a997-1aae37399f7c","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:06:57.282678787Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1188}
1382023-08-10T06:06:57.237Z{"msg":"[2] 88c1d1d4-5443-42be-8500-ffdf9afad768 (56c24d0d-910f-48eb-a997-1aae37399f7c) New WaitActive New ds_transition to WaitActive","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:06:57.282796775Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1188}
1392023-08-10T06:06:57.240Z{"msg":"[2] Transition from New to WaitActive","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:06:57.282939208Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1188}
1402023-08-10T06:06:57.243Z{"msg":"[2] client is_active_req TRUE, promote! session 56c24d0d-910f-48eb-a997-1aae37399f7c","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:06:57.283017809Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1188}
1412023-08-10T06:06:57.245Z{"msg":"[0] 88c1d1d4-5443-42be-8500-ffdf9afad768 (56c24d0d-910f-48eb-a997-1aae37399f7c) New WaitActive WaitActive ds_transition to WaitActive","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:06:57.283092748Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1188}
1422023-08-10T06:06:57.248Z{"msg":"[0] Transition from New to WaitActive","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:06:57.283168046Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1188}
1432023-08-10T06:06:57.251Z{"msg":"[0] client is_active_req TRUE, promote! session 56c24d0d-910f-48eb-a997-1aae37399f7c","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:06:57.283245627Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1188}
1442023-08-10T06:06:57.254Z{"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-08-10T06:06:57.283496072Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1188}
1452023-08-10T06:06:57.257Z{"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-08-10T06:06:57.283564125Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1188}
1462023-08-10T06:06:57.260Z{"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-08-10T06:06:57.283616443Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1188}
1472023-08-10T06:06:57.262Z{"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-08-10T06:06:57.283667077Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1188}
1482023-08-10T06:06:57.265Z{"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-08-10T06:06:57.283722551Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1188}
1492023-08-10T06:06:57.268Z{"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-08-10T06:06:57.283748965Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1188}
1502023-08-10T06:06:57.270Z{"msg":"88c1d1d4-5443-42be-8500-ffdf9afad768 WaitActive WaitActive WaitActive","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:06:57.283789597Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1188}
1512023-08-10T06:06:57.273Z{"msg":"88c1d1d4-5443-42be-8500-ffdf9afad768 WaitActive WaitActive WaitActive","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:06:57.283834735Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1188}
1522023-08-10T06:06:57.276Z{"msg":"88c1d1d4-5443-42be-8500-ffdf9afad768 WaitActive WaitActive WaitActive","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:06:57.283901462Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1188}
1532023-08-10T06:06:57.278Z{"msg":"[1] 88c1d1d4-5443-42be-8500-ffdf9afad768 (56c24d0d-910f-48eb-a997-1aae37399f7c) WaitActive WaitActive WaitActive ds_transition to WaitQuorum","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:06:57.284328371Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1188}
1542023-08-10T06:06:57.281Z{"msg":"[1] Transition from WaitActive to WaitQuorum","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:06:57.284387328Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1188}
1552023-08-10T06:06:57.283Z{"msg":"[1] new RM replaced this: None","v":0,"name":"crucible","level":40,"time":"2023-08-10T06:06:57.284413039Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1188}
1562023-08-10T06:06:57.286Z{"msg":"[1] Starts reconcile loop","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:06:57.28448613Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1188}
1572023-08-10T06:06:57.289Z{"msg":"[1] 127.0.0.1:8820 task reports connection:true","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:06:57.284592404Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1188}
1582023-08-10T06:06:57.292Z{"msg":"88c1d1d4-5443-42be-8500-ffdf9afad768 WaitActive WaitQuorum WaitActive","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:06:57.284683396Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1188}
1592023-08-10T06:06:57.294Z{"msg":"Waiting for 2 more clients to be ready","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:06:57.284756966Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1188}
1602023-08-10T06:06:57.297Z{"msg":"Set check for repair","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:06:57.284805585Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1188}
1612023-08-10T06:06:57.300Z{"msg":"[2] 88c1d1d4-5443-42be-8500-ffdf9afad768 (56c24d0d-910f-48eb-a997-1aae37399f7c) WaitActive WaitQuorum WaitActive ds_transition to WaitQuorum","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:06:57.2848492Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1188}
1622023-08-10T06:06:57.303Z{"msg":"[2] Transition from WaitActive to WaitQuorum","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:06:57.284891813Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1188}
1632023-08-10T06:06:57.305Z{"msg":"[2] new RM replaced this: None","v":0,"name":"crucible","level":40,"time":"2023-08-10T06:06:57.284931059Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1188}
1642023-08-10T06:06:57.308Z{"msg":"[2] Starts reconcile loop","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:06:57.284970141Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1188}
1652023-08-10T06:06:57.311Z{"msg":"[2] 127.0.0.1:8830 task reports connection:true","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:06:57.285010853Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1188}
1662023-08-10T06:06:57.314Z{"msg":"88c1d1d4-5443-42be-8500-ffdf9afad768 WaitActive WaitQuorum WaitQuorum","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:06:57.285052186Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1188}
1672023-08-10T06:06:57.316Z{"msg":"Waiting for 1 more clients to be ready","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:06:57.285099399Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1188}
1682023-08-10T06:06:57.319Z{"msg":"Set check for repair","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:06:57.2851201Z","The guest has finished waiting for activation with:26
1692023-08-10T06:06:57.324ZWait for a query_work_queue command to finish before sending IO
1702023-08-10T06:06:57.327Zhostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1188}
1712023-08-10T06:06:57.330Z{"msg":"[0] 88c1d1d4-5443-42be-8500-ffdf9afad768 (56c24d0d-910f-48eb-a997-1aae37399f7c) WaitActive WaitQuorum WaitQuorum ds_transition to WaitQuorum","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:06:57.285227663Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1188}
1722023-08-10T06:06:57.333Z{"msg":"[0] Transition from WaitActive to WaitQuorum","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:06:57.285257093Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1188}
1732023-08-10T06:06:57.335Z{"msg":"[0] new RM replaced this: None","v":0,"name":"crucible","level":40,"time":"2023-08-10T06:06:57.285286901Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1188}
1742023-08-10T06:06:57.338Z{"msg":"[0] Starts reconcile loop","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:06:57.285374971Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1188}
1752023-08-10T06:06:57.341Z{"msg":"[0] 127.0.0.1:8810 task reports connection:true","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:06:57.285413956Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1188}
1762023-08-10T06:06:57.343Z{"msg":"88c1d1d4-5443-42be-8500-ffdf9afad768 WaitQuorum WaitQuorum WaitQuorum","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:06:57.285473172Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1188}
1772023-08-10T06:06:57.346Z{"msg":"[0]R flush_numbers: [2015, 2016, 2016, 2016, 2016]","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:06:57.285531841Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1188}
1782023-08-10T06:06:57.349Z{"msg":"[0]R generation: [20, 20, 20, 20, 20]","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:06:57.28559538Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1188}
1792023-08-10T06:06:57.351Z{"msg":"[0]R dirty: [false, false, false, false, false]","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:06:57.285657323Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1188}
1802023-08-10T06:06:57.354Z{"msg":"[1]R flush_numbers: [2015, 2016, 2016, 2016, 2016]","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:06:57.28571811Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1188}
1812023-08-10T06:06:57.357Z{"msg":"[1]R generation: [20, 20, 20, 20, 20]","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:06:57.285786204Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1188}
1822023-08-10T06:06:57.360Z{"msg":"[1]R dirty: [false, false, false, false, false]","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:06:57.285817379Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1188}
1832023-08-10T06:06:57.362Z{"msg":"[2]R flush_numbers: [2015, 2016, 2016, 2016, 2016]","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:06:57.285838332Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1188}
1842023-08-10T06:06:57.365Z{"msg":"[2]R generation: [20, 20, 20, 20, 20]","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:06:57.285857139Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1188}
1852023-08-10T06:06:57.368Z{"msg":"[2]R dirty: [false, false, false, false, false]","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:06:57.285876165Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1188}
1862023-08-10T06:06:57.371Z{"msg":"Max found gen is 21","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:06:57.285894669Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1188}
1872023-08-10T06:06:57.375Z{"msg":"Generation requested: 26 >= found:21","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:06:57.285912938Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1188}
1882023-08-10T06:06:57.378Z{"msg":"Next flush: 2017","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:06:57.285930743Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1188}
1892023-08-10T06:06:57.380Z{"msg":"All extents match","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:06:57.285949318Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1188}
1902023-08-10T06:06:57.383Z{"msg":"No downstairs repair required","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:06:57.285967897Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1188}
1912023-08-10T06:06:57.386Z{"msg":"No initial repair work was required","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:06:57.285986948Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1188}
1922023-08-10T06:06:57.388Z{"msg":"Set Downstairs and Upstairs active","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:06:57.286005419Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1188}
1932023-08-10T06:06:57.391Z{"msg":"88c1d1d4-5443-42be-8500-ffdf9afad768 is now active with session: 56c24d0d-910f-48eb-a997-1aae37399f7c","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:06:57.286025742Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1188}
1942023-08-10T06:06:57.394ZRegion: es:10 ec:5 bs:4096 ts:204800 tb:50 max_io:50 or 204800
1952023-08-10T06:06:57.396Z{"msg":"88c1d1d4-5443-42be-8500-ffdf9afad768 Set Active after no repair","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:06:57.28604915Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1188}
1962023-08-10T06:06:57.399Z{"msg":"Notify all downstairs, region set compare is done.","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:06:57.286068518Z","hostname":"Fill test
1972023-08-10T06:06:57.402Zip-10-150-1-162.us-west-2.compute.internal","pid":1188}
1982023-08-10T06:06:57.404Z{"msg":"Set check for repair","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:06:57.286088734Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1188}
1992023-08-10T06:06:57.408Z{"msg":"[0] received reconcile message","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:06:57.286107016Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1188}
2002023-08-10T06:06:57.411Z{"msg":"[0] All repairs completed, exit","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:06:57.286125965Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1188}
2012023-08-10T06:06:57.414Z{"msg":"[0] Starts cmd_loop","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:06:57.286155814Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1188}
2022023-08-10T06:06:57.416Z{"msg":"[2] received reconcile message","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:06:57.28617858Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1188}
2032023-08-10T06:06:57.419Z{"msg":"[2] All repairs completed, exit","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:06:57.28619809Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1188}
2042023-08-10T06:06:57.422Z{"msg":"[1] received reconcile message","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:06:57.286216828Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1188}
2052023-08-10T06:06:57.425Z{"msg":"[2] Starts cmd_loop","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:06:57.28623546Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1188}
2062023-08-10T06:06:57.427Z{"msg":"[1] All repairs completed, exit","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:06:57.286254264Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1188}
2072023-08-10T06:06:57.430Z{"msg":"[1] Starts cmd_loop","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:06:57.286272916Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1188}
2082023-08-10T06:06:57.433ZRead and Verify all blocks (0..50 range:false)
2092023-08-10T06:06:57.435ZWrote out file "/var/tmp/test_up/verify_file"
2102023-08-10T06:06:57.438ZCLIENT: Tests done. All submitted work has been ACK'd
2112023-08-10T06:06:57.457Z----------------------------------------------------------------
2122023-08-10T06:06:57.460Z Crucible gen:26 GIO:true work queues: Upstairs:0 downstairs:1
2132023-08-10T06:06:57.463ZGW_ID ACK DSID TYPE BLOCKS DS:0 DS:1 DS:2 REPLAY
2142023-08-10T06:06:57.465Z 3 Acked 1002 Read 50 Done Done Done false
2152023-08-10T06:06:57.468Z STATES DS:0 DS:1 DS:2 TOTAL
2162023-08-10T06:06:57.471Z New 0 0 0 0
2172023-08-10T06:06:57.473Z Sent 0 0 0 0
2182023-08-10T06:06:57.476Z Done 1 1 1 3
2192023-08-10T06:06:57.479Z Skipped 0 0 0 0
2202023-08-10T06:06:57.481Z Error 0 0 0 0
2212023-08-10T06:06:57.484ZLast Flush: 1001 1001 1001
2222023-08-10T06:06:57.487ZDownstairs last five completed: 1001 1000
2232023-08-10T06:06:57.489ZUpstairs last five completed: 3 2 1
2242023-08-10T06:06:57.492ZCLIENT: Up:0 ds:1 act:3
2252023-08-10T06:06:58.176Z{"msg":"Checking if live repair is needed","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:06:58.286452756Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1188}
2262023-08-10T06:06:58.179Z{"msg":"No Live Repair required at this time","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:06:58.286551743Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1188}
2272023-08-10T06:07:01.457Z----------------------------------------------------------------
2282023-08-10T06:07:01.460Z Crucible gen:26 GIO:true work queues: Upstairs:0 downstairs:0
2292023-08-10T06:07:01.463ZDownstairs last five completed: 1003 1002 1001 1000
2302023-08-10T06:07:01.467ZUpstairs last five completed: 4 3 2 1
2312023-08-10T06:07:01.470ZCLIENT: Up:0 ds:0 act:3
2322023-08-10T06:07:01.473ZCLIENT: All crucible jobs finished, exiting program
2332023-08-10T06:07:01.476ZRepair setup passed
2342023-08-10T06:07:01.480ZCopy the 8830 file
2352023-08-10T06:07:01.483Zcp -r /var/tmp/test_up/8830 /var/tmp/test_up/previous
2362023-08-10T06:07:01.509Z/var/tmp/bins/crutest repair -g 27 -q --key uUNQZMLN6+7Z1bxrX+G3ctqq/MPXkUp3G36OWVCYmCQ= -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
2372023-08-10T06:07:01.531Z{"msg":"Upstairs starts","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:07:01.642330054Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1194}
2382023-08-10T06:07:01.534Z{"msg":"Crucible Version: BuildInfo {\n version: \"0.0.1\",\n git_sha: \"9f9f88bb1717d2b86fef41798471b705ff437b87\",\n git_commit_timestamp: \"2023-08-10T05:35:49.000000000Z\",\n git_branch: \"alan/wip-for-vcr\",\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-08-10T06:07:01.642839761Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1194}
2392023-08-10T06:07:01.537Z{"msg":"Upstairs <-> Downstairs Message Version: 4","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:07:01.642892854Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1194}
2402023-08-10T06:07:01.541Z{"msg":"Crucible stats registered with UUID: 3a64b8d7-0361-4868-8162-bc470ea1c9e8","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:07:01.642919071Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1194}
2412023-08-10T06:07:01.544Z{"msg":"Crucible 3a64b8d7-0361-4868-8162-bc470ea1c9e8 has session id: 72aaf95f-8aa1-4238-9fe0-5b7a203150f2","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:07:01.642988691Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1194}
2422023-08-10T06:07:01.547ZCrucible runtime is spawned
2432023-08-10T06:07:01.550ZThe guest has requested activation with gen:27
2442023-08-10T06:07:01.553Z{"msg":"up_listen starts","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:07:01.643396087Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1194,"task":"up_listen"}
2452023-08-10T06:07:01.560Z{"msg":"[2] connecting to 127.0.0.1:8830","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:07:01.643465871Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1194,"looper":"2"}
2462023-08-10T06:07:01.564Z{"msg":"Wait for all three downstairs to come online","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:07:01.64352243Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1194}
2472023-08-10T06:07:01.567Z{"msg":"Flush timeout: 0.5","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:07:01.64358605Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1194}
2482023-08-10T06:07:01.570Z{"msg":"[0] connecting to 127.0.0.1:8810","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:07:01.643700875Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1194,"looper":"0"}
2492023-08-10T06:07:01.574Z{"msg":"[2] 3a64b8d7-0361-4868-8162-bc470ea1c9e8 looper connected","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:07:01.643783671Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1194,"looper":"2"}
2502023-08-10T06:07:01.577Z{"msg":"[1] connecting to 127.0.0.1:8820","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:07:01.643853745Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1194,"looper":"1"}
2512023-08-10T06:07:01.580Z{"msg":"[0] 3a64b8d7-0361-4868-8162-bc470ea1c9e8 looper connected","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:07:01.643933349Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1194,"looper":"0"}
2522023-08-10T06:07:01.583Z{"msg":"[1] 3a64b8d7-0361-4868-8162-bc470ea1c9e8 looper connected","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:07:01.643975382Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1194,"looper":"1"}
2532023-08-10T06:07:01.586Z{"msg":"3a64b8d7-0361-4868-8162-bc470ea1c9e8 active request set","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:07:01.644479933Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1194}
2542023-08-10T06:07:01.589Z{"msg":"Set desired generation to :27","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:07:01.644533669Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1194}
2552023-08-10T06:07:01.592Z{"msg":"[2] Proc runs for 127.0.0.1:8830 in state New","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:07:01.644749712Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1194}
2562023-08-10T06:07:01.596Z{"msg":"[0] Proc runs for 127.0.0.1:8810 in state New","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:07:01.645059365Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1194}
2572023-08-10T06:07:01.599Z{"msg":"[1] Proc runs for 127.0.0.1:8820 in state New","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:07:01.645124996Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1194}
2582023-08-10T06:07:01.602Z{"msg":"[2] 3a64b8d7-0361-4868-8162-bc470ea1c9e8 (55b0b733-dd8c-4330-a585-85db0d210c47) New New New ds_transition to WaitActive","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:07:01.645462871Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1194}
2592023-08-10T06:07:01.605Z{"msg":"[2] Transition from New to WaitActive","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:07:01.645522198Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1194}
2602023-08-10T06:07:01.608Z{"msg":"[2] client is_active_req TRUE, promote! session 55b0b733-dd8c-4330-a585-85db0d210c47","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:07:01.645565435Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1194}
2612023-08-10T06:07:01.611Z{"msg":"[1] 3a64b8d7-0361-4868-8162-bc470ea1c9e8 (55b0b733-dd8c-4330-a585-85db0d210c47) New New WaitActive ds_transition to WaitActive","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:07:01.645714614Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1194}
2622023-08-10T06:07:01.614Z{"msg":"[1] Transition from New to WaitActive","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:07:01.645781901Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1194}
2632023-08-10T06:07:01.617Z{"msg":"[1] client is_active_req TRUE, promote! session 55b0b733-dd8c-4330-a585-85db0d210c47","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:07:01.645851932Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1194}
2642023-08-10T06:07:01.620Z{"msg":"[0] 3a64b8d7-0361-4868-8162-bc470ea1c9e8 (55b0b733-dd8c-4330-a585-85db0d210c47) New WaitActive WaitActive ds_transition to WaitActive","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:07:01.645888114Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1194}
2652023-08-10T06:07:01.623Z{"msg":"[0] Transition from New to WaitActive","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:07:01.645922875Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1194}
2662023-08-10T06:07:01.626Z{"msg":"[0] client is_active_req TRUE, promote! session 55b0b733-dd8c-4330-a585-85db0d210c47","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:07:01.64596268Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1194}
2672023-08-10T06:07:01.629Z{"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-08-10T06:07:01.646336659Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1194}
2682023-08-10T06:07:01.632Z{"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-08-10T06:07:01.646393997Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1194}
2692023-08-10T06:07:01.634Z{"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-08-10T06:07:01.646461237Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1194}
2702023-08-10T06:07:01.639Z{"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-08-10T06:07:01.646536462Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1194}
2712023-08-10T06:07:01.642Z{"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-08-10T06:07:01.646576104Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1194}
2722023-08-10T06:07:01.645Z{"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-08-10T06:07:01.646649383Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1194}
2732023-08-10T06:07:01.648Z{"msg":"3a64b8d7-0361-4868-8162-bc470ea1c9e8 WaitActive WaitActive WaitActive","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:07:01.646843931Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1194}
2742023-08-10T06:07:01.651Z{"msg":"3a64b8d7-0361-4868-8162-bc470ea1c9e8 WaitActive WaitActive WaitActive","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:07:01.646897669Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1194}
2752023-08-10T06:07:01.654Z{"msg":"3a64b8d7-0361-4868-8162-bc470ea1c9e8 WaitActive WaitActive WaitActive","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:07:01.646922235Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1194}
2762023-08-10T06:07:01.657Z{"msg":"[1] 3a64b8d7-0361-4868-8162-bc470ea1c9e8 (55b0b733-dd8c-4330-a585-85db0d210c47) WaitActive WaitActive WaitActive ds_transition to WaitQuorum","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:07:01.647189389Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1194}
2772023-08-10T06:07:01.660Z{"msg":"[1] Transition from WaitActive to WaitQuorum","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:07:01.647267595Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1194}
2782023-08-10T06:07:01.667Z{"msg":"[1] new RM replaced this: None","v":0,"name":"crucible","level":40,"time":"2023-08-10T06:07:01.64732731Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1194}
2792023-08-10T06:07:01.671Z{"msg":"[1] Starts reconcile loop","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:07:01.647397533Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1194}
2802023-08-10T06:07:01.674Z{"msg":"[1] 127.0.0.1:8820 task reports connection:true","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:07:01.647454733Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1194}
2812023-08-10T06:07:01.677Z{"msg":"3a64b8d7-0361-4868-8162-bc470ea1c9e8 WaitActive WaitQuorum WaitActive","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:07:01.64751236Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1194}
2822023-08-10T06:07:01.681Z{"msg":"Waiting for 2 more clients to be ready","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:07:01.647567721Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1194}
2832023-08-10T06:07:01.684Z{"msg":"Set check for repair","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:07:01.647624143Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1194}
2842023-08-10T06:07:01.687Z{"msg":"[0] 3a64b8d7-0361-4868-8162-bc470ea1c9e8 (55b0b733-dd8c-4330-a585-85db0d210c47) WaitActive WaitQuorum WaitActive ds_transition to WaitQuorum","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:07:01.647683877Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1194}
2852023-08-10T06:07:01.690Z{"msg":"[0] Transition from WaitActive to WaitQuorum","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:07:01.647738792Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1194}
2862023-08-10T06:07:01.693Z{"msg":"[0] new RM replaced this: None","v":0,"name":"crucible","level":40,"time":"2023-08-10T06:07:01.647805265Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1194}
2872023-08-10T06:07:01.697Z{"msg":"[0] Starts reconcile loop","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:07:01.647894064Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1194}
2882023-08-10T06:07:01.700Z{"msg":"[2] 3a64b8d7-0361-4868-8162-bc470ea1c9e8 (55b0b733-dd8c-4330-a585-85db0d210c47) WaitQuorum WaitQuorum WaitActive ds_transition to WaitQuorum","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:07:01.647957801Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1194}
2892023-08-10T06:07:01.702Z{"msg":"[2] Transition from WaitActive to WaitQuorum","v":0,"name":"crucible","level":30The guest has finished waiting for activation with:27
2902023-08-10T06:07:01.705ZWait for a query_work_queue command to finish before sending IO
2912023-08-10T06:07:01.709Z,"time":"2023-08-10T06:07:01.648074499Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1194}
2922023-08-10T06:07:01.712Z{"msg":"[0] 127.0.0.1:8810 task reports connection:true","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:07:01.648195577Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1194}
2932023-08-10T06:07:01.716Z{"msg":"[2] new RM replaced this: None","v":0,"name":"crucible","level":40,"time":"2023-08-10T06:07:01.648249843Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1194}
2942023-08-10T06:07:01.719Z{"msg":"3a64b8d7-0361-4868-8162-bc470ea1c9e8 WaitQuorum WaitQuorum WaitQuorum","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:07:01.648271885Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1194}
2952023-08-10T06:07:01.722Z{"msg":"[1]R flush_numbers: [2017, 2017, 2017, 2017, 2017]","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:07:01.648314555Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1194}
2962023-08-10T06:07:01.725Z{"msg":"[1]R generation: [26, 26, 26, 26, 26]","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:07:01.648359156Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1194}
2972023-08-10T06:07:01.728Z{"msg":"[1]R dirty: [false, false, false, false, false]","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:07:01.648399149Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1194}
2982023-08-10T06:07:01.731Z{"msg":"[2]R flush_numbers: [2017, 2017, 2017, 2017, 2017]","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:07:01.648439261Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1194}
2992023-08-10T06:07:01.736Z{"msg":"[2]R generation: [26, 26, 26, 26, 26]","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:07:01.648483358Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1194}
3002023-08-10T06:07:01.740Z{"msg":"[2]R dirty: [false, false, false, false, false]","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:07:01.648525039Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1194}
3012023-08-10T06:07:01.743Z{"msg":"[0]R flush_numbers: [2017, 2017, 2017, 2017, 2017]","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:07:01.648565075Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1194}
3022023-08-10T06:07:01.745Z{"msg":"[0]R generation: [26, 26, 26, 26, 26]","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:07:01.648604844Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1194}
3032023-08-10T06:07:01.749Z{"msg":"[0]R dirty: [false, false, false, false, false]","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:07:01.648648305Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1194}
3042023-08-10T06:07:01.752Z{"msg":"Max found gen is 27","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:07:01.648692246Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1194}
3052023-08-10T06:07:01.755Z{"msg":"Generation requested: 27 >= found:27","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:07:01.64871256Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1194}
3062023-08-10T06:07:01.758Z{"msg":"Next flush: 2018","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:07:01.648731286Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1194}
3072023-08-10T06:07:01.761Z{"msg":"All extents match","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:07:01.648749977Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1194}
3082023-08-10T06:07:01.764Z{"msg":"No downstairs repair required","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:07:01.648768693Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1194}
3092023-08-10T06:07:01.767Z{"msg":"[2] Starts reconcile loop","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:07:01.64878736Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1194}
3102023-08-10T06:07:01.770Z{"msg":"No initial repair work was required","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:07:01.648806379Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1194}
3112023-08-10T06:07:01.773Z{"msg":"Set Downstairs and Upstairs active","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:07:01.648825142Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1194}
3122023-08-10T06:07:01.776Z{"msg":"3a64b8d7-0361-4868-8162-bc470ea1c9e8 is now active with session: 55b0b733-dd8c-4330-a585-85db0d210c47","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:07:01.64884629Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1194}
3132023-08-10T06:07:01.779Z{"msg":"3a64b8d7-0361-4868-8162-bc470ea1c9e8 Set Active after no repair","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:07:01.648865995Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1194}
3142023-08-10T06:07:01.782Z{"msg":"Notify all downstairs, region set compare is done.","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:07:01.648884698Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1194}
3152023-08-10T06:07:01.786Z{"msg":"Set check for repair","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:07:01.648902645Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1194}
3162023-08-10T06:07:01.789Z{"msg":"[2] 127.0.0.1:8830 task reports connection:true","vRegion: es:10 ec:5 bs:4096 ts:204800 tb:50 max_io:50 or 204800
3172023-08-10T06:07:01.792Z":0,"name":"crucible","level":30,"time":"2023-08-10T06:07:01.648926545Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1194}
3182023-08-10T06:07:01.795Z{"msg":"3a64b8d7-0361-4868-8162-bc470ea1c9e8 Active Active Active","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:07:01.648946096Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1194}
3192023-08-10T06:07:01.798Z{"msg":"Set check for repair","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:07:01.648964536Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1194}
3202023-08-10T06:07:01.801Z{"msg":"[2] received reconcile message","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:07:01.648984048Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1194}
3212023-08-10T06:07:01.804Z{"msg":"[2] All repairs completed, exit","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:07:01.649002921Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1194}
3222023-08-10T06:07:01.807Z{"msg":"[2] Starts cmd_loop","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:07:01.649021001Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1194}
3232023-08-10T06:07:01.810Z{"msg":"[1] received reconcile message","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:07:01.649039985Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1194}
3242023-08-10T06:07:01.813Z{"msg":"[1] All repairs completed, exit","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:07:01.649058757Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1194}
3252023-08-10T06:07:01.817Z{"msg":"[1] Starts cmd_loop","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:07:01.649077123Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1194}
3262023-08-10T06:07:01.820Z{"msg":"[0] received reconcile message","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:07:01.649096064Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1194}
3272023-08-10T06:07:01.823Z{"msg":"[0] All repairs completed, exit","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:07:01.649114266Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1194}
3282023-08-10T06:07:01.826Z{"msg":"[0] Starts cmd_loop","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:07:01.649147272Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1194}
3292023-08-10T06:07:01.829ZLoading write count information from file "/var/tmp/test_up/verify_file"
3302023-08-10T06:07:01.832ZRun Repair workload
3312023-08-10T06:07:01.835Z01/10 Write block 24 len 20480 data: 2 2 2 2 2
3322023-08-10T06:07:01.838Z02/10 Write block 24 len 16384 data: 3 3 3 3
3332023-08-10T06:07:01.841Z03/10 Read block 14 len 24576
3342023-08-10T06:07:01.844Z04/10 Write block 14 len 32768 data: 2 2 2 2 2 2 2 2
3352023-08-10T06:07:01.847Z05/10 Read block 14 len 16384
3362023-08-10T06:07:01.850Z06/10 Read block 17 len 36864
3372023-08-10T06:07:01.853Z07/10 Write block 40 len 12288 data: 2 2 2
3382023-08-10T06:07:01.857Z08/10 Write block 22 len 20480 data: 2 2 4 4 4
3392023-08-10T06:07:01.860Z09/10 Read block 2 len 8192
3402023-08-10T06:07:01.863Z10/10 Write block 31 len 8192 data: 2 2
3412023-08-10T06:07:01.865Z----------------------------------------------------------------
3422023-08-10T06:07:01.869Z Crucible gen:27 GIO:true work queues: Upstairs:0 downstairs:10
3432023-08-10T06:07:01.872ZGW_ID ACK DSID TYPE BLOCKS DS:0 DS:1 DS:2 REPLAY
3442023-08-10T06:07:01.875Z 1 Acked 1000 Write 5 Done Done Done false
3452023-08-10T06:07:01.878Z 2 Acked 1001 Write 4 Done Done Done false
3462023-08-10T06:07:01.881Z 3 Acked 1002 Read 6 Done Done Done false
3472023-08-10T06:07:01.884Z 4 Acked 1003 Write 8 Done Done Done false
3482023-08-10T06:07:01.888Z 5 Acked 1004 Read 4 Done Done Done false
3492023-08-10T06:07:01.891Z 6 Acked 1005 Read 9 Done Done Done false
3502023-08-10T06:07:01.894Z 7 Acked 1006 Write 3 Done Done Done false
3512023-08-10T06:07:01.897Z 8 Acked 1007 Write 5 Done Done Done false
3522023-08-10T06:07:01.900Z 9 Acked 1008 Read 2 Done Done Done false
3532023-08-10T06:07:01.903Z 10 Acked 1009 Write 2 Done Done Done false
3542023-08-10T06:07:01.906Z STATES DS:0 DS:1 DS:2 TOTAL
3552023-08-10T06:07:01.909Z New 0 0 0 0
3562023-08-10T06:07:01.913Z Sent 0 0 0 0
3572023-08-10T06:07:01.916Z Done 10 10 10 30
3582023-08-10T06:07:01.919Z Skipped 0 0 0 0
3592023-08-10T06:07:01.922Z Error 0 0 0 0
3602023-08-10T06:07:01.926ZLast Flush: 0 0 0
3612023-08-10T06:07:01.929ZDownstairs last five completed:
3622023-08-10T06:07:01.933ZUpstairs last five completed: 10 9 8 7 6 5
3632023-08-10T06:07:01.937ZWrote out file "/var/tmp/test_up/verify_file"
3642023-08-10T06:07:01.940ZRepair part 1 passed
3652023-08-10T06:07:01.943Z
3662023-08-10T06:07:01.947ZKill the current downstairs
3672023-08-10T06:07:01.950Zrm -rf /var/tmp/test_up/8830
3682023-08-10T06:07:01.952ZNow put back the original so we have a mismatch
3692023-08-10T06:07:01.956Zmv /var/tmp/test_up/previous /var/tmp/test_up/8830
3702023-08-10T06:07:01.959ZRestart downstairs with old directory
3712023-08-10T06:07:02.028Z/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
3722023-08-10T06:07:02.048Z{"msg":"current number of open files limit 65536 is already the maximum","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:07:02.159790906Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1200}
3732023-08-10T06:07:02.052Z{"msg":"Database read version 1","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:07:02.160165308Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1200}
3742023-08-10T06:07:02.055Z{"msg":"Database write version 1","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:07:02.160207282Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1200}
3752023-08-10T06:07:02.060Z{"msg":"current number of open files limit 65536 is already the maximum","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:07:02.17261407Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1200}
3762023-08-10T06:07:02.063Z{"msg":"Database read version 1","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:07:02.172688803Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1200}
3772023-08-10T06:07:02.066Z{"msg":"Database write version 1","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:07:02.172714062Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1200}
3782023-08-10T06:07:02.069Z{"msg":"current number of open files limit 65536 is already the maximum","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:07:02.179851774Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1200}
3792023-08-10T06:07:02.072Z{"msg":"Database read version 1","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:07:02.179908629Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1200}
3802023-08-10T06:07:02.075Z{"msg":"Database write version 1","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:07:02.179951997Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1200}
3812023-08-10T06:07:02.104ZEXT BLOCKS GEN0 GEN1 GEN2 FL0 FL1 FL2 D0 D1 D2 DIFF
3822023-08-10T06:07:02.108Z 0 000-009 26 26 26 2017 2017 2017 F F F
3832023-08-10T06:07:02.110Z 1 010-019 26 26 26 2017 2017 2017 T T F <---
3842023-08-10T06:07:02.114Z 2 020-029 26 26 26 2017 2017 2017 T T F <---
3852023-08-10T06:07:02.118Z 3 030-039 26 26 26 2017 2017 2017 T T F <---
3862023-08-10T06:07:02.122Z 4 040-049 26 26 26 2017 2017 2017 T T F <---
3872023-08-10T06:07:02.128ZMax gen: 26, Max flush: 2017
3882023-08-10T06:07:02.132ZError: Difference in extent metadata found!
3892023-08-10T06:07:02.135Zdump test found error as expected
3902023-08-10T06:07:02.138Z
3912023-08-10T06:07:02.141Z
3922023-08-10T06:07:02.144Z/var/tmp/bins/crutest deactivate -g 28 -q --key uUNQZMLN6+7Z1bxrX+G3ctqq/MPXkUp3G36OWVCYmCQ= -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
3932023-08-10T06:07:02.147Z{"msg":"Upstairs starts","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:07:02.24599064Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1201}
3942023-08-10T06:07:02.150Z{"msg":"Crucible Version: BuildInfo {\n version: \"0.0.1\",\n git_sha: \"9f9f88bb1717d2b86fef41798471b705ff437b87\",\n git_commit_timestamp: \"2023-08-10T05:35:49.000000000Z\",\n git_branch: \"alan/wip-for-vcr\",\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-08-10T06:07:02.246537799Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1201}
3952023-08-10T06:07:02.154Z{"msg":"Upstairs <-> Downstairs Message Version: 4","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:07:02.246591049Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1201}
3962023-08-10T06:07:02.157Z{"msg":"Crucible stats registered with UUID: 6aac1c0a-c22f-4cb2-8a7b-6a31d4c53787","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:07:02.246634927Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1201}
3972023-08-10T06:07:02.160Z{"msg":"Crucible 6aac1c0a-c22f-4cb2-8a7b-6a31d4c53787 has session id: a3136cb6-7313-40df-b89f-a8fe15fe4d2e","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:07:02.246678675Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1201}
3982023-08-10T06:07:02.163ZCrucible runtime is spawned
3992023-08-10T06:07:02.167ZThe guest has requested activation with gen:28
4002023-08-10T06:07:02.170Z{"msg":"up_listen starts","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:07:02.247029957Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1201,"task":"up_listen"}
4012023-08-10T06:07:02.174Z{"msg":"Wait for all three downstairs to come online","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:07:02.24709554Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1201}
4022023-08-10T06:07:02.177Z{"msg":"[1] connecting to 127.0.0.1:8820","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:07:02.24718079Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1201,"looper":"1"}
4032023-08-10T06:07:02.180Z{"msg":"Flush timeout: 0.5","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:07:02.247255562Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1201}
4042023-08-10T06:07:02.183Z{"msg":"[0] connecting to 127.0.0.1:8810","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:07:02.247345867Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1201,"looper":"0"}
4052023-08-10T06:07:02.186Z{"msg":"[2] connecting to 127.0.0.1:8830","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:07:02.247415191Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1201,"looper":"2"}
4062023-08-10T06:07:02.190Z{"msg":"[1] 6aac1c0a-c22f-4cb2-8a7b-6a31d4c53787 looper connected","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:07:02.247501989Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1201,"looper":"1"}
4072023-08-10T06:07:02.193Z{"msg":"[0] 6aac1c0a-c22f-4cb2-8a7b-6a31d4c53787 looper connected","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:07:02.247557571Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1201,"looper":"0"}
4082023-08-10T06:07:02.196Z{"msg":"6aac1c0a-c22f-4cb2-8a7b-6a31d4c53787 active request set","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:07:02.248086049Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1201}
4092023-08-10T06:07:02.199Z{"msg":"Set desired generation to :28","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:07:02.248161686Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1201}
4102023-08-10T06:07:02.202Z{"msg":"[1] Proc runs for 127.0.0.1:8820 in state New","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:07:02.248353042Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1201}
4112023-08-10T06:07:02.205Z{"msg":"[0] Proc runs for 127.0.0.1:8810 in state New","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:07:02.248647692Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1201}
4122023-08-10T06:07:02.208Z{"msg":"[1] 6aac1c0a-c22f-4cb2-8a7b-6a31d4c53787 (8659a9be-e58c-4b73-8575-5390f69a5fbc) New New New ds_transition to WaitActive","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:07:02.249103869Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1201}
4132023-08-10T06:07:02.211Z{"msg":"[1] Transition from New to WaitActive","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:07:02.249187161Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1201}
4142023-08-10T06:07:02.215Z{"msg":"[1] client is_active_req TRUE, promote! session 8659a9be-e58c-4b73-8575-5390f69a5fbc","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:07:02.249232068Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1201}
4152023-08-10T06:07:02.219Z{"msg":"[0] 6aac1c0a-c22f-4cb2-8a7b-6a31d4c53787 (8659a9be-e58c-4b73-8575-5390f69a5fbc) New WaitActive New ds_transition to WaitActive","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:07:02.249276844Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1201}
4162023-08-10T06:07:02.222Z{"msg":"[0] Transition from New to WaitActive","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:07:02.249302496Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1201}
4172023-08-10T06:07:02.225Z{"msg":"[0] client is_active_req TRUE, promote! session 8659a9be-e58c-4b73-8575-5390f69a5fbc","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:07:02.249368463Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1201}
4182023-08-10T06:07:02.227Z{"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-08-10T06:07:02.249789391Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1201}
4192023-08-10T06:07:02.230Z{"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-08-10T06:07:02.249870188Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1201}
4202023-08-10T06:07:02.233Z{"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-08-10T06:07:02.249943534Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1201}
4212023-08-10T06:07:02.236Z{"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-08-10T06:07:02.250009359Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1201}
4222023-08-10T06:07:02.239Z{"msg":"6aac1c0a-c22f-4cb2-8a7b-6a31d4c53787 WaitActive WaitActive New","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:07:02.250064319Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1201}
4232023-08-10T06:07:02.242Z{"msg":"6aac1c0a-c22f-4cb2-8a7b-6a31d4c53787 WaitActive WaitActive New","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:07:02.25012241Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1201}
4242023-08-10T06:07:02.245Z{"msg":"[1] 6aac1c0a-c22f-4cb2-8a7b-6a31d4c53787 (8659a9be-e58c-4b73-8575-5390f69a5fbc) WaitActive WaitActive New ds_transition to WaitQuorum","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:07:02.250708139Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1201}
4252023-08-10T06:07:02.249Z{"msg":"[1] Transition from WaitActive to WaitQuorum","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:07:02.250768881Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1201}
4262023-08-10T06:07:02.252Z{"msg":"[1] new RM replaced this: None","v":0,"name":"crucible","level":40,"time":"2023-08-10T06:07:02.250793998Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1201}
4272023-08-10T06:07:02.255Z{"msg":"[0] 6aac1c0a-c22f-4cb2-8a7b-6a31d4c53787 (8659a9be-e58c-4b73-8575-5390f69a5fbc) WaitActive WaitQuorum New ds_transition to WaitQuorum","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:07:02.250836911Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1201}
4282023-08-10T06:07:02.258Z{"msg":"[0] Transition from WaitActive to WaitQuorum","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:07:02.250860493Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1201}
4292023-08-10T06:07:02.261Z{"msg":"[0] new RM replaced this: None","v":0,"name":"crucible","level":40,"time":"2023-08-10T06:07:02.250899009Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1201}
4302023-08-10T06:07:02.264Z{"msg":"[1] Starts reconcile loop","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:07:02.250920162Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1201}
4312023-08-10T06:07:02.267Z{"msg":"[1] 127.0.0.1:8820 task reports connection:true","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:07:02.250959083Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1201}
4322023-08-10T06:07:02.270Z{"msg":"[0] Starts reconcile loop","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:07:02.250981471Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1201}
4332023-08-10T06:07:02.273Z{"msg":"6aac1c0a-c22f-4cb2-8a7b-6a31d4c53787 WaitQuorum WaitQuorum New","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:07:02.251022583Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1201}
4342023-08-10T06:07:02.278Z{"msg":"Waiting for 1 more clients to be ready","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:07:02.251045684Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1201}
4352023-08-10T06:07:02.281Z{"msg":"Set check for repair","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:07:02.251086445Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1201}
4362023-08-10T06:07:02.284Z{"msg":"[0] 127.0.0.1:8810 task reports connection:true","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:07:02.251107293Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1201}
4372023-08-10T06:07:02.287Z{"msg":"6aac1c0a-c22f-4cb2-8a7b-6a31d4c53787 WaitQuorum WaitQuorum New","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:07:02.251151526Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1201}
4382023-08-10T06:07:02.290Z{"msg":"Waiting for 1 more clients to be ready","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:07:02.251173971Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1201}
4392023-08-10T06:07:02.293Z{"msg":"Set check for repair","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:07:02.251211967Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1201}
4402023-08-10T06:07:03.140Z{"msg":"Checking if live repair is needed","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:07:03.252274878Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1201}
4412023-08-10T06:07:04.137Z{"msg":"[2] 6aac1c0a-c22f-4cb2-8a7b-6a31d4c53787 looper connected","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:07:04.25026458Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1201,"looper":"2"}
4422023-08-10T06:07:04.140Z{"msg":"[2] Proc runs for 127.0.0.1:8830 in state New","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:07:04.250364809Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1201}
4432023-08-10T06:07:04.143Z{"msg":"[2] 6aac1c0a-c22f-4cb2-8a7b-6a31d4c53787 (8659a9be-e58c-4b73-8575-5390f69a5fbc) WaitQuorum WaitQuorum New ds_transition to WaitActive","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:07:04.251235745Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1201}
4442023-08-10T06:07:04.146Z{"msg":"[2] Transition from New to WaitActive","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:07:04.251296786Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1201}
4452023-08-10T06:07:04.149Z{"msg":"[2] client is_active_req TRUE, promote! session 8659a9be-e58c-4b73-8575-5390f69a5fbc","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:07:04.251342536Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1201}
4462023-08-10T06:07:04.152Z{"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-08-10T06:07:04.251881903Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1201}
4472023-08-10T06:07:04.155Z{"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-08-10T06:07:04.251942988Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1201}
4482023-08-10T06:07:04.158Z{"msg":"6aac1c0a-c22f-4cb2-8a7b-6a31d4c53787 WaitQuorum WaitQuorum WaitActive","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:07:04.251987308Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1201}
4492023-08-10T06:07:04.160Z{"msg":"[2] 6aac1c0a-c22f-4cb2-8a7b-6a31d4c53787 (8659a9be-e58c-4b73-8575-5390f69a5fbc) WaitQuorum WaitQuorum WaitActive ds_transition to WaitQuorum","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:07:04.252830072Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1201}
4502023-08-10T06:07:04.163Z{"msg":"[2] Transition from WaitActive to WaitQuorum","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:07:04.25288113Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1201}
4512023-08-10T06:07:04.166Z{"msg":"[2] new RM replaced this: None","v":0,"name":"crucible","level":40,"time":"2023-08-10T06:07:04.25297418Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1201}
4522023-08-10T06:07:04.169Z{"msg":"[2] Starts reconcile loop","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:07:04.25303519Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1201}
4532023-08-10T06:07:04.171Z{"msg":"[2] 127.0.0.1:8830 task reports connection:true","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:07:04.253092827Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1201}
4542023-08-10T06:07:04.174Z{"msg":"6aac1c0a-c22f-4cb2-8a7b-6a31d4c53787 WaitQuorum WaitQuorum WaitQuorum","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:07:04.253132744Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1201}
4552023-08-10T06:07:04.177Z{"msg":"[1]R flush_numbers: [2017, 2017, 2017, 2017, 2017]","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:07:04.253180309Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1201}
4562023-08-10T06:07:04.180Z{"msg":"[1]R generation: [26, 26, 26, 26, 26]","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:07:04.253221724Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1201}
4572023-08-10T06:07:04.183Z{"msg":"[1]R dirty: [false, true, true, true, true]","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:07:04.253262233Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1201}
4582023-08-10T06:07:04.186Z{"msg":"[0]R flush_numbers: [2017, 2017, 2017, 2017, 2017]","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:07:04.253302302Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1201}
4592023-08-10T06:07:04.189Z{"msg":"[0]R generation: [26, 26, 26, 26, 26]","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:07:04.253342468Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1201}
4602023-08-10T06:07:04.192Z{"msg":"[0]R dirty: [false, true, true, true, true]","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:07:04.253382485Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1201}
4612023-08-10T06:07:04.194Z{"msg":"[2]R flush_numbers: [2017, 2017, 2017, 2017, 2017]","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:07:04.25340396Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1201}
4622023-08-10T06:07:04.197Z{"msg":"[2]R generation: [26, 26, 26, 26, 26]","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:07:04.253442263Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1201}
4632023-08-10T06:07:04.200Z{"msg":"[2]R dirty: [false, false, false, false, false]","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:07:04.253482922Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1201}
4642023-08-10T06:07:04.203Z{"msg":"Max found gen is 27","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:07:04.253522036Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1201}
4652023-08-10T06:07:04.205Z{"msg":"Generation requested: 28 >= found:27","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:07:04.253561785Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1201}
4662023-08-10T06:07:04.209Z{"msg":"Next flush: 2018","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:07:04.253600742Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1201}
4672023-08-10T06:07:04.212Z{"msg":"Extents 1 dirty","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:07:04.253640174Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1201,"":"mend"}
4682023-08-10T06:07:04.214Z{"msg":"First source client ID for extent 1","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:07:04.253681065Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1201,"mrl":"dirty","":"mend"}
4692023-08-10T06:07:04.217Z{"msg":"extent:1 gens: 26 26 26","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:07:04.253723467Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1201,"mrl":"dirty","":"mend"}
4702023-08-10T06:07:04.220Z{"msg":"extent:1 flush: 2017 2017 2017 scs: [0, 1, 2]","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:07:04.253765686Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1201,"mrl":"dirty","":"mend"}
4712023-08-10T06:07:04.222Z{"msg":"max_flush now has: [0, 1, 2]","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:07:04.253806982Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1201,"mrl":"dirty","":"mend"}
4722023-08-10T06:07:04.226Z{"msg":"extent:1 dirty: true true false","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:07:04.253829335Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1201,"mrl":"dirty","":"mend"}
4732023-08-10T06:07:04.228Z{"msg":"find dest for source 0 for extent at index 1","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:07:04.25389217Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1201,"mrl":"dirty","":"mend"}
4742023-08-10T06:07:04.231Z{"msg":"source 0, add dest 1 source flush","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:07:04.253942825Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1201,"mrl":"dirty","":"mend"}
4752023-08-10T06:07:04.233Z{"msg":"source 0, add dest 2 source flush","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:07:04.253986491Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1201,"mrl":"dirty","":"mend"}
4762023-08-10T06:07:04.236Z{"msg":"Extents 2 dirty","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:07:04.254043673Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1201,"":"mend"}
4772023-08-10T06:07:04.239Z{"msg":"First source client ID for extent 2","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:07:04.254114593Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1201,"mrl":"dirty","":"mend"}
4782023-08-10T06:07:04.242Z{"msg":"extent:2 gens: 26 26 26","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:07:04.254193332Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1201,"mrl":"dirty","":"mend"}
4792023-08-10T06:07:04.245Z{"msg":"extent:2 flush: 2017 2017 2017 scs: [0, 1, 2]","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:07:04.254262476Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1201,"mrl":"dirty","":"mend"}
4802023-08-10T06:07:04.248Z{"msg":"max_flush now has: [0, 1, 2]","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:07:04.254341248Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1201,"mrl":"dirty","":"mend"}
4812023-08-10T06:07:04.251Z{"msg":"extent:2 dirty: true true false","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:07:04.254403268Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1201,"mrl":"dirty","":"mend"}
4822023-08-10T06:07:04.254Z{"msg":"find dest for source 0 for extent at index 2","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:07:04.254461856Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1201,"mrl":"dirty","":"mend"}
4832023-08-10T06:07:04.257Z{"msg":"source 0, add dest 1 source flush","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:07:04.254519248Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1201,"mrl":"dirty","":"mend"}
4842023-08-10T06:07:04.260Z{"msg":"source 0, add dest 2 source flush","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:07:04.254576267Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1201,"mrl":"dirty","":"mend"}
4852023-08-10T06:07:04.263Z{"msg":"Extents 3 dirty","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:07:04.25463517Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1201,"":"mend"}
4862023-08-10T06:07:04.266Z{"msg":"First source client ID for extent 3","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:07:04.254691516Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1201,"mrl":"dirty","":"mend"}
4872023-08-10T06:07:04.268Z{"msg":"extent:3 gens: 26 26 26","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:07:04.254747957Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1201,"mrl":"dirty","":"mend"}
4882023-08-10T06:07:04.271Z{"msg":"extent:3 flush: 2017 2017 2017 scs: [0, 1, 2]","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:07:04.254807088Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1201,"mrl":"dirty","":"mend"}
4892023-08-10T06:07:04.274Z{"msg":"max_flush now has: [0, 1, 2]","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:07:04.254863863Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1201,"mrl":"dirty","":"mend"}
4902023-08-10T06:07:04.277Z{"msg":"extent:3 dirty: true true false","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:07:04.254920243Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1201,"mrl":"dirty","":"mend"}
4912023-08-10T06:07:04.280Z{"msg":"find dest for source 0 for extent at index 3","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:07:04.254977039Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1201,"mrl":"dirty","":"mend"}
4922023-08-10T06:07:04.283Z{"msg":"source 0, add dest 1 source flush","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:07:04.25503339Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1201,"mrl":"dirty","":"mend"}
4932023-08-10T06:07:04.286Z{"msg":"source 0, add dest 2 source flush","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:07:04.255090972Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1201,"mrl":"dirty","":"mend"}
4942023-08-10T06:07:04.289Z{"msg":"Extents 4 dirty","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:07:04.255147958Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1201,"":"mend"}
4952023-08-10T06:07:04.292Z{"msg":"First source client ID for extent 4","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:07:04.255208997Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1201,"mrl":"dirty","":"mend"}
4962023-08-10T06:07:04.295Z{"msg":"extent:4 gens: 26 26 26","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:07:04.255278539Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1201,"mrl":"dirty","":"mend"}
4972023-08-10T06:07:04.297Z{"msg":"extent:4 flush: 2017 2017 2017 scs: [0, 1, 2]","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:07:04.255340515Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1201,"mrl":"dirty","":"mend"}
4982023-08-10T06:07:04.300Z{"msg":"max_flush now has: [0, 1, 2]","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:07:04.255397517Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1201,"mrl":"dirty","":"mend"}
4992023-08-10T06:07:04.303Z{"msg":"extent:4 dirty: true true false","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:07:04.255454082Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1201,"mrl":"dirty","":"mend"}
5002023-08-10T06:07:04.306Z{"msg":"find dest for source 0 for extent at index 4","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:07:04.255510429Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1201,"mrl":"dirty","":"mend"}
5012023-08-10T06:07:04.309Z{"msg":"source 0, add dest 1 source flush","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:07:04.255566814Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1201,"mrl":"dirty","":"mend"}
5022023-08-10T06:07:04.312Z{"msg":"source 0, add dest 2 source flush","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:07:04.255631229Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1201,"mrl":"dirty","":"mend"}
5032023-08-10T06:07:04.315Z{"msg":"Transition from WaitQuorum to Repair","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:07:04.255689325Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1201}
5042023-08-10T06:07:04.318Z{"msg":"Transition from WaitQuorum to Repair","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:07:04.255744398Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1201}
5052023-08-10T06:07:04.320Z{"msg":"Transition from WaitQuorum to Repair","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:07:04.255799959Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1201}
5062023-08-10T06:07:04.323Z{"msg":"Found 4 extents that need repair","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:07:04.255855085Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1201}
5072023-08-10T06:07:04.326Z{"msg":"Full repair list: {4: ExtentFix { source: 0, dest: [1, 2] }, 3: ExtentFix { source: 0, dest: [1, 2] }, 1: ExtentFix { source: 0, dest: [1, 2] }, 2: ExtentFix { source: 0, dest: [1, 2] }}","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:07:04.255916802Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1201,"":"downstairs"}
5082023-08-10T06:07:04.329Z{"msg":"Task list: [ReconcileIO { id: 0, op: ExtentFlush { repair_id: 0, extent_id: 4, client_id: 0, flush_number: 2018, gen_number: 27 }, state: {1: New, 2: New, 0: New} }, ReconcileIO { id: 1, op: ExtentClose { repair_id: 1, extent_id: 4 }, state: {0: New, 1: New, 2: New} }, ReconcileIO { id: 2, op: ExtentRepair { repair_id: 2, extent_id: 4, source_client_id: 0, source_repair_address: 0.0.0.0:12810, dest_clients: [1, 2] }, state: {2: New, 0: New, 1: New} }, ReconcileIO { id: 3, op: ExtentReopen { repair_id: 3, extent_id: 4 }, state: {1: New, 0: New, 2: New} }, ReconcileIO { id: 4, op: ExtentFlush { repair_id: 4, extent_id: 3, client_id: 0, flush_number: 2018, gen_number: 27 }, state: {0: New, 2: New, 1: New} }, ReconcileIO { id: 5, op: ExtentClose { repair_id: 5, extent_id: 3 }, state: {1: New, 0: New, 2: New} }, ReconcileIO { id: 6, op: ExtentRepair { repair_id: 6, extent_id: 3, source_client_id: 0, source_repair_address: 0.0.0.0:12810, dest_clients: [1, 2] }, state: {1: New, 0: New, 2: New} }, ReconcileIO { id: 7, op: ExtentReopen { repair_id: 7, extent_id: 3 }, state: {1: New, 2: New, 0: New} }, ReconcileIO { id: 8, op: ExtentFlush { repair_id: 8, extent_id: 1, client_id: 0, flush_number: 2018, gen_number: 27 }, state: {2: New, 1: New, 0: New} }, ReconcileIO { id: 9, op: ExtentClose { repair_id: 9, extent_id: 1 }, state: {0: New, 1: New, 2: New} }, ReconcileIO { id: 10, op: ExtentRepair { repair_id: 10, extent_id: 1, source_client_id: 0, source_repair_address: 0.0.0.0:12810, dest_clients: [1, 2] }, state: {1: New, 2: New, 0: New} }, ReconcileIO { id: 11, op: ExtentReopen { repair_id: 11, extent_id: 1 }, state: {1: New, 0: New, 2: New} }, ReconcileIO { id: 12, op: ExtentFlush { repair_id: 12, extent_id: 2, client_id: 0, flush_number: 2018, gen_number: 27 }, state: {0: New, 1: New, 2: New} }, ReconcileIO { id: 13, op: ExtentClose { repair_id: 13, extent_id: 2 }, state: {1: New, 2: New, 0: New} }, ReconcileIO { id: 14, op: ExtentRepair { repair_id: 14, extent_id: 2, source_client_id: 0, source_repair_address: 0.0.0.0:12810, dest_clients: [1, 2] }, state: {1: New, 0: New, 2: New} }, ReconcileIO { id: 15, op: ExtentReopen { repair_id: 15, extent_id: 2 }, state: {0: New, 1: New, 2: New} }]","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:07:04.256051507Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1201,"":"downstairs"}
5092023-08-10T06:07:04.332Z{"msg":"Begin repair with 16 commands","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:07:04.256081545Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1201}
5102023-08-10T06:07:04.336Z{"msg":"Pop front: ReconcileIO { id: 0, op: ExtentFlush { repair_id: 0, extent_id: 4, client_id: 0, flush_number: 2018, gen_number: 27 }, state: {1: New, 2: New, 0: New} }","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:07:04.256109331Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1201}
5112023-08-10T06:07:04.338Z{"msg":"Sent repair work, now wait for resp","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:07:04.256139459Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1201}
5122023-08-10T06:07:04.341Z{"msg":"[2] received reconcile message","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:07:04.256159981Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1201}
5132023-08-10T06:07:04.344Z{"msg":"[2] rep_in_progress: return ReconcileIO { id: 0, op: ExtentFlush { repair_id: 0, extent_id: 4, client_id: 0, flush_number: 2018, gen_number: 27 }, state: {1: New, 2: InProgress, 0: New} }","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:07:04.256182478Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1201,"":"downstairs"}
5142023-08-10T06:07:04.347Z{"msg":"[0] received reconcile message","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:07:04.25620262Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1201}
5152023-08-10T06:07:04.349Z{"msg":"[2] client ExtentFlush { repair_id: 0, extent_id: 4, client_id: 0, flush_number: 2018, gen_number: 27 }","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:07:04.256223288Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1201}
5162023-08-10T06:07:04.352Z{"msg":"[0] rep_in_progress: return ReconcileIO { id: 0, op: ExtentFlush { repair_id: 0, extent_id: 4, client_id: 0, flush_number: 2018, gen_number: 27 }, state: {1: New, 2: InProgress, 0: InProgress} }","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:07:04.256245829Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1201,"":"downstairs"}
5172023-08-10T06:07:04.355Z{"msg":"[0] client ExtentFlush { repair_id: 0, extent_id: 4, client_id: 0, flush_number: 2018, gen_number: 27 }","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:07:04.256267754Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1201}
5182023-08-10T06:07:04.358Z{"msg":"[1] received reconcile message","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:07:04.256286201Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1201}
5192023-08-10T06:07:04.361Z{"msg":"[1] rep_in_progress: return ReconcileIO { id: 0, op: ExtentFlush { repair_id: 0, extent_id: 4, client_id: 0, flush_number: 2018, gen_number: 27 }, state: {1: InProgress, 2: Done, 0: InProgress} }","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:07:04.256309461Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1201,"":"downstairs"}
5202023-08-10T06:07:04.364Z{"msg":"[1] client ExtentFlush { repair_id: 0, extent_id: 4, client_id: 0, flush_number: 2018, gen_number: 27 }","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:07:04.256331871Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1201}
5212023-08-10T06:07:04.367Z{"msg":"Completion from [0] id:0 status:true","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:07:04.25968067Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1201}
5222023-08-10T06:07:04.370Z{"msg":"[1/16] Repair commands completed","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:07:04.259713019Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1201}
5232023-08-10T06:07:04.373Z{"msg":"Pop front: ReconcileIO { id: 1, op: ExtentClose { repair_id: 1, extent_id: 4 }, state: {0: New, 1: New, 2: New} }","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:07:04.2597354Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1201}
5242023-08-10T06:07:04.377Z{"msg":"Sent repair work, now wait for resp","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:07:04.259755099Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1201}
5252023-08-10T06:07:04.381Z{"msg":"[2] received reconcile message","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:07:04.259773865Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1201}
5262023-08-10T06:07:04.384Z{"msg":"[2] rep_in_progress: return ReconcileIO { id: 1, op: ExtentClose { repair_id: 1, extent_id: 4 }, state: {0: New, 1: New, 2: InProgress} }","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:07:04.259795339Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1201,"":"downstairs"}
5272023-08-10T06:07:04.387Z{"msg":"[2] client ExtentClose { repair_id: 1, extent_id: 4 }","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:07:04.259817259Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1201}
5282023-08-10T06:07:04.390Z{"msg":"[0] received reconcile message","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:07:04.259836215Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1201}
5292023-08-10T06:07:04.393Z{"msg":"[0] rep_in_progress: return ReconcileIO { id: 1, op: ExtentClose { repair_id: 1, extent_id: 4 }, state: {0: InProgress, 1: New, 2: InProgress} }","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:07:04.259857388Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1201,"":"downstairs"}
5302023-08-10T06:07:04.396Z{"msg":"[0] client ExtentClose { repair_id: 1, extent_id: 4 }","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:07:04.259877916Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1201}
5312023-08-10T06:07:04.399Z{"msg":"[1] received reconcile message","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:07:04.259916046Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1201}
5322023-08-10T06:07:04.401Z{"msg":"[1] rep_in_progress: return ReconcileIO { id: 1, op: ExtentClose { repair_id: 1, extent_id: 4 }, state: {0: InProgress, 1: InProgress, 2: InProgress} }","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:07:04.25995176Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1201,"":"downstairs"}
5332023-08-10T06:07:04.404Z{"msg":"[1] client ExtentClose { repair_id: 1, extent_id: 4 }","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:07:04.259975098Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1201}
5342023-08-10T06:07:04.407Z{"msg":"Completion from [1] id:1 status:true","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:07:04.263121779Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1201}
5352023-08-10T06:07:04.410Z{"msg":"[2/16] Repair commands completed","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:07:04.263161732Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1201}
5362023-08-10T06:07:04.413Z{"msg":"Pop front: ReconcileIO { id: 2, op: ExtentRepair { repair_id: 2, extent_id: 4, source_client_id: 0, source_repair_address: 0.0.0.0:12810, dest_clients: [1, 2] }, state: {2: New, 0: New, 1: New} }","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:07:04.263187885Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1201}
5372023-08-10T06:07:04.417Z{"msg":"Sent repair work, now wait for resp","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:07:04.263208264Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1201}
5382023-08-10T06:07:04.420Z{"msg":"[2] received reconcile message","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:07:04.263227652Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1201}
5392023-08-10T06:07:04.423Z{"msg":"[2] rep_in_progress: return ReconcileIO { id: 2, op: ExtentRepair { repair_id: 2, extent_id: 4, source_client_id: 0, source_repair_address: 0.0.0.0:12810, dest_clients: [1, 2] }, state: {2: InProgress, 0: New, 1: New} }","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:07:04.263251391Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1201,"":"downstairs"}
5402023-08-10T06:07:04.426Z{"msg":"[2] client ExtentRepair { repair_id: 2, extent_id: 4, source_client_id: 0, source_repair_address: 0.0.0.0:12810, dest_clients: [1, 2] }","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:07:04.263274655Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1201}
5412023-08-10T06:07:04.430Z{"msg":"[2] Sending repair request 2","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:07:04.263294016Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1201}
5422023-08-10T06:07:04.432Z{"msg":"[0] received reconcile message","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:07:04.263312528Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1201}
5432023-08-10T06:07:04.435Z{"msg":"[0] rep_in_progress: return ReconcileIO { id: 2, op: ExtentRepair { repair_id: 2, extent_id: 4, source_client_id: 0, source_repair_address: 0.0.0.0:12810, dest_clients: [1, 2] }, state: {2: InProgress, 0: InProgress, 1: New} }","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:07:04.263336248Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1201,"":"downstairs"}
5442023-08-10T06:07:04.439Z{"msg":"[1] received reconcile message","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:07:04.263356244Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1201}
5452023-08-10T06:07:04.442Z{"msg":"[0] client ExtentRepair { repair_id: 2, extent_id: 4, source_client_id: 0, source_repair_address: 0.0.0.0:12810, dest_clients: [1, 2] }","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:07:04.263377835Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1201}
5462023-08-10T06:07:04.445Z{"msg":"[0] No action required 2","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:07:04.263396612Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1201}
5472023-08-10T06:07:04.448Z{"msg":"[1] rep_in_progress: return ReconcileIO { id: 2, op: ExtentRepair { repair_id: 2, extent_id: 4, source_client_id: 0, source_repair_address: 0.0.0.0:12810, dest_clients: [1, 2] }, state: {2: InProgress, 0: InProgress, 1: InProgress} }","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:07:04.263420036Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1201,"":"downstairs"}
5482023-08-10T06:07:04.451Z{"msg":"[1] client ExtentRepair { repair_id: 2, extent_id: 4, source_client_id: 0, source_repair_address: 0.0.0.0:12810, dest_clients: [1, 2] }","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:07:04.263442645Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1201}
5492023-08-10T06:07:04.454Z{"msg":"[1] Sending repair request 2","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:07:04.26361193Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1201}
5502023-08-10T06:07:04.456Z{"msg":"Completion from [1] id:2 status:true","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:07:04.409048026Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1201}
5512023-08-10T06:07:04.459Z{"msg":"[3/16] Repair commands completed","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:07:04.409154835Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1201}
5522023-08-10T06:07:04.462Z{"msg":"Pop front: ReconcileIO { id: 3, op: ExtentReopen { repair_id: 3, extent_id: 4 }, state: {1: New, 0: New, 2: New} }","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:07:04.409189435Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1201}
5532023-08-10T06:07:04.465Z{"msg":"Sent repair work, now wait for resp","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:07:04.40925248Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1201}
5542023-08-10T06:07:04.468Z{"msg":"[2] received reconcile message","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:07:04.409317192Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1201}
5552023-08-10T06:07:04.471Z{"msg":"[2] rep_in_progress: return ReconcileIO { id: 3, op: ExtentReopen { repair_id: 3, extent_id: 4 }, state: {1: New, 0: New, 2: InProgress} }","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:07:04.409393766Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1201,"":"downstairs"}
5562023-08-10T06:07:04.474Z{"msg":"[2] client ExtentReopen { repair_id: 3, extent_id: 4 }","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:07:04.409473432Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1201}
5572023-08-10T06:07:04.477Z{"msg":"[0] received reconcile message","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:07:04.409513648Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1201}
5582023-08-10T06:07:04.479Z{"msg":"[0] rep_in_progress: return ReconcileIO { id: 3, op: ExtentReopen { repair_id: 3, extent_id: 4 }, state: {1: New, 0: InProgress, 2: InProgress} }","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:07:04.409585101Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1201,"":"downstairs"}
5592023-08-10T06:07:04.483Z{"msg":"[0] client ExtentReopen { repair_id: 3, extent_id: 4 }","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:07:04.409656069Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1201}
5602023-08-10T06:07:04.486Z{"msg":"[1] received reconcile message","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:07:04.40972659Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1201}
5612023-08-10T06:07:04.489Z{"msg":"[1] rep_in_progress: return ReconcileIO { id: 3, op: ExtentReopen { repair_id: 3, extent_id: 4 }, state: {1: InProgress, 0: InProgress, 2: InProgress} }","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:07:04.409772345Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1201,"":"downstairs"}
5622023-08-10T06:07:04.492Z{"msg":"[1] client ExtentReopen { repair_id: 3, extent_id: 4 }","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:07:04.409837142Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1201}
5632023-08-10T06:07:04.494Z{"msg":"Completion from [1] id:3 status:true","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:07:04.410470732Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1201}
5642023-08-10T06:07:04.497Z{"msg":"[4/16] Repair commands completed","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:07:04.410513157Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1201}
5652023-08-10T06:07:04.500Z{"msg":"Pop front: ReconcileIO { id: 4, op: ExtentFlush { repair_id: 4, extent_id: 3, client_id: 0, flush_number: 2018, gen_number: 27 }, state: {0: New, 2: New, 1: New} }","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:07:04.410555547Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1201}
5662023-08-10T06:07:04.503Z{"msg":"Sent repair work, now wait for resp","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:07:04.410592564Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1201}
5672023-08-10T06:07:04.506Z{"msg":"[2] received reconcile message","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:07:04.410630214Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1201}
5682023-08-10T06:07:04.509Z{"msg":"[2] rep_in_progress: return ReconcileIO { id: 4, op: ExtentFlush { repair_id: 4, extent_id: 3, client_id: 0, flush_number: 2018, gen_number: 27 }, state: {0: New, 2: InProgress, 1: New} }","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:07:04.410673985Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1201,"":"downstairs"}
5692023-08-10T06:07:04.513Z{"msg":"[2] client ExtentFlush { repair_id: 4, extent_id: 3, client_id: 0, flush_number: 2018, gen_number: 27 }","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:07:04.41071811Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1201}
5702023-08-10T06:07:04.516Z{"msg":"[1] received reconcile message","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:07:04.410744334Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1201}
5712023-08-10T06:07:04.518Z{"msg":"[1] rep_in_progress: return ReconcileIO { id: 4, op: ExtentFlush { repair_id: 4, extent_id: 3, client_id: 0, flush_number: 2018, gen_number: 27 }, state: {0: New, 2: Done, 1: InProgress} }","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:07:04.410767896Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1201,"":"downstairs"}
5722023-08-10T06:07:04.521Z{"msg":"[1] client ExtentFlush { repair_id: 4, extent_id: 3, client_id: 0, flush_number: 2018, gen_number: 27 }","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:07:04.41079075Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1201}
5732023-08-10T06:07:04.524Z{"msg":"[0] received reconcile message","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:07:04.410809815Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1201}
5742023-08-10T06:07:04.527Z{"msg":"[0] rep_in_progress: return ReconcileIO { id: 4, op: ExtentFlush { repair_id: 4, extent_id: 3, client_id: 0, flush_number: 2018, gen_number: 27 }, state: {0: InProgress, 2: Done, 1: Done} }","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:07:04.410832714Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1201,"":"downstairs"}
5752023-08-10T06:07:04.534Z{"msg":"[0] client ExtentFlush { repair_id: 4, extent_id: 3, client_id: 0, flush_number: 2018, gen_number: 27 }","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:07:04.410854448Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1201}
5762023-08-10T06:07:04.537Z{"msg":"Completion from [0] id:4 status:true","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:07:04.415938605Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1201}
5772023-08-10T06:07:04.540Z{"msg":"[5/16] Repair commands completed","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:07:04.415971406Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1201}
5782023-08-10T06:07:04.542Z{"msg":"Pop front: ReconcileIO { id: 5, op: ExtentClose { repair_id: 5, extent_id: 3 }, state: {1: New, 0: New, 2: New} }","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:07:04.415993406Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1201}
5792023-08-10T06:07:04.545Z{"msg":"Sent repair work, now wait for resp","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:07:04.416013139Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1201}
5802023-08-10T06:07:04.548Z{"msg":"[2] received reconcile message","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:07:04.416039435Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1201}
5812023-08-10T06:07:04.551Z{"msg":"[2] rep_in_progress: return ReconcileIO { id: 5, op: ExtentClose { repair_id: 5, extent_id: 3 }, state: {1: New, 0: New, 2: InProgress} }","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:07:04.416079943Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1201,"":"downstairs"}
5822023-08-10T06:07:04.554Z{"msg":"[2] client ExtentClose { repair_id: 5, extent_id: 3 }","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:07:04.416119448Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1201}
5832023-08-10T06:07:04.557Z{"msg":"[0] received reconcile message","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:07:04.416158408Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1201}
5842023-08-10T06:07:04.560Z{"msg":"[0] rep_in_progress: return ReconcileIO { id: 5, op: ExtentClose { repair_id: 5, extent_id: 3 }, state: {1: New, 0: InProgress, 2: InProgress} }","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:07:04.416200056Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1201,"":"downstairs"}
5852023-08-10T06:07:04.563Z{"msg":"[0] client ExtentClose { repair_id: 5, extent_id: 3 }","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:07:04.416241302Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1201}
5862023-08-10T06:07:04.566Z{"msg":"[1] received reconcile message","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:07:04.416264543Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1201}
5872023-08-10T06:07:04.569Z{"msg":"[1] rep_in_progress: return ReconcileIO { id: 5, op: ExtentClose { repair_id: 5, extent_id: 3 }, state: {1: InProgress, 0: InProgress, 2: InProgress} }","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:07:04.416287163Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1201,"":"downstairs"}
5882023-08-10T06:07:04.572Z{"msg":"[1] client ExtentClose { repair_id: 5, extent_id: 3 }","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:07:04.416307886Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1201}
5892023-08-10T06:07:04.575Z{"msg":"Completion from [1] id:5 status:true","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:07:04.419279579Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1201}
5902023-08-10T06:07:04.580Z{"msg":"[6/16] Repair commands completed","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:07:04.419310345Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1201}
5912023-08-10T06:07:04.583Z{"msg":"Pop front: ReconcileIO { id: 6, op: ExtentRepair { repair_id: 6, extent_id: 3, source_client_id: 0, source_repair_address: 0.0.0.0:12810, dest_clients: [1, 2] }, state: {1: New, 0: New, 2: New} }","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:07:04.419334263Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1201}
5922023-08-10T06:07:04.586Z{"msg":"Sent repair work, now wait for resp","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:07:04.419353965Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1201}
5932023-08-10T06:07:04.589Z{"msg":"[2] received reconcile message","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:07:04.419373603Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1201}
5942023-08-10T06:07:04.592Z{"msg":"[2] rep_in_progress: return ReconcileIO { id: 6, op: ExtentRepair { repair_id: 6, extent_id: 3, source_client_id: 0, source_repair_address: 0.0.0.0:12810, dest_clients: [1, 2] }, state: {1: New, 0: New, 2: InProgress} }","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:07:04.419397135Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1201,"":"downstairs"}
5952023-08-10T06:07:04.595Z{"msg":"[2] client ExtentRepair { repair_id: 6, extent_id: 3, source_client_id: 0, source_repair_address: 0.0.0.0:12810, dest_clients: [1, 2] }","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:07:04.419420478Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1201}
5962023-08-10T06:07:04.598Z{"msg":"[2] Sending repair request 6","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:07:04.419444265Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1201}
5972023-08-10T06:07:04.601Z{"msg":"[0] received reconcile message","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:07:04.419477732Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1201}
5982023-08-10T06:07:04.603Z{"msg":"[0] rep_in_progress: return ReconcileIO { id: 6, op: ExtentRepair { repair_id: 6, extent_id: 3, source_client_id: 0, source_repair_address: 0.0.0.0:12810, dest_clients: [1, 2] }, state: {1: New, 0: InProgress, 2: InProgress} }","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:07:04.419508225Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1201,"":"downstairs"}
5992023-08-10T06:07:04.606Z{"msg":"[0] client ExtentRepair { repair_id: 6, extent_id: 3, source_client_id: 0, source_repair_address: 0.0.0.0:12810, dest_clients: [1, 2] }","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:07:04.41953139Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1201}
6002023-08-10T06:07:04.609Z{"msg":"[0] No action required 6","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:07:04.419550582Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1201}
6012023-08-10T06:07:04.612Z{"msg":"[1] received reconcile message","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:07:04.419569277Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1201}
6022023-08-10T06:07:04.615Z{"msg":"[1] rep_in_progress: return ReconcileIO { id: 6, op: ExtentRepair { repair_id: 6, extent_id: 3, source_client_id: 0, source_repair_address: 0.0.0.0:12810, dest_clients: [1, 2] }, state: {1: InProgress, 0: Done, 2: InProgress} }","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:07:04.419592889Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1201,"":"downstairs"}
6032023-08-10T06:07:04.618Z{"msg":"[1] client ExtentRepair { repair_id: 6, extent_id: 3, source_client_id: 0, source_repair_address: 0.0.0.0:12810, dest_clients: [1, 2] }","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:07:04.419615139Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1201}
6042023-08-10T06:07:04.621Z{"msg":"[1] Sending repair request 6","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:07:04.419634353Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1201}
6052023-08-10T06:07:04.624Z{"msg":"Completion from [1] id:6 status:true","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:07:04.500284559Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1201}
6062023-08-10T06:07:04.627Z{"msg":"[7/16] Repair commands completed","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:07:04.500338709Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1201}
6072023-08-10T06:07:04.630Z{"msg":"Pop front: ReconcileIO { id: 7, op: ExtentReopen { repair_id: 7, extent_id: 3 }, state: {1: New, 2: New, 0: New} }","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:07:04.500361403Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1201}
6082023-08-10T06:07:04.633Z{"msg":"Sent repair work, now wait for resp","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:07:04.500381765Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1201}
6092023-08-10T06:07:04.637Z{"msg":"[2] received reconcile message","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:07:04.500400792Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1201}
6102023-08-10T06:07:04.640Z{"msg":"[2] rep_in_progress: return ReconcileIO { id: 7, op: ExtentReopen { repair_id: 7, extent_id: 3 }, state: {1: New, 2: InProgress, 0: New} }","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:07:04.500422444Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1201,"":"downstairs"}
6112023-08-10T06:07:04.644Z{"msg":"[2] client ExtentReopen { repair_id: 7, extent_id: 3 }","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:07:04.500455952Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1201}
6122023-08-10T06:07:04.646Z{"msg":"[0] received reconcile message","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:07:04.500488526Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1201}
6132023-08-10T06:07:04.650Z{"msg":"[0] rep_in_progress: return ReconcileIO { id: 7, op: ExtentReopen { repair_id: 7, extent_id: 3 }, state: {1: New, 2: InProgress, 0: InProgress} }","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:07:04.500513195Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1201,"":"downstairs"}
6142023-08-10T06:07:04.652Z{"msg":"[0] client ExtentReopen { repair_id: 7, extent_id: 3 }","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:07:04.500534759Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1201}
6152023-08-10T06:07:04.655Z{"msg":"[1] received reconcile message","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:07:04.500553621Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1201}
6162023-08-10T06:07:04.658Z{"msg":"[1] rep_in_progress: return ReconcileIO { id: 7, op: ExtentReopen { repair_id: 7, extent_id: 3 }, state: {1: InProgress, 2: InProgress, 0: InProgress} }","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:07:04.500574995Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1201,"":"downstairs"}
6172023-08-10T06:07:04.661Z{"msg":"[1] client ExtentReopen { repair_id: 7, extent_id: 3 }","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:07:04.500595329Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1201}
6182023-08-10T06:07:04.663Z{"msg":"Completion from [1] id:7 status:true","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:07:04.501586351Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1201}
6192023-08-10T06:07:04.666Z{"msg":"[8/16] Repair commands completed","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:07:04.501614738Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1201}
6202023-08-10T06:07:04.669Z{"msg":"Pop front: ReconcileIO { id: 8, op: ExtentFlush { repair_id: 8, extent_id: 1, client_id: 0, flush_number: 2018, gen_number: 27 }, state: {2: New, 1: New, 0: New} }","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:07:04.501637296Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1201}
6212023-08-10T06:07:04.672Z{"msg":"Sent repair work, now wait for resp","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:07:04.501727144Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1201}
6222023-08-10T06:07:04.674Z{"msg":"[2] received reconcile message","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:07:04.501768306Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1201}
6232023-08-10T06:07:04.677Z{"msg":"[2] rep_in_progress: return ReconcileIO { id: 8, op: ExtentFlush { repair_id: 8, extent_id: 1, client_id: 0, flush_number: 2018, gen_number: 27 }, state: {2: InProgress, 1: New, 0: New} }","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:07:04.501811593Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1201,"":"downstairs"}
6242023-08-10T06:07:04.680Z{"msg":"[0] received reconcile message","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:07:04.501849317Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1201}
6252023-08-10T06:07:04.683Z{"msg":"[2] client ExtentFlush { repair_id: 8, extent_id: 1, client_id: 0, flush_number: 2018, gen_number: 27 }","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:07:04.501888587Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1201}
6262023-08-10T06:07:04.686Z{"msg":"[0] rep_in_progress: return ReconcileIO { id: 8, op: ExtentFlush { repair_id: 8, extent_id: 1, client_id: 0, flush_number: 2018, gen_number: 27 }, state: {2: Done, 1: New, 0: InProgress} }","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:07:04.501928455Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1201,"":"downstairs"}
6272023-08-10T06:07:04.688Z{"msg":"[0] client ExtentFlush { repair_id: 8, extent_id: 1, client_id: 0, flush_number: 2018, gen_number: 27 }","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:07:04.501953367Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1201}
6282023-08-10T06:07:04.692Z{"msg":"[1] received reconcile message","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:07:04.501972576Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1201}
6292023-08-10T06:07:04.695Z{"msg":"[1] rep_in_progress: return ReconcileIO { id: 8, op: ExtentFlush { repair_id: 8, extent_id: 1, client_id: 0, flush_number: 2018, gen_number: 27 }, state: {2: Done, 1: InProgress, 0: InProgress} }","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:07:04.501995602Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1201,"":"downstairs"}
6302023-08-10T06:07:04.698Z{"msg":"[1] client ExtentFlush { repair_id: 8, extent_id: 1, client_id: 0, flush_number: 2018, gen_number: 27 }","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:07:04.502017134Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1201}
6312023-08-10T06:07:04.701Z{"msg":"Completion from [0] id:8 status:true","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:07:04.506670344Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1201}
6322023-08-10T06:07:04.704Z{"msg":"[9/16] Repair commands completed","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:07:04.506700083Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1201}
6332023-08-10T06:07:04.706Z{"msg":"Pop front: ReconcileIO { id: 9, op: ExtentClose { repair_id: 9, extent_id: 1 }, state: {0: New, 1: New, 2: New} }","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:07:04.50672192Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1201}
6342023-08-10T06:07:04.709Z{"msg":"Sent repair work, now wait for resp","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:07:04.506741936Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1201}
6352023-08-10T06:07:04.712Z{"msg":"[2] received reconcile message","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:07:04.506761346Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1201}
6362023-08-10T06:07:04.715Z{"msg":"[2] rep_in_progress: return ReconcileIO { id: 9, op: ExtentClose { repair_id: 9, extent_id: 1 }, state: {0: New, 1: New, 2: InProgress} }","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:07:04.506783319Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1201,"":"downstairs"}
6372023-08-10T06:07:04.718Z{"msg":"[2] client ExtentClose { repair_id: 9, extent_id: 1 }","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:07:04.506809135Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1201}
6382023-08-10T06:07:04.720Z{"msg":"[0] received reconcile message","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:07:04.506842833Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1201}
6392023-08-10T06:07:04.723Z{"msg":"[0] rep_in_progress: return ReconcileIO { id: 9, op: ExtentClose { repair_id: 9, extent_id: 1 }, state: {0: InProgress, 1: New, 2: InProgress} }","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:07:04.506871613Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1201,"":"downstairs"}
6402023-08-10T06:07:04.726Z{"msg":"[0] client ExtentClose { repair_id: 9, extent_id: 1 }","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:07:04.506893372Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1201}
6412023-08-10T06:07:04.729Z{"msg":"[1] received reconcile message","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:07:04.506912909Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1201}
6422023-08-10T06:07:04.732Z{"msg":"[1] rep_in_progress: return ReconcileIO { id: 9, op: ExtentClose { repair_id: 9, extent_id: 1 }, state: {0: InProgress, 1: InProgress, 2: InProgress} }","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:07:04.506935517Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1201,"":"downstairs"}
6432023-08-10T06:07:04.735Z{"msg":"[1] client ExtentClose { repair_id: 9, extent_id: 1 }","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:07:04.506956061Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1201}
6442023-08-10T06:07:04.738Z{"msg":"Completion from [1] id:9 status:true","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:07:04.509812035Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1201}
6452023-08-10T06:07:04.740Z{"msg":"[10/16] Repair commands completed","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:07:04.509843732Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1201}
6462023-08-10T06:07:04.743Z{"msg":"Pop front: ReconcileIO { id: 10, op: ExtentRepair { repair_id: 10, extent_id: 1, source_client_id: 0, source_repair_address: 0.0.0.0:12810, dest_clients: [1, 2] }, state: {1: New, 2: New, 0: New} }","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:07:04.50987888Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1201}
6472023-08-10T06:07:04.746Z{"msg":"Sent repair work, now wait for resp","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:07:04.509916746Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1201}
6482023-08-10T06:07:04.749Z{"msg":"[2] received reconcile message","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:07:04.509952364Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1201}
6492023-08-10T06:07:04.751Z{"msg":"[2] rep_in_progress: return ReconcileIO { id: 10, op: ExtentRepair { repair_id: 10, extent_id: 1, source_client_id: 0, source_repair_address: 0.0.0.0:12810, dest_clients: [1, 2] }, state: {1: New, 2: InProgress, 0: New} }","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:07:04.509997626Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1201,"":"downstairs"}
6502023-08-10T06:07:04.754Z{"msg":"[2] client ExtentRepair { repair_id: 10, extent_id: 1, source_client_id: 0, source_repair_address: 0.0.0.0:12810, dest_clients: [1, 2] }","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:07:04.510041666Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1201}
6512023-08-10T06:07:04.757Z{"msg":"[2] Sending repair request 10","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:07:04.510079575Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1201}
6522023-08-10T06:07:04.760Z{"msg":"[0] received reconcile message","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:07:04.510116233Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1201}
6532023-08-10T06:07:04.762Z{"msg":"[1] received reconcile message","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:07:04.510153412Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1201}
6542023-08-10T06:07:04.765Z{"msg":"[0] rep_in_progress: return ReconcileIO { id: 10, op: ExtentRepair { repair_id: 10, extent_id: 1, source_client_id: 0, source_repair_address: 0.0.0.0:12810, dest_clients: [1, 2] }, state: {1: New, 2: InProgress, 0: InProgress} }","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:07:04.510196867Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1201,"":"downstairs"}
6552023-08-10T06:07:04.768Z{"msg":"[0] client ExtentRepair { repair_id: 10, extent_id: 1, source_client_id: 0, source_repair_address: 0.0.0.0:12810, dest_clients: [1, 2] }","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:07:04.510224209Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1201}
6562023-08-10T06:07:04.770Z{"msg":"[0] No action required 10","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:07:04.510243354Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1201}
6572023-08-10T06:07:04.773Z{"msg":"[1] rep_in_progress: return ReconcileIO { id: 10, op: ExtentRepair { repair_id: 10, extent_id: 1, source_client_id: 0, source_repair_address: 0.0.0.0:12810, dest_clients: [1, 2] }, state: {1: InProgress, 2: InProgress, 0: InProgress} }","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:07:04.510267444Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1201,"":"downstairs"}
6582023-08-10T06:07:04.776Z{"msg":"[1] client ExtentRepair { repair_id: 10, extent_id: 1, source_client_id: 0, source_repair_address: 0.0.0.0:12810, dest_clients: [1, 2] }","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:07:04.510290752Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1201}
6592023-08-10T06:07:04.779Z{"msg":"[1] Sending repair request 10","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:07:04.510310002Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1201}
6602023-08-10T06:07:04.781Z{"msg":"Completion from [2] id:10 status:true","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:07:04.591326268Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1201}
6612023-08-10T06:07:04.784Z{"msg":"[11/16] Repair commands completed","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:07:04.591395145Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1201}
6622023-08-10T06:07:04.787Z{"msg":"Pop front: ReconcileIO { id: 11, op: ExtentReopen { repair_id: 11, extent_id: 1 }, state: {1: New, 0: New, 2: New} }","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:07:04.591418777Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1201}
6632023-08-10T06:07:04.790Z{"msg":"Sent repair work, now wait for resp","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:07:04.591438831Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1201}
6642023-08-10T06:07:04.793Z{"msg":"[2] received reconcile message","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:07:04.59145811Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1201}
6652023-08-10T06:07:04.795Z{"msg":"[2] rep_in_progress: return ReconcileIO { id: 11, op: ExtentReopen { repair_id: 11, extent_id: 1 }, state: {1: New, 0: New, 2: InProgress} }","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:07:04.59148094Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1201,"":"downstairs"}
6662023-08-10T06:07:04.798Z{"msg":"[2] client ExtentReopen { repair_id: 11, extent_id: 1 }","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:07:04.591514166Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1201}
6672023-08-10T06:07:04.801Z{"msg":"[0] received reconcile message","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:07:04.59154903Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1201}
6682023-08-10T06:07:04.804Z{"msg":"[0] rep_in_progress: return ReconcileIO { id: 11, op: ExtentReopen { repair_id: 11, extent_id: 1 }, state: {1: New, 0: InProgress, 2: InProgress} }","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:07:04.591576069Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1201,"":"downstairs"}
6692023-08-10T06:07:04.806Z{"msg":"[0] client ExtentReopen { repair_id: 11, extent_id: 1 }","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:07:04.591597393Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1201}
6702023-08-10T06:07:04.809Z{"msg":"[1] received reconcile message","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:07:04.591616151Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1201}
6712023-08-10T06:07:04.812Z{"msg":"[1] rep_in_progress: return ReconcileIO { id: 11, op: ExtentReopen { repair_id: 11, extent_id: 1 }, state: {1: InProgress, 0: InProgress, 2: InProgress} }","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:07:04.591638792Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1201,"":"downstairs"}
6722023-08-10T06:07:04.815Z{"msg":"[1] client ExtentReopen { repair_id: 11, extent_id: 1 }","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:07:04.591659824Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1201}
6732023-08-10T06:07:04.817Z{"msg":"Completion from [1] id:11 status:true","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:07:04.592827843Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1201}
6742023-08-10T06:07:04.820Z{"msg":"[12/16] Repair commands completed","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:07:04.592860604Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1201}
6752023-08-10T06:07:04.823Z{"msg":"Pop front: ReconcileIO { id: 12, op: ExtentFlush { repair_id: 12, extent_id: 2, client_id: 0, flush_number: 2018, gen_number: 27 }, state: {0: New, 1: New, 2: New} }","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:07:04.592884576Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1201}
6762023-08-10T06:07:04.826Z{"msg":"Sent repair work, now wait for resp","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:07:04.592904371Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1201}
6772023-08-10T06:07:04.829Z{"msg":"[2] received reconcile message","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:07:04.592926804Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1201}
6782023-08-10T06:07:04.831Z{"msg":"[2] rep_in_progress: return ReconcileIO { id: 12, op: ExtentFlush { repair_id: 12, extent_id: 2, client_id: 0, flush_number: 2018, gen_number: 27 }, state: {0: New, 1: New, 2: InProgress} }","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:07:04.592961727Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1201,"":"downstairs"}
6792023-08-10T06:07:04.834Z{"msg":"[2] client ExtentFlush { repair_id: 12, extent_id: 2, client_id: 0, flush_number: 2018, gen_number: 27 }","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:07:04.593002378Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1201}
6802023-08-10T06:07:04.837Z{"msg":"[0] received reconcile message","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:07:04.593025563Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1201}
6812023-08-10T06:07:04.839Z{"msg":"[1] received reconcile message","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:07:04.593045Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1201}
6822023-08-10T06:07:04.842Z{"msg":"[0] rep_in_progress: return ReconcileIO { id: 12, op: ExtentFlush { repair_id: 12, extent_id: 2, client_id: 0, flush_number: 2018, gen_number: 27 }, state: {0: InProgress, 1: New, 2: Done} }","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:07:04.593068786Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1201,"":"downstairs"}
6832023-08-10T06:07:04.845Z{"msg":"[0] client ExtentFlush { repair_id: 12, extent_id: 2, client_id: 0, flush_number: 2018, gen_number: 27 }","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:07:04.593090783Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1201}
6842023-08-10T06:07:04.848Z{"msg":"[1] rep_in_progress: return ReconcileIO { id: 12, op: ExtentFlush { repair_id: 12, extent_id: 2, client_id: 0, flush_number: 2018, gen_number: 27 }, state: {0: InProgress, 1: InProgress, 2: Done} }","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:07:04.593113809Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1201,"":"downstairs"}
6852023-08-10T06:07:04.851Z{"msg":"[1] client ExtentFlush { repair_id: 12, extent_id: 2, client_id: 0, flush_number: 2018, gen_number: 27 }","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:07:04.593142124Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1201}
6862023-08-10T06:07:04.853Z{"msg":"Completion from [0] id:12 status:true","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:07:04.597929041Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1201}
6872023-08-10T06:07:04.856Z{"msg":"[13/16] Repair commands completed","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:07:04.597963494Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1201}
6882023-08-10T06:07:04.859Z{"msg":"Pop front: ReconcileIO { id: 13, op: ExtentClose { repair_id: 13, extent_id: 2 }, state: {1: New, 2: New, 0: New} }","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:07:04.597986045Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1201}
6892023-08-10T06:07:04.862Z{"msg":"Sent repair work, now wait for resp","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:07:04.598005285Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1201}
6902023-08-10T06:07:04.864Z{"msg":"[2] received reconcile message","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:07:04.598025156Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1201}
6912023-08-10T06:07:04.867Z{"msg":"[2] rep_in_progress: return ReconcileIO { id: 13, op: ExtentClose { repair_id: 13, extent_id: 2 }, state: {1: New, 2: InProgress, 0: New} }","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:07:04.598047089Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1201,"":"downstairs"}
6922023-08-10T06:07:04.870Z{"msg":"[2] client ExtentClose { repair_id: 13, extent_id: 2 }","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:07:04.598068455Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1201}
6932023-08-10T06:07:04.873Z{"msg":"[0] received reconcile message","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:07:04.59809045Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1201}
6942023-08-10T06:07:04.876Z{"msg":"[0] rep_in_progress: return ReconcileIO { id: 13, op: ExtentClose { repair_id: 13, extent_id: 2 }, state: {1: New, 2: InProgress, 0: InProgress} }","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:07:04.598129664Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1201,"":"downstairs"}
6952023-08-10T06:07:04.878Z{"msg":"[0] client ExtentClose { repair_id: 13, extent_id: 2 }","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:07:04.598164894Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1201}
6962023-08-10T06:07:04.881Z{"msg":"[1] received reconcile message","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:07:04.598186451Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1201}
6972023-08-10T06:07:04.883Z{"msg":"[1] rep_in_progress: return ReconcileIO { id: 13, op: ExtentClose { repair_id: 13, extent_id: 2 }, state: {1: InProgress, 2: InProgress, 0: InProgress} }","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:07:04.598208888Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1201,"":"downstairs"}
6982023-08-10T06:07:04.886Z{"msg":"[1] client ExtentClose { repair_id: 13, extent_id: 2 }","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:07:04.59822932Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1201}
6992023-08-10T06:07:04.889Z{"msg":"Completion from [1] id:13 status:true","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:07:04.601496636Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1201}
7002023-08-10T06:07:04.892Z{"msg":"[14/16] Repair commands completed","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:07:04.601529954Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1201}
7012023-08-10T06:07:04.895Z{"msg":"Pop front: ReconcileIO { id: 14, op: ExtentRepair { repair_id: 14, extent_id: 2, source_client_id: 0, source_repair_address: 0.0.0.0:12810, dest_clients: [1, 2] }, state: {1: New, 0: New, 2: New} }","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:07:04.601554954Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1201}
7022023-08-10T06:07:04.897Z{"msg":"Sent repair work, now wait for resp","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:07:04.601574944Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1201}
7032023-08-10T06:07:04.900Z{"msg":"[2] received reconcile message","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:07:04.60159469Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1201}
7042023-08-10T06:07:04.903Z{"msg":"[2] rep_in_progress: return ReconcileIO { id: 14, op: ExtentRepair { repair_id: 14, extent_id: 2, source_client_id: 0, source_repair_address: 0.0.0.0:12810, dest_clients: [1, 2] }, state: {1: New, 0: New, 2: InProgress} }","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:07:04.601619395Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1201,"":"downstairs"}
7052023-08-10T06:07:04.905Z{"msg":"[2] client ExtentRepair { repair_id: 14, extent_id: 2, source_client_id: 0, source_repair_address: 0.0.0.0:12810, dest_clients: [1, 2] }","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:07:04.601651362Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1201}
7062023-08-10T06:07:04.908Z{"msg":"[2] Sending repair request 14","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:07:04.601687474Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1201}
7072023-08-10T06:07:04.911Z{"msg":"[0] received reconcile message","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:07:04.601711121Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1201}
7082023-08-10T06:07:04.914Z{"msg":"[0] rep_in_progress: return ReconcileIO { id: 14, op: ExtentRepair { repair_id: 14, extent_id: 2, source_client_id: 0, source_repair_address: 0.0.0.0:12810, dest_clients: [1, 2] }, state: {1: New, 0: InProgress, 2: InProgress} }","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:07:04.601735464Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1201,"":"downstairs"}
7092023-08-10T06:07:04.916Z{"msg":"[0] client ExtentRepair { repair_id: 14, extent_id: 2, source_client_id: 0, source_repair_address: 0.0.0.0:12810, dest_clients: [1, 2] }","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:07:04.601769283Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1201}
7102023-08-10T06:07:04.919Z{"msg":"[0] No action required 14","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:07:04.641594164Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1201}
7112023-08-10T06:07:04.922Z{"msg":"[1] received reconcile message","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:07:04.641646998Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1201}
7122023-08-10T06:07:04.924Z{"msg":"[1] rep_in_progress: return ReconcileIO { id: 14, op: ExtentRepair { repair_id: 14, extent_id: 2, source_client_id: 0, source_repair_address: 0.0.0.0:12810, dest_clients: [1, 2] }, state: {1: InProgress, 0: Done, 2: InProgress} }","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:07:04.641691194Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1201,"":"downstairs"}
7132023-08-10T06:07:04.927Z{"msg":"[1] client ExtentRepair { repair_id: 14, extent_id: 2, source_client_id: 0, source_repair_address: 0.0.0.0:12810, dest_clients: [1, 2] }","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:07:04.641737384Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1201}
7142023-08-10T06:07:04.930Z{"msg":"[1] Sending repair request 14","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:07:04.641774432Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1201}
7152023-08-10T06:07:04.933Z{"msg":"Completion from [2] id:14 status:true","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:07:04.685560572Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1201}
7162023-08-10T06:07:04.936Z{"msg":"[15/16] Repair commands completed","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:07:04.685608172Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1201}
7172023-08-10T06:07:04.938Z{"msg":"Pop front: ReconcileIO { id: 15, op: ExtentReopen { repair_id: 15, extent_id: 2 }, state: {0: New, 1: New, 2: New} }","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:07:04.685632349Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1201}
7182023-08-10T06:07:04.941Z{"msg":"Sent repair work, now wait for resp","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:07:04.685652705Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1201}
7192023-08-10T06:07:04.944Z{"msg":"[2] received reconcile message","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:07:04.685671859Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1201}
7202023-08-10T06:07:04.946Z{"msg":"[2] rep_in_progress: return ReconcileIO { id: 15, op: ExtentReopen { repair_id: 15, extent_id: 2 }, state: {0: New, 1: New, 2: InProgress} }","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:07:04.685694053Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1201,"":"downstairs"}
7212023-08-10T06:07:04.949Z{"msg":"[2] client ExtentReopen { repair_id: 15, extent_id: 2 }","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:07:04.685715596Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1201}
7222023-08-10T06:07:04.952Z{"msg":"[0] received reconcile message","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:07:04.68573462Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1201}
7232023-08-10T06:07:04.955Z{"msg":"[0] rep_in_progress: return ReconcileIO { id: 15, op: ExtentReopen { repair_id: 15, extent_id: 2 }, state: {0: InProgress, 1: New, 2: InProgress} }","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:07:04.685757541Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1201,"":"downstairs"}
7242023-08-10T06:07:04.957Z{"msg":"[0] client ExtentReopen { repair_id: 15, extent_id: 2 }","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:07:04.685784587Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1201}
7252023-08-10T06:07:04.960Z{"msg":"[1] received reconcile message","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:07:04.685819534Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1201}
7262023-08-10T06:07:04.963Z{"msg":"[1] rep_in_progress: return ReconcileIO { id: 15, op: ExtentReopen { repair_id: 15, extent_id: 2 }, state: {0: InProgress, 1: InProgress, 2: InProgress} }","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:07:04.685861907Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1201,"":"downstairs"}
7272023-08-10T06:07:04.974Z{"msg":"[1] client ExtentReopen { repair_id: 15, extent_id: 2 }","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:07:04.685904324Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1201}
7282023-08-10T06:07:04.977Z{"msg":"Completion from [0] id:15 status:true","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:07:04.68699125Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1201}
7292023-08-10T06:07:04.979Z{"msg":"[16/16] Repair commands completed","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:07:04.687028228Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1201}
7302023-08-10T06:07:04.982Z{"msg":"4 extents repaired in 0.433 ave:0.1082","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:07:04.687049474Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1201}
7312023-08-10T06:07:04.984Z{"msg":"All required repair work is completed","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:07:04.687069005Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1201}
7322023-08-10T06:07:04.987Z{"msg":"Set Downstairs and Upstairs active after repairs","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:07:04.687088079Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1201}
7332023-08-10T06:07:04.990Z{"msg":"6aac1c0a-c22f-4cb2-8a7b-6a31d4c53787 is now active with session: 8659a9be-e58c-4b73-8575-5390f69a5fbc","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:07:04.687109717Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1201}
7342023-08-10T06:07:04.992Z{"msg":"Notify all downstairs, region set compare is done.","v":0,"name":"crucible","level"The guest has finished waiting for activation with:28
7352023-08-10T06:07:04.995Z:30Wait for a query_work_queue command to finish before sending IO
7362023-08-10T06:07:04.998Z,"time":"2023-08-10T06:07:04.687135642Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1201}
7372023-08-10T06:07:05.002Z{"msg":"Set check for repair","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:07:04.687170127Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1201}
7382023-08-10T06:07:05.005Z{"msg":"[0] received reconcile message","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:07:04.687316562Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1201}
7392023-08-10T06:07:05.008Z{"msg":"[1] received reconcile message","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:07:04.68734657Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1201}
7402023-08-10T06:07:05.011Z{"msg":"[2] received reconcile message","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:07:04.687365421Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1201}
7412023-08-10T06:07:05.014Z{"msg":"[0] All repairs completed, exit","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:07:04.687750231Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1201}
7422023-08-10T06:07:05.016Z{"msg":"[2] All repairs completed, exit","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:07:04.68784782Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1201}
7432023-08-10T06:07:05.019Z{"msg":"[0] Starts cmd_loop","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:07:04.68788037Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1201}
7442023-08-10T06:07:05.022Z{"msg":"[2] Starts cmd_loop","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:07:04.687899734Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1201}
7452023-08-10T06:07:05.025Z{"msg":"[1] All repairs completed, exit","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:07:04.687918621Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1201}
7462023-08-10T06:07:05.028Z{"msg":"[1] Starts cmd_loop","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:07:04.687936908Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1201}
7472023-08-10T06:07:05.031ZRegion: es:10 ec:5 bs:4096 ts:204800 tb:50 max_io:50 or 204800
7482023-08-10T06:07:05.034ZLoading write count information from file "/var/tmp/test_up/verify_file"
7492023-08-10T06:07:05.036ZRead and Verify all blocks (0..50 range:false)
7502023-08-10T06:07:05.040ZWrote out file "/var/tmp/test_up/verify_file"
7512023-08-10T06:07:05.043ZVerify test completed
7522023-08-10T06:07:05.046ZWrote out file "/var/tmp/test_up/verify_file"
7532023-08-10T06:07:05.049ZCLIENT: Tests done. All submitted work has been ACK'd
7542023-08-10T06:07:05.052Z----------------------------------------------------------------
7552023-08-10T06:07:05.055Z Crucible gen:28 GIO:true work queues: Upstairs:1 downstairs:2
7562023-08-10T06:07:05.059ZGW_ID ACK DSID TYPE BLOCKS DS:0 DS:1 DS:2 REPLAY
7572023-08-10T06:07:05.063Z 1 Acked 1000 Read 50 Done Done Done false
7582023-08-10T06:07:05.066Z 2 NotAcked 1001 Flush 0 Sent Sent Sent false
7592023-08-10T06:07:05.069Z STATES DS:0 DS:1 DS:2 TOTAL
7602023-08-10T06:07:05.072Z New 0 0 0 0
7612023-08-10T06:07:05.077Z Sent 1 1 1 3
7622023-08-10T06:07:05.080Z Done 1 1 1 3
7632023-08-10T06:07:05.083Z Skipped 0 0 0 0
7642023-08-10T06:07:05.087Z Error 0 0 0 0
7652023-08-10T06:07:05.090ZLast Flush: 0 0 0
7662023-08-10T06:07:05.096ZDownstairs last five completed:
7672023-08-10T06:07:05.100ZUpstairs last five completed: 1
7682023-08-10T06:07:05.105ZCLIENT: Up:1 ds:2 act:3
7692023-08-10T06:07:05.574Z{"msg":"Checking if live repair is needed","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:07:05.688546929Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1201}
7702023-08-10T06:07:05.577Z{"msg":"No Live Repair required at this time","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:07:05.68864259Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1201}
7712023-08-10T06:07:08.827Z----------------------------------------------------------------
7722023-08-10T06:07:08.830Z Crucible gen:28 GIO:true work queues: Upstairs:0 downstairs:0
7732023-08-10T06:07:08.834ZDownstairs last five completed: 1001 1000
7742023-08-10T06:07:08.837ZUpstairs last five completed: 2 1
7752023-08-10T06:07:08.840ZCLIENT: Up:0 ds:0 act:3
7762023-08-10T06:07:08.843ZCLIENT: All crucible jobs finished, exiting program
7772023-08-10T06:07:08.846ZRepair part 2 passed
7782023-08-10T06:07:08.849Z/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
7792023-08-10T06:07:08.853Z{"msg":"current number of open files limit 65536 is already the maximum","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:07:08.969861028Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1203}
7802023-08-10T06:07:08.856Z{"msg":"Database read version 1","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:07:08.970227069Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1203}
7812023-08-10T06:07:08.858Z{"msg":"Database write version 1","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:07:08.970254501Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1203}
7822023-08-10T06:07:08.862Z{"msg":"current number of open files limit 65536 is already the maximum","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:07:08.974406945Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1203}
7832023-08-10T06:07:08.865Z{"msg":"Database read version 1","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:07:08.974458608Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1203}
7842023-08-10T06:07:08.868Z{"msg":"Database write version 1","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:07:08.974501969Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1203}
7852023-08-10T06:07:08.871Z{"msg":"current number of open files limit 65536 is already the maximum","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:07:08.976324458Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1203}
7862023-08-10T06:07:08.873Z{"msg":"Database read version 1","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:07:08.976374583Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1203}
7872023-08-10T06:07:08.876Z{"msg":"Database write version 1","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:07:08.976417385Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1203}
7882023-08-10T06:07:08.879ZEXT BLOCKS GEN0 GEN1 GEN2 FL0 FL1 FL2 D0 D1 D2 DIFF
7892023-08-10T06:07:08.882Z 0 000-009 26 26 26 2017 2017 2017 F F F
7902023-08-10T06:07:08.884Z 1 010-019 27 27 27 2018 2018 2018 F F F
7912023-08-10T06:07:08.887Z 2 020-029 27 27 27 2018 2018 2018 F F F
7922023-08-10T06:07:08.890Z 3 030-039 27 27 27 2018 2018 2018 F F F
7932023-08-10T06:07:08.893Z 4 040-049 27 27 27 2018 2018 2018 F F F
7942023-08-10T06:07:08.896ZMax gen: 27, Max flush: 2018
7952023-08-10T06:07:08.899Zdump test passed
7962023-08-10T06:07:08.902Z/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
7972023-08-10T06:07:08.905Z{"msg":"current number of open files limit 65536 is already the maximum","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:07:09.000379047Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1204}
7982023-08-10T06:07:08.908Z{"msg":"Database read version 1","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:07:09.000674855Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1204}
7992023-08-10T06:07:08.910Z{"msg":"Database write version 1","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:07:09.00072579Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1204}
8002023-08-10T06:07:08.914Z{"msg":"current number of open files limit 65536 is already the maximum","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:07:09.004120976Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1204}
8012023-08-10T06:07:08.917Z{"msg":"Database read version 1","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:07:09.004184449Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1204}
8022023-08-10T06:07:08.920Z{"msg":"Database write version 1","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:07:09.004229234Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1204}
8032023-08-10T06:07:08.923Z{"msg":"current number of open files limit 65536 is already the maximum","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:07:09.005770703Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1204}
8042023-08-10T06:07:08.926Z{"msg":"Database read version 1","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:07:09.005825959Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1204}
8052023-08-10T06:07:08.929Z{"msg":"Database write version 1","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:07:09.005869014Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1204}
8062023-08-10T06:07:08.932Z Extent 1
8072023-08-10T06:07:08.934ZGEN 27 27 27
8082023-08-10T06:07:08.937ZFLUSH_ID 2018 2018 2018
8092023-08-10T06:07:08.940ZDIRTY
8102023-08-10T06:07:08.943Z
8112023-08-10T06:07:08.946ZBLOCK D0 D1 D2 C0 C1 C2 DIFF
8122023-08-10T06:07:08.949Z{"msg":"current number of open files limit 65536 is already the maximum","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:07:09.007539201Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1204}
8132023-08-10T06:07:08.951Z{"msg":"Database read version 1","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:07:09.007590011Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1204}
8142023-08-10T06:07:08.955Z{"msg":"Database write version 1","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:07:09.007650388Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1204}
8152023-08-10T06:07:08.958Z{"msg":"current number of open files limit 65536 is already the maximum","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:07:09.009422762Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1204}
8162023-08-10T06:07:08.961Z{"msg":"Database read version 1","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:07:09.009476278Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1204}
8172023-08-10T06:07:08.964Z{"msg":"Database write version 1","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:07:09.009519313Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1204}
8182023-08-10T06:07:08.967Z{"msg":"current number of open files limit 65536 is already the maximum","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:07:09.011073463Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1204}
8192023-08-10T06:07:08.969Z{"msg":"Database read version 1","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:07:09.011144722Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1204}
8202023-08-10T06:07:08.972Z{"msg":"Database write version 1","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:07:09.011197054Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1204}
8212023-08-10T06:07:08.975Z010 A A A A A A
8222023-08-10T06:07:08.978Z{"msg":"current number of open files limit 65536 is already the maximum","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:07:09.013310143Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1204}
8232023-08-10T06:07:08.981Z{"msg":"Database read version 1","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:07:09.013362268Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1204}
8242023-08-10T06:07:08.984Z{"msg":"Database write version 1","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:07:09.013405241Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1204}
8252023-08-10T06:07:08.987Z{"msg":"current number of open files limit 65536 is already the maximum","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:07:09.015005893Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1204}
8262023-08-10T06:07:08.990Z{"msg":"Database read version 1","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:07:09.015058886Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1204}
8272023-08-10T06:07:08.993Z{"msg":"Database write version 1","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:07:09.015101646Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1204}
8282023-08-10T06:07:08.996Z{"msg":"current number of open files limit 65536 is already the maximum","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:07:09.016635188Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1204}
8292023-08-10T06:07:08.999Z{"msg":"Database read version 1","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:07:09.016689922Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1204}
8302023-08-10T06:07:09.002Z{"msg":"Database write version 1","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:07:09.016733008Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1204}
8312023-08-10T06:07:09.005Z011 A A A A A A
8322023-08-10T06:07:09.008Z{"msg":"current number of open files limit 65536 is already the maximum","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:07:09.018290063Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1204}
8332023-08-10T06:07:09.011Z{"msg":"Database read version 1","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:07:09.018341758Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1204}
8342023-08-10T06:07:09.014Z{"msg":"Database write version 1","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:07:09.018363929Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1204}
8352023-08-10T06:07:09.017Z{"msg":"current number of open files limit 65536 is already the maximum","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:07:09.019908648Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1204}
8362023-08-10T06:07:09.020Z{"msg":"Database read version 1","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:07:09.019960724Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1204}
8372023-08-10T06:07:09.023Z{"msg":"Database write version 1","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:07:09.020003326Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1204}
8382023-08-10T06:07:09.025Z{"msg":"current number of open files limit 65536 is already the maximum","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:07:09.021515678Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1204}
8392023-08-10T06:07:09.028Z{"msg":"Database read version 1","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:07:09.021566885Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1204}
8402023-08-10T06:07:09.031Z{"msg":"Database write version 1","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:07:09.02160992Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1204}
8412023-08-10T06:07:09.034Z012 A A A A A A
8422023-08-10T06:07:09.036Z{"msg":"current number of open files limit 65536 is already the maximum","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:07:09.023183209Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1204}
8432023-08-10T06:07:09.039Z{"msg":"Database read version 1","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:07:09.023238431Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1204}
8442023-08-10T06:07:09.042Z{"msg":"Database write version 1","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:07:09.023281468Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1204}
8452023-08-10T06:07:09.045Z{"msg":"current number of open files limit 65536 is already the maximum","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:07:09.024790552Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1204}
8462023-08-10T06:07:09.048Z{"msg":"Database read version 1","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:07:09.024841505Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1204}
8472023-08-10T06:07:09.050Z{"msg":"Database write version 1","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:07:09.024884076Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1204}
8482023-08-10T06:07:09.053Z{"msg":"current number of open files limit 65536 is already the maximum","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:07:09.026397123Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1204}
8492023-08-10T06:07:09.056Z{"msg":"Database read version 1","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:07:09.026450244Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1204}
8502023-08-10T06:07:09.059Z{"msg":"Database write version 1","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:07:09.026493275Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1204}
8512023-08-10T06:07:09.062Z013 A A A A A A
8522023-08-10T06:07:09.065Z{"msg":"current number of open files limit 65536 is already the maximum","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:07:09.028103482Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1204}
8532023-08-10T06:07:09.067Z{"msg":"Database read version 1","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:07:09.028175726Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1204}
8542023-08-10T06:07:09.070Z{"msg":"Database write version 1","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:07:09.028223046Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1204}
8552023-08-10T06:07:09.073Z{"msg":"current number of open files limit 65536 is already the maximum","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:07:09.029698838Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1204}
8562023-08-10T06:07:09.076Z{"msg":"Database read version 1","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:07:09.029751197Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1204}
8572023-08-10T06:07:09.079Z{"msg":"Database write version 1","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:07:09.02979371Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1204}
8582023-08-10T06:07:09.082Z{"msg":"current number of open files limit 65536 is already the maximum","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:07:09.031307156Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1204}
8592023-08-10T06:07:09.085Z{"msg":"Database read version 1","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:07:09.031359611Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1204}
8602023-08-10T06:07:09.088Z{"msg":"Database write version 1","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:07:09.031402444Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1204}
8612023-08-10T06:07:09.091Z014 A A A A A A
8622023-08-10T06:07:09.094Z{"msg":"current number of open files limit 65536 is already the maximum","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:07:09.032959234Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1204}
8632023-08-10T06:07:09.096Z{"msg":"Database read version 1","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:07:09.033011409Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1204}
8642023-08-10T06:07:09.100Z{"msg":"Database write version 1","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:07:09.033054042Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1204}
8652023-08-10T06:07:09.102Z{"msg":"current number of open files limit 65536 is already the maximum","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:07:09.034598627Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1204}
8662023-08-10T06:07:09.105Z{"msg":"Database read version 1","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:07:09.034650373Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1204}
8672023-08-10T06:07:09.108Z{"msg":"Database write version 1","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:07:09.034672231Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1204}
8682023-08-10T06:07:09.111Z{"msg":"current number of open files limit 65536 is already the maximum","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:07:09.03621075Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1204}
8692023-08-10T06:07:09.114Z{"msg":"Database read version 1","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:07:09.036241067Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1204}
8702023-08-10T06:07:09.117Z{"msg":"Database write version 1","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:07:09.036259858Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1204}
8712023-08-10T06:07:09.119Z015 A A A A A A
8722023-08-10T06:07:09.122Z{"msg":"current number of open files limit 65536 is already the maximum","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:07:09.03784644Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1204}
8732023-08-10T06:07:09.125Z{"msg":"Database read version 1","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:07:09.03787447Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1204}
8742023-08-10T06:07:09.128Z{"msg":"Database write version 1","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:07:09.037893408Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1204}
8752023-08-10T06:07:09.131Z{"msg":"current number of open files limit 65536 is already the maximum","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:07:09.039480373Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1204}
8762023-08-10T06:07:09.134Z{"msg":"Database read version 1","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:07:09.03950722Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1204}
8772023-08-10T06:07:09.136Z{"msg":"Database write version 1","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:07:09.039526382Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1204}
8782023-08-10T06:07:09.139Z{"msg":"current number of open files limit 65536 is already the maximum","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:07:09.041095368Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1204}
8792023-08-10T06:07:09.142Z{"msg":"Database read version 1","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:07:09.041126183Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1204}
8802023-08-10T06:07:09.145Z{"msg":"Database write version 1","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:07:09.041158411Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1204}
8812023-08-10T06:07:09.148Z016 A A A A A A
8822023-08-10T06:07:09.151Z{"msg":"current number of open files limit 65536 is already the maximum","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:07:09.042783451Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1204}
8832023-08-10T06:07:09.154Z{"msg":"Database read version 1","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:07:09.042810538Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1204}
8842023-08-10T06:07:09.157Z{"msg":"Database write version 1","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:07:09.042828986Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1204}
8852023-08-10T06:07:09.160Z{"msg":"current number of open files limit 65536 is already the maximum","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:07:09.044397892Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1204}
8862023-08-10T06:07:09.162Z{"msg":"Database read version 1","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:07:09.044426676Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1204}
8872023-08-10T06:07:09.165Z{"msg":"Database write version 1","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:07:09.044444897Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1204}
8882023-08-10T06:07:09.168Z{"msg":"current number of open files limit 65536 is already the maximum","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:07:09.046002866Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1204}
8892023-08-10T06:07:09.171Z{"msg":"Database read version 1","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:07:09.046029564Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1204}
8902023-08-10T06:07:09.173Z{"msg":"Database write version 1","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:07:09.046048641Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1204}
8912023-08-10T06:07:09.176Z017 A A A A A A
8922023-08-10T06:07:09.181Z{"msg":"current number of open files limit 65536 is already the maximum","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:07:09.04764313Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1204}
8932023-08-10T06:07:09.185Z{"msg":"Database read version 1","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:07:09.047673963Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1204}
8942023-08-10T06:07:09.188Z{"msg":"Database write version 1","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:07:09.047693305Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1204}
8952023-08-10T06:07:09.190Z{"msg":"current number of open files limit 65536 is already the maximum","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:07:09.049254867Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1204}
8962023-08-10T06:07:09.193Z{"msg":"Database read version 1","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:07:09.049283369Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1204}
8972023-08-10T06:07:09.196Z{"msg":"Database write version 1","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:07:09.049302542Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1204}
8982023-08-10T06:07:09.199Z{"msg":"current number of open files limit 65536 is already the maximum","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:07:09.050856167Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1204}
8992023-08-10T06:07:09.202Z{"msg":"Database read version 1","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:07:09.050884076Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1204}
9002023-08-10T06:07:09.204Z{"msg":"Database write version 1","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:07:09.050902906Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1204}
9012023-08-10T06:07:09.207Z018 A A A A A A
9022023-08-10T06:07:09.210Z{"msg":"current number of open files limit 65536 is already the maximum","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:07:09.052485866Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1204}
9032023-08-10T06:07:09.213Z{"msg":"Database read version 1","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:07:09.052523684Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1204}
9042023-08-10T06:07:09.216Z{"msg":"Database write version 1","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:07:09.052544591Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1204}
9052023-08-10T06:07:09.219Z{"msg":"current number of open files limit 65536 is already the maximum","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:07:09.054095663Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1204}
9062023-08-10T06:07:09.221Z{"msg":"Database read version 1","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:07:09.054122479Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1204}
9072023-08-10T06:07:09.224Z{"msg":"Database write version 1","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:07:09.054152595Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1204}
9082023-08-10T06:07:09.227Z{"msg":"current number of open files limit 65536 is already the maximum","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:07:09.0557529Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1204}
9092023-08-10T06:07:09.230Z{"msg":"Database read version 1","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:07:09.0557826Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1204}
9102023-08-10T06:07:09.233Z{"msg":"Database write version 1","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:07:09.055801619Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1204}
9112023-08-10T06:07:09.236Z019 A A A A A A
9122023-08-10T06:07:09.239Zdump extent test passed
9132023-08-10T06:07:09.241Z/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
9142023-08-10T06:07:09.244Z{"msg":"current number of open files limit 65536 is already the maximum","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:07:09.08151056Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1205}
9152023-08-10T06:07:09.247Z{"msg":"Database read version 1","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:07:09.081862563Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1205}
9162023-08-10T06:07:09.249Z{"msg":"Database write version 1","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:07:09.081887724Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1205}
9172023-08-10T06:07:09.252Z{"msg":"current number of open files limit 65536 is already the maximum","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:07:09.085407806Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1205}
9182023-08-10T06:07:09.254Z{"msg":"Database read version 1","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:07:09.085439357Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1205}
9192023-08-10T06:07:09.257Z{"msg":"Database write version 1","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:07:09.085457975Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1205}
9202023-08-10T06:07:09.260Z{"msg":"current number of open files limit 65536 is already the maximum","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:07:09.087122383Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1205}
9212023-08-10T06:07:09.263Z{"msg":"Database read version 1","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:07:09.087209431Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1205}
9222023-08-10T06:07:09.265Z{"msg":"Database write version 1","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:07:09.087231091Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1205}
9232023-08-10T06:07:09.268ZExtent 2 Block in extent 0 Actual block 20
9242023-08-10T06:07:09.271Z
9252023-08-10T06:07:09.273Z{"msg":"current number of open files limit 65536 is already the maximum","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:07:09.088735335Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1205}
9262023-08-10T06:07:09.446Z{"msg":"Database read version 1","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:07:09.088762948Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1205}
9272023-08-10T06:07:09.449Z{"msg":"Database write version 1","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:07:09.088781842Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1205}
9282023-08-10T06:07:09.452Z{"msg":"current number of open files limit 65536 is already the maximum","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:07:09.090640783Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1205}
9292023-08-10T06:07:09.455Z
9302023-08-10T06:07:09.458Z{"msg":"Database read version 1","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:07:09.090671305Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1205}
9312023-08-10T06:07:09.461Zreal 5:43.055955898
9322023-08-10T06:07:09.464Z{"msg":"Database write version 1","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:07:09.090689846Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1205}
9332023-08-10T06:07:09.467Zuser 4:36.373513163
9342023-08-10T06:07:09.469Z{"msg":"current number of open files limit 65536 is already the maximum","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:07:09.092279756Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1205}
9352023-08-10T06:07:09.472Zsys 23.444112608
9362023-08-10T06:07:09.475Z{"msg":"Database read version 1","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:07:09.092306403Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1205}
9372023-08-10T06:07:09.477Ztrap 0.330674163
9382023-08-10T06:07:09.480Z{"msg":"Database write version 1","v":0,"name":"crucible","level":30,"time":"2023-08-10T06:07:09.092325003Z","hostname":"ip-10-150-1-162.us-west-2.compute.internal","pid":1205}
9392023-08-10T06:07:09.483Ztflt 0.148079149
9402023-08-10T06:07:09.486Z DATA SHA256 VER
9412023-08-10T06:07:09.488Zdflt 0.047232643
9422023-08-10T06:07:09.491Z------ ---------------------------------------------------------------- ---
9432023-08-10T06:07:09.494Zkflt 0.001212589
9442023-08-10T06:07:09.497Z 0 b4f5ee008c8fe786954d733e17bd9197c20450ac551bda64d79e60d9979d2a8b A
9452023-08-10T06:07:09.499Zlock 53:06.385727177
9462023-08-10T06:07:09.502Z 1 b4f5ee008c8fe786954d733e17bd9197c20450ac551bda64d79e60d9979d2a8b A
9472023-08-10T06:07:09.506Zslp 10:46.700548274
9482023-08-10T06:07:09.509Z 2 b4f5ee008c8fe786954d733e17bd9197c20450ac551bda64d79e60d9979d2a8b A
9492023-08-10T06:07:09.511Zlat 19.043094756
9502023-08-10T06:07:09.514Z
9512023-08-10T06:07:09.517Zstop 0.030080998
9522023-08-10T06:07:09.519ZNONCES 0 1 2 DIFF
9532023-08-10T06:07:09.522Z------ ------------------------ ------------------------ ------------------------ -----
9542023-08-10T06:07:09.525Z 0 b0415b57bd56819fbefad691 b0415b57bd56819fbefad691 b0415b57bd56819fbefad691
9552023-08-10T06:07:09.528Z
9562023-08-10T06:07:09.530Z TAGS 0 1 2 DIFF
9572023-08-10T06:07:09.533Z------ -------------------------------- -------------------------------- -------------------------------- -----
9582023-08-10T06:07:09.536Z 0 561a93fe052ba11f0d335bf7e9cdaee7 561a93fe052ba11f0d335bf7e9cdaee7 561a93fe052ba11f0d335bf7e9cdaee7
9592023-08-10T06:07:09.538Z
9602023-08-10T06:07:09.541ZHASHES 0 1 2 DIFF
9612023-08-10T06:07:09.544Z------ ---------------- ---------------- ---------------- -----
9622023-08-10T06:07:09.547Z 0 ab94edde9aa0240e ab94edde9aa0240e ab94edde9aa0240e
9632023-08-10T06:07:09.549Z
9642023-08-10T06:07:09.552Zdump block test passed
9652023-08-10T06:07:09.555ZUpstairs tests have completed, stopping all downstairs
9662023-08-10T06:07:09.557Z
9672023-08-10T06:07:09.560ZAll Tests have passed
9682023-08-10T06:07:09.563Z5:44 Test duration
9692023-08-10T06:07:09.566Zprocess exited: duration 355172 ms, exit code 0
 
9702023-08-10T06:07:09.572Zfound 2 output files
9712023-08-10T06:07:09.574Zuploading: /tmp/test_up/dsc-out.txt (4399 bytes)
9722023-08-10T06:07:09.584Zuploaded: /tmp/test_up/dsc-out.txt
9732023-08-10T06:07:09.594Zuploading: /tmp/test_up/test_up_out.txt (3412466 bytes)
9742023-08-10T06:07:10.515Zuploaded: /tmp/test_up/test_up_out.txt