01HKT6T8PVMB7M0Y7NT5XS2YT6: test-up-encrypted

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

Buildomat Job: 01HKT6TQJCC0JGVC9T3QV6WXQM

Tags:

Artefacts:

Output:

SEQ GLOBAL TIME DETAILS
12024-01-10T17:51:53.931Zjob dependencies complete; ready to run (waiting for 20 m 56 s)
22024-01-10T17:53:26.802Zjob assigned to worker 01HKT817G6VHZ6Q23WZM68WP70 (queued for 1 m 32 s)
32024-01-10T17:53:27.530Zdownloading input: /input/build/work/bins/crucible-downstairs.gz
42024-01-10T17:53:52.215Zdownloaded input: /input/build/work/bins/crucible-downstairs.gz
52024-01-10T17:53:52.215Zdownloading input: /input/build/work/bins/crucible-hammer.gz
62024-01-10T17:54:04.878Zdownloaded input: /input/build/work/bins/crucible-hammer.gz
72024-01-10T17:54:04.878Zdownloading input: /input/build/work/bins/crutest.gz
82024-01-10T17:54:22.933Zdownloaded input: /input/build/work/bins/crutest.gz
92024-01-10T17:54:22.933Zdownloading input: /input/build/work/bins/dsc.gz
102024-01-10T17:54:34.786Zdownloaded input: /input/build/work/bins/dsc.gz
112024-01-10T17:54:34.795Zdownloading input: /input/build/work/scripts/perf-downstairs-tick.d
122024-01-10T17:54:34.795Zdownloaded input: /input/build/work/scripts/perf-downstairs-tick.d
132024-01-10T17:54:34.795Zdownloading input: /input/build/work/scripts/test_ds.sh
142024-01-10T17:54:34.795Zdownloaded input: /input/build/work/scripts/test_ds.sh
152024-01-10T17:54:34.795Zdownloading input: /input/build/work/scripts/test_live_repair.sh
162024-01-10T17:54:34.795Zdownloaded input: /input/build/work/scripts/test_live_repair.sh
172024-01-10T17:54:34.795Zdownloading input: /input/build/work/scripts/test_repair.sh
182024-01-10T17:54:34.795Zdownloaded input: /input/build/work/scripts/test_repair.sh
192024-01-10T17:54:34.795Zdownloading input: /input/build/work/scripts/test_replay.sh
202024-01-10T17:54:34.795Zdownloaded input: /input/build/work/scripts/test_replay.sh
212024-01-10T17:54:34.801Zdownloading input: /input/build/work/scripts/test_up.sh
222024-01-10T17:54:34.801Zdownloaded input: /input/build/work/scripts/test_up.sh
232024-01-10T17:54:34.801Zdownloading input: /input/build/work/scripts/upstairs_info.d
242024-01-10T17:54:34.801Zdownloaded input: /input/build/work/scripts/upstairs_info.d
252024-01-10T17:54:34.801Zdownloading input: /input/build/tmp/cargo-test-out.log
262024-01-10T17:54:55.820Zdownloaded input: /input/build/tmp/cargo-test-out.log
 
272024-01-10T17:54:55.820Zstarting task 0: "setup"
282024-01-10T17:54:55.883Z++ uname -s
292024-01-10T17:54:55.885Z+ kern=SunOS
302024-01-10T17:54:55.885Z+ case "$kern" in
312024-01-10T17:54:55.885Z+ groupadd -g 12345 build
322024-01-10T17:54:55.888Z+ useradd -u 12345 -g build -d /home/build -s /bin/bash -c build -P 'Primary Administrator' build
332024-01-10T17:54:57.902Z+ zfs create -o mountpoint=/work rpool/work
342024-01-10T17:54:58.080Z++ awk '$2 == "/home" { print $3 }' /etc/mnttab
352024-01-10T17:54:58.083Z+ home_fs=zfs
362024-01-10T17:54:58.083Z+ [[ zfs == autofs ]]
372024-01-10T17:54:58.083Z+ mkdir -p /home/build
382024-01-10T17:54:58.087Z+ chown build:build /home/build /work
392024-01-10T17:54:59.088Z+ chmod 0700 /home/build /work
402024-01-10T17:54:59.092Zprocess exited: duration 3281 ms, exit code 0
 
412024-01-10T17:54:59.098Zstarting task 1: "authentication"
422024-01-10T17:54:59.123Zprocess exited: duration 24 ms, exit code 0
 
432024-01-10T17:54:59.132Zstarting task 2: "build"
442024-01-10T17:54:59.136Z+ banner cores
452024-01-10T17:54:59.177Z
462024-01-10T17:54:59.177Z #### #### ##### ###### ####
472024-01-10T17:54:59.178Z # # # # # # # #
482024-01-10T17:54:59.178Z # # # # # ##### ####
492024-01-10T17:54:59.178Z # # # ##### # #
502024-01-10T17:54:59.178Z # # # # # # # # #
512024-01-10T17:54:59.178Z #### #### # # ###### ####
522024-01-10T17:54:59.178Z
532024-01-10T17:54:59.181Z+ pfexec coreadm -i /tmp/core.%f.%p -g /tmp/core.%f.%p -e global -e log -e proc-setid -e global-setid
542024-01-10T17:54:59.189Z+ echo 'input bins dir contains:'
552024-01-10T17:54:59.189Zinput bins dir contains:
562024-01-10T17:54:59.193Z+ ls -ltr /input/build/work/bins
572024-01-10T17:54:59.193Ztotal 698594
582024-01-10T17:54:59.193Z-rw-r--r-- 1 root root 109456429 Jan 10 17:53 crucible-downstairs.gz
592024-01-10T17:54:59.193Z-rw-r--r-- 1 root root 85807289 Jan 10 17:54 crucible-hammer.gz
602024-01-10T17:54:59.193Z-rw-r--r-- 1 root root 93634688 Jan 10 17:54 crutest.gz
612024-01-10T17:54:59.193Z-rw-r--r-- 1 root root 68539139 Jan 10 17:54 dsc.gz
622024-01-10T17:54:59.193Z+ banner unpack
632024-01-10T17:54:59.200Z
642024-01-10T17:54:59.200Z # # # # ##### ## #### # #
652024-01-10T17:54:59.200Z # # ## # # # # # # # # #
662024-01-10T17:54:59.200Z # # # # # # # # # # ####
672024-01-10T17:54:59.200Z # # # # # ##### ###### # # #
682024-01-10T17:54:59.200Z # # # ## # # # # # # #
692024-01-10T17:54:59.200Z #### # # # # # #### # #
702024-01-10T17:54:59.200Z
712024-01-10T17:54:59.201Z+ mkdir -p /var/tmp/bins
722024-01-10T17:54:59.212Z+ for t in "$input/bins/"*.gz
732024-01-10T17:54:59.212Z++ basename /input/build/work/bins/crucible-downstairs.gz
742024-01-10T17:54:59.212Z+ b=crucible-downstairs.gz
752024-01-10T17:54:59.212Z+ b=crucible-downstairs
762024-01-10T17:54:59.212Z+ gunzip
772024-01-10T17:55:03.060Z+ chmod +x /var/tmp/bins/crucible-downstairs
782024-01-10T17:55:03.064Z+ for t in "$input/bins/"*.gz
792024-01-10T17:55:03.064Z++ basename /input/build/work/bins/crucible-hammer.gz
802024-01-10T17:55:03.068Z+ b=crucible-hammer.gz
812024-01-10T17:55:03.068Z+ b=crucible-hammer
822024-01-10T17:55:03.068Z+ gunzip
832024-01-10T17:55:06.037Z+ chmod +x /var/tmp/bins/crucible-hammer
842024-01-10T17:55:06.042Z+ for t in "$input/bins/"*.gz
852024-01-10T17:55:06.042Z++ basename /input/build/work/bins/crutest.gz
862024-01-10T17:55:06.042Z+ b=crutest.gz
872024-01-10T17:55:06.042Z+ b=crutest
882024-01-10T17:55:06.042Z+ gunzip
892024-01-10T17:55:09.309Z+ chmod +x /var/tmp/bins/crutest
902024-01-10T17:55:09.314Z+ for t in "$input/bins/"*.gz
912024-01-10T17:55:09.314Z++ basename /input/build/work/bins/dsc.gz
922024-01-10T17:55:09.314Z+ b=dsc.gz
932024-01-10T17:55:09.314Z+ b=dsc
942024-01-10T17:55:09.314Z+ gunzip
952024-01-10T17:55:11.621Z+ chmod +x /var/tmp/bins/dsc
962024-01-10T17:55:11.624Z+ export BINDIR=/var/tmp/bins
972024-01-10T17:55:11.624Z+ BINDIR=/var/tmp/bins
982024-01-10T17:55:11.624Z+ banner test_up_encrypted
992024-01-10T17:55:11.627Z
1002024-01-10T17:55:11.627Z ##### ###### #### ##### # # ##### ###### # #
1012024-01-10T17:55:11.627Z # # # # # # # # # ## #
1022024-01-10T17:55:11.627Z # ##### #### # # # # # ##### # # #
1032024-01-10T17:55:11.629Z # # # # # # ##### # # # #
1042024-01-10T17:55:11.629Z # # # # # # # # # # ##
1052024-01-10T17:55:11.629Z # ###### #### # ####### #### # ####### ###### # #
1062024-01-10T17:55:11.629Z
1072024-01-10T17:55:11.629Z+ ptime -m bash /input/build/work/scripts/test_up.sh -N encrypted
1082024-01-10T17:55:11.641Z/input/build/work
1092024-01-10T17:55:11.653ZTurn off color for downstairs dump
1102024-01-10T17:55:11.776ZUpstairs using key: boT7NTSGT7uMkx4oORu6LkvCOeLC/cizc8y5BTSIj+c=
1112024-01-10T17:55:11.812Zdsc output goes to /tmp/test_up/dsc-out.txt
1122024-01-10T17:55:11.812ZCreating three downstairs regions
1132024-01-10T17:55:12.144ZStarting three downstairs
1142024-01-10T17:55:17.153ZDisable automatic restart on all downstairs
1152024-01-10T17:55:17.261Z
1162024-01-10T17:55:17.261ZBegin tests, output goes to /tmp/test_up/test_up_out.txt
1172024-01-10T17:55:17.265ZRunning test: span
1182024-01-10T17:55:21.407ZCompleted test: span
1192024-01-10T17:55:26.429ZRunning test: big
1202024-01-10T17:55:31.003ZCompleted test: big
1212024-01-10T17:55:36.011ZRunning test: dep
1222024-01-10T17:56:48.884ZCompleted test: dep
1232024-01-10T17:56:53.840ZRunning test: balloon
1242024-01-10T17:58:42.796ZCompleted test: balloon
1252024-01-10T17:58:47.815ZRunning test: deactivate
1262024-01-10T17:58:54.505ZCompleted test: deactivate
1272024-01-10T17:58:59.516ZRunning hammer
1282024-01-10T17:59:20.539ZRun repair tests
1292024-01-10T17:59:20.544Z/var/tmp/bins/crutest fill -g 31 -q --key boT7NTSGT7uMkx4oORu6LkvCOeLC/cizc8y5BTSIj+c= -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
1302024-01-10T17:59:20.564Z{"msg":"Upstairs starts","v":0,"name":"crucible","level":30,"time":"2024-01-10T17:59:20.567893461Z","hostname":"ip-10-150-1-187.us-west-2.compute.internal","pid":1196}
1312024-01-10T17:59:20.569Z{"msg":"Crucible Version: BuildInfo {\n version: \"0.0.1\",\n git_sha: \"99c957c6a74e6d7d6180d15bada5890df4de8432\",\n git_commit_timestamp: \"2024-01-10T17:30:23.000000000Z\",\n git_branch: \"renovate/rust-1.x\",\n rustc_semver: \"1.75.0\",\n rustc_channel: \"stable\",\n rustc_host_triple: \"x86_64-unknown-illumos\",\n rustc_commit_sha: \"82e1608dfa6e0b5569232559e3d385fea5a93112\",\n cargo_triple: \"x86_64-unknown-illumos\",\n debug: true,\n opt_level: 0,\n}","v":0,"name":"crucible","level":30,"time":"2024-01-10T17:59:20.568426708Z","hostname":"ip-10-150-1-187.us-west-2.compute.internal","pid":1196}
1322024-01-10T17:59:20.570Z{"msg":"Upstairs <-> Downstairs Message Version: 5","v":0,"name":"crucible","level":30,"time":"2024-01-10T17:59:20.568485736Z","hostname":"ip-10-150-1-187.us-west-2.compute.internal","pid":1196}
1332024-01-10T17:59:20.570Z{"msg":"Crucible da6b062f-bf6c-492a-b8a8-d3d1fa783392 has session id: 8c9a8f98-5621-45fc-9179-97747cf80149","v":0,"name":"crucible","level":30,"time":"2024-01-10T17:59:20.568509635Z","hostname":"ip-10-150-1-187.us-west-2.compute.internal","pid":1196,"session_id":"8c9a8f98-5621-45fc-9179-97747cf80149"}
1342024-01-10T17:59:20.570Z{"msg":"Upstairs opts: Upstairs UUID: da6b062f-bf6c-492a-b8a8-d3d1fa783392, Targets: [127.0.0.1:8810, 127.0.0.1:8820, 127.0.0.1:8830], lossy: false, flush_timeout: None, key populated: true, cert_pem populated: false, key_pem populated: false, root_cert_pem populated: false, Control: None, read_only: false","v":0,"name":"crucible","level":30,"time":"2024-01-10T17:59:20.568544665Z","hostname":"ip-10-150-1-187.us-west-2.compute.internal","pid":1196,"session_id":"8c9a8f98-5621-45fc-9179-97747cf80149"}
1352024-01-10T17:59:20.570Z{"msg":"Crucible stats registered with UUID: da6b062f-bf6c-492a-b8a8-d3d1fa783392","v":0,"name":"crucible","level":30,"time":"2024-01-10T17:59:20.568580101Z","hostname":"ip-10-150-1-187.us-west-2.compute.internal","pid":1196,"session_id":"8c9a8f98-5621-45fc-9179-97747cf80149"}
1362024-01-10T17:59:20.570ZCrucible runtime is spawned
1372024-01-10T17:59:20.570Z{"msg":"The guest has requested activation with gen:31","v":0,"name":"crucible","level":30,"time":"2024-01-10T17:59:20.56896798Z","hostname":"ip-10-150-1-187.us-west-2.compute.internal","pid":1196}
1382024-01-10T17:59:20.570Z{"msg":"da6b062f-bf6c-492a-b8a8-d3d1fa783392 active request set","v":0,"name":"crucible","level":30,"time":"2024-01-10T17:59:20.569126767Z","hostname":"ip-10-150-1-187.us-west-2.compute.internal","pid":1196,"session_id":"8c9a8f98-5621-45fc-9179-97747cf80149"}
1392024-01-10T17:59:20.570Z{"msg":"sending connect oneshot to client","v":0,"name":"crucible","level":30,"time":"2024-01-10T17:59:20.569231428Z","hostname":"ip-10-150-1-187.us-west-2.compute.internal","pid":1196,"client":"0","":"downstairs","session_id":"8c9a8f98-5621-45fc-9179-97747cf80149"}
1402024-01-10T17:59:20.570Z{"msg":"client set_active_request while in New; waiting...","v":0,"name":"crucible","level":30,"time":"2024-01-10T17:59:20.569323506Z","hostname":"ip-10-150-1-187.us-west-2.compute.internal","pid":1196,"client":"0","":"downstairs","session_id":"8c9a8f98-5621-45fc-9179-97747cf80149"}
1412024-01-10T17:59:20.570Z{"msg":"sending connect oneshot to client","v":0,"name":"crucible","level":30,"time":"2024-01-10T17:59:20.569386045Z","hostname":"ip-10-150-1-187.us-west-2.compute.internal","pid":1196,"client":"1","":"downstairs","session_id":"8c9a8f98-5621-45fc-9179-97747cf80149"}
1422024-01-10T17:59:20.570Z{"msg":"client set_active_request while in New; waiting...","v":0,"name":"crucible","level":30,"time":"2024-01-10T17:59:20.569411826Z","hostname":"ip-10-150-1-187.us-west-2.compute.internal","pid":1196,"client":"1","":"downstairs","session_id":"8c9a8f98-5621-45fc-9179-97747cf80149"}
1432024-01-10T17:59:20.570Z{"msg":"sending connect oneshot to client","v":0,"name":"crucible","level":30,"time":"2024-01-10T17:59:20.569442394Z","hostname":"ip-10-150-1-187.us-west-2.compute.internal","pid":1196,"client":"2","":"downstairs","session_id":"8c9a8f98-5621-45fc-9179-97747cf80149"}
1442024-01-10T17:59:20.570Z{"msg":"client set_active_request while in New; waiting...","v":0,"name":"crucible","level":30,"time":"2024-01-10T17:59:20.569547759Z","hostname":"ip-10-150-1-187.us-west-2.compute.internal","pid":1196,"client":"2","":"downstairs","session_id":"8c9a8f98-5621-45fc-9179-97747cf80149"}
1452024-01-10T17:59:20.570Z{"msg":"connecting to 127.0.0.1:8810","v":0,"name":"crucible","level":30,"time":"2024-01-10T17:59:20.569591225Z","hostname":"ip-10-150-1-187.us-west-2.compute.internal","pid":1196,"":"io task","client":"0","":"downstairs","session_id":"8c9a8f98-5621-45fc-9179-97747cf80149"}
1462024-01-10T17:59:20.570Z{"msg":"connecting to 127.0.0.1:8820","v":0,"name":"crucible","level":30,"time":"2024-01-10T17:59:20.569617294Z","hostname":"ip-10-150-1-187.us-west-2.compute.internal","pid":1196,"":"io task","client":"1","":"downstairs","session_id":"8c9a8f98-5621-45fc-9179-97747cf80149"}
1472024-01-10T17:59:20.570Z{"msg":"connecting to 127.0.0.1:8830","v":0,"name":"crucible","level":30,"time":"2024-01-10T17:59:20.569661654Z","hostname":"ip-10-150-1-187.us-west-2.compute.internal","pid":1196,"":"io task","client":"2","":"downstairs","session_id":"8c9a8f98-5621-45fc-9179-97747cf80149"}
1482024-01-10T17:59:20.570Z{"msg":"ds_connection connected","v":0,"name":"crucible","level":30,"time":"2024-01-10T17:59:20.569686126Z","hostname":"ip-10-150-1-187.us-west-2.compute.internal","pid":1196,"":"io task","client":"0","":"downstairs","session_id":"8c9a8f98-5621-45fc-9179-97747cf80149"}
1492024-01-10T17:59:20.570Z{"msg":"ds_connection connected","v":0,"name":"crucible","level":30,"time":"2024-01-10T17:59:20.569719848Z","hostname":"ip-10-150-1-187.us-west-2.compute.internal","pid":1196,"":"io task","client":"1","":"downstairs","session_id":"8c9a8f98-5621-45fc-9179-97747cf80149"}
1502024-01-10T17:59:20.570Z{"msg":"ds_connection connected","v":0,"name":"crucible","level":30,"time":"2024-01-10T17:59:20.569893667Z","hostname":"ip-10-150-1-187.us-west-2.compute.internal","pid":1196,"":"io task","client":"2","":"downstairs","session_id":"8c9a8f98-5621-45fc-9179-97747cf80149"}
1512024-01-10T17:59:20.570Z{"msg":"ds_transition from New to WaitActive","v":0,"name":"crucible","level":30,"time":"2024-01-10T17:59:20.57069828Z","hostname":"ip-10-150-1-187.us-west-2.compute.internal","pid":1196,"client":"0","":"downstairs","session_id":"8c9a8f98-5621-45fc-9179-97747cf80149"}
1522024-01-10T17:59:20.571Z{"msg":"[0] Transition from New to WaitActive","v":0,"name":"crucible","level":30,"time":"2024-01-10T17:59:20.570757528Z","hostname":"ip-10-150-1-187.us-west-2.compute.internal","pid":1196,"client":"0","":"downstairs","session_id":"8c9a8f98-5621-45fc-9179-97747cf80149"}
1532024-01-10T17:59:20.571Z{"msg":"ds_transition from New to WaitActive","v":0,"name":"crucible","level":30,"time":"2024-01-10T17:59:20.570782734Z","hostname":"ip-10-150-1-187.us-west-2.compute.internal","pid":1196,"client":"1","":"downstairs","session_id":"8c9a8f98-5621-45fc-9179-97747cf80149"}
1542024-01-10T17:59:20.571Z{"msg":"[1] Transition from New to WaitActive","v":0,"name":"crucible","level":30,"time":"2024-01-10T17:59:20.570824758Z","hostname":"ip-10-150-1-187.us-west-2.compute.internal","pid":1196,"client":"1","":"downstairs","session_id":"8c9a8f98-5621-45fc-9179-97747cf80149"}
1552024-01-10T17:59:20.571Z{"msg":"ds_transition from New to WaitActive","v":0,"name":"crucible","level":30,"time":"2024-01-10T17:59:20.57084844Z","hostname":"ip-10-150-1-187.us-west-2.compute.internal","pid":1196,"client":"2","":"downstairs","session_id":"8c9a8f98-5621-45fc-9179-97747cf80149"}
1562024-01-10T17:59:20.571Z{"msg":"[2] Transition from New to WaitActive","v":0,"name":"crucible","level":30,"time":"2024-01-10T17:59:20.570870686Z","hostname":"ip-10-150-1-187.us-west-2.compute.internal","pid":1196,"client":"2","":"downstairs","session_id":"8c9a8f98-5621-45fc-9179-97747cf80149"}
1572024-01-10T17:59:20.575Z{"msg":"downstairs client at Some(127.0.0.1:8830) has region UUID 12345678-0000-0000-0000-000000008830","v":0,"name":"crucible","level":30,"time":"2024-01-10T17:59:20.571773505Z","hostname":"ip-10-150-1-187.us-west-2.compute.internal","pid":1196,"client":"2","":"downstairs","session_id":"8c9a8f98-5621-45fc-9179-97747cf80149"}
1582024-01-10T17:59:20.575Z{"msg":"downstairs client at Some(127.0.0.1:8820) has region UUID 12345678-0000-0000-0000-000000008820","v":0,"name":"crucible","level":30,"time":"2024-01-10T17:59:20.5720696Z","hostname":"ip-10-150-1-187.us-west-2.compute.internal","pid":1196,"client":"1","":"downstairs","session_id":"8c9a8f98-5621-45fc-9179-97747cf80149"}
1592024-01-10T17:59:20.575Z{"msg":"downstairs client at Some(127.0.0.1:8810) has region UUID 12345678-0000-0000-0000-000000008810","v":0,"name":"crucible","level":30,"time":"2024-01-10T17:59:20.572218596Z","hostname":"ip-10-150-1-187.us-west-2.compute.internal","pid":1196,"client":"0","":"downstairs","session_id":"8c9a8f98-5621-45fc-9179-97747cf80149"}
1602024-01-10T17:59:20.575Z{"msg":"ds_transition from WaitActive to WaitQuorum","v":0,"name":"crucible","level":30,"time":"2024-01-10T17:59:20.572256915Z","hostname":"ip-10-150-1-187.us-west-2.compute.internal","pid":1196,"client":"2","":"downstairs","session_id":"8c9a8f98-5621-45fc-9179-97747cf80149"}
1612024-01-10T17:59:20.575Z{"msg":"[2] Transition from WaitActive to WaitQuorum","v":0,"name":"crucible","level":30,"time":"2024-01-10T17:59:20.572280823Z","hostname":"ip-10-150-1-187.us-west-2.compute.internal","pid":1196,"client":"2","":"downstairs","session_id":"8c9a8f98-5621-45fc-9179-97747cf80149"}
1622024-01-10T17:59:20.576Z{"msg":"Waiting for true more clients to be ready","v":0,"name":"crucible","level":30,"time":"2024-01-10T17:59:20.572348162Z","hostname":"ip-10-150-1-187.us-west-2.compute.internal","pid":1196,"session_id":"8c9a8f98-5621-45fc-9179-97747cf80149"}
1632024-01-10T17:59:20.577Z{"msg":"ds_transition from WaitActive to WaitQuorum","v":0,"name":"crucible","level":30,"time":"2024-01-10T17:59:20.572799953Z","hostname":"ip-10-150-1-187.us-west-2.compute.internal","pid":1196,"client":"1","":"downstairs","session_id":"8c9a8f98-5621-45fc-9179-97747cf80149"}
1642024-01-10T17:59:20.577Z{"msg":"[1] Transition from WaitActive to WaitQuorum","v":0,"name":"crucible","level":30,"time":"2024-01-10T17:59:20.572862516Z","hostname":"ip-10-150-1-187.us-west-2.compute.internal","pid":1196,"client":"1","":"downstairs","session_id":"8c9a8f98-5621-45fc-9179-97747cf80149"}
1652024-01-10T17:59:20.577Z{"msg":"Waiting for true more clients to be ready","v":0,"name":"crucible","level":30,"time":"2024-01-10T17:59:20.572888317Z","hostname":"ip-10-150-1-187.us-west-2.compute.internal","pid":1196,"session_id":"8c9a8f98-5621-45fc-9179-97747cf80149"}
1662024-01-10T17:59:20.577Z{"msg":"ds_transition from WaitActive to WaitQuorum","v":0,"name":"crucible","level":30,"time":"2024-01-10T17:59:20.572909029Z","hostname":"ip-10-150-1-187.us-west-2.compute.internal","pid":1196,"client":"0","":"downstairs","session_id":"8c9a8f98-5621-45fc-9179-97747cf80149"}
1672024-01-10T17:59:20.577Z{"msg":"[0] Transition from WaitActive to WaitQuorum","v":0,"name":"crucible","level":30,"time":"2024-01-10T17:59:20.57294932Z","hostname":"ip-10-150-1-187.us-west-2.compute.internal","pid":1196,"client":"0","":"downstairs","session_id":"8c9a8f98-5621-45fc-9179-97747cf80149"}
1682024-01-10T17:59:20.577Z{"msg":"[0]R flush_numbers: [1855, 1855, 1855, 1855, 1855]","v":0,"name":"crucible","level":30,"time":"2024-01-10T17:59:20.572973515Z","hostname":"ip-10-150-1-187.us-west-2.compute.internal","pid":1196,"":"downstairs","":"downstairs","session_id":"8c9a8f98-5621-45fc-9179-97747cf80149"}
1692024-01-10T17:59:20.577Z{"msg":"[0]R generation: [25, 25, 25, 25, 25]","v":0,"name":"crucible","level":30,"time":"2024-01-10T17:59:20.572995391Z","hostname":"ip-10-150-1-187.us-west-2.compute.internal","pid":1196,"":"downstairs","":"downstairs","session_id":"8c9a8f98-5621-45fc-9179-97747cf80149"}
1702024-01-10T17:59:20.577ZWait for a query_work_queue command to finish before sending IO
1712024-01-10T17:59:20.577Z{"msg":"[0]R dirty: [false, false, false, false, false]","v":0,"name":"crucible","level":30,"time":"2024-01-10T17:59:20.573037855Z","hostname":"ip-10-150-1-187.us-west-2.compute.internal","pid":1196,"":"downstairs","":"downstairs","session_id":"8c9a8f98-5621-45fc-9179-97747cf80149"}
1722024-01-10T17:59:20.577Z{"msg":"[1]R flush_numbers: [1855, 1855, 1855, 1855, 1855]","v":0,"name":"crucible","level":30,"time":"2024-01-10T17:59:20.573061812Z","hostname":"ip-10-150-1-187.us-west-2.compute.internal","pid":1196,"":"downstairs","":"downstairs","session_id":"8c9a8f98-5621-45fc-9179-97747cf80149"}
1732024-01-10T17:59:20.578Z{"msg":"[1]R generation: [25, 25, 25, 25, 25]","v":0,"name":"crucible","level":30,"time":"2024-01-10T17:59:20.573083424Z","hostname":"ip-10-150-1-187.us-west-2.compute.internal","pid":1196,"":"downstairs","":"downstairs","session_id":"8c9a8f98-5621-45fc-9179-97747cf80149"}
1742024-01-10T17:59:20.578Z{"msg":"[1]R dirty: [false, false, false, false, false]","v":0,"name":"crucible","level":30,"time":"2024-01-10T17:59:20.573123215Z","hostname":"ip-10-150-1-187.us-west-2.compute.internal","pid":1196,"":"downstairs","":"downstairs","session_id":"8c9a8f98-5621-45fc-9179-97747cf80149"}
1752024-01-10T17:59:20.578Z{"msg":"[2]R flush_numbers: [1855, 1855, 1855, 1855, 1855]","v":0,"name":"crucible","level":30,"time":"2024-01-10T17:59:20.573146935Z","hostname":"ip-10-150-1-187.us-west-2.compute.internal","pid":1196,"":"downstairs","":"downstairs","session_id":"8c9a8f98-5621-45fc-9179-97747cf80149"}
1762024-01-10T17:59:20.578Z{"msg":"[2]R generation: [25, 25, 25, 25, 25]","v":0,"name":"crucible","level":30,"time":"2024-01-10T17:59:20.573168712Z","hostname":"ip-10-150-1-187.us-west-2.compute.internal","pid":1196,"":"downstairs","":"downstairs","session_id":"8c9a8f98-5621-45fc-9179-97747cf80149"}
1772024-01-10T17:59:20.578Z{"msg":"[2]R dirty: [false, false, false, false, false]","v":0,"name":"crucible","level":30,"time":"2024-01-10T17:59:20.573190383Z","hostname":"ip-10-150-1-187.us-west-2.compute.internal","pid":1196,"":"downstairs","":"downstairs","session_id":"8c9a8f98-5621-45fc-9179-97747cf80149"}
1782024-01-10T17:59:20.578Z{"msg":"Max found gen is 26","v":0,"name":"crucible","level":30,"time":"2024-01-10T17:59:20.573211459Z","hostname":"ip-10-150-1-187.us-west-2.compute.internal","pid":1196,"":"downstairs","":"downstairs","session_id":"8c9a8f98-5621-45fc-9179-97747cf80149"}
1792024-01-10T17:59:20.578Z{"msg":"Generation requested: 31 >= found:26","v":0,"name":"crucible","level":30,"time":"2024-01-10T17:59:20.573261347Z","hostname":"ip-10-150-1-187.us-west-2.compute.internal","pid":1196,"":"downstairs","":"downstairs","session_id":"8c9a8f98-5621-45fc-9179-97747cf80149"}
1802024-01-10T17:59:20.578Z{"msg":"Next flush: 1856","v":0,"name":"crucible","level":30,"time":"2024-01-10T17:59:20.573283802Z","hostname":"ip-10-150-1-187.us-west-2.compute.internal","pid":1196,"":"downstairs","":"downstairs","session_id":"8c9a8f98-5621-45fc-9179-97747cf80149"}
1812024-01-10T17:59:20.578Z{"msg":"All extents match","v":0,"name":"crucible","level":30,"time":"2024-01-10T17:59:20.573332383Z","hostname":"ip-10-150-1-187.us-west-2.compute.internal","pid":1196,"":"downstairs","":"downstairs","session_id":"8c9a8f98-5621-45fc-9179-97747cf80149"}
1822024-01-10T17:59:20.578Z{"msg":"No downstairs repair required","v":0,"name":"crucible","level":30,"time":"2024-01-10T17:59:20.573355823Z","hostname":"ip-10-150-1-187.us-west-2.compute.internal","pid":1196,"session_id":"8c9a8f98-5621-45fc-9179-97747cf80149"}
1832024-01-10T17:59:20.579Z{"msg":"Transition from WaitQuorum to Active","v":0,"name":"crucible","level":30,"time":"2024-01-10T17:59:20.573397073Z","hostname":"ip-10-150-1-187.us-west-2.compute.internal","pid":1196,"client":"0","":"downstairs","session_id":"8c9a8f98-5621-45fc-9179-97747cf80149"}
1842024-01-10T17:59:20.579Z{"msg":"Transition from WaitQuorum to Active","v":0,"name":"crucible","level":30,"time":"2024-01-10T17:59:20.573419988Z","hostname":"ip-10-150-1-187.us-west-2.compute.internal","pid":1196,"client":"1","":"downstairs","session_id":"8c9a8f98-5621-45fc-9179-97747cf80149"}
1852024-01-10T17:59:20.579Z{"msg":"Transition from WaitQuorum to Active","v":0,"name":"crucible","level":30,"time":"2024-01-10T17:59:20.573464642Z","hostname":"ip-10-150-1-187.us-west-2.compute.internal","pid":1196,"client":"2","":"downstairs","session_id":"8c9a8f98-5621-45fc-9179-97747cf80149"}
1862024-01-10T17:59:20.579Z{"msg":"All required repair work is completed","v":0,"name":"crucible","level":30,"time":"2024-01-10T17:59:20.573487429Z","hostname":"ip-10-150-1-187.us-west-2.compute.internal","pid":1196,"session_id":"8c9a8f98-5621-45fc-9179-97747cf80149"}
1872024-01-10T17:59:20.579Z{"msg":"Set Downstairs and Upstairs active after repairs","v":0,"name":"crucible","level":30,"time":"2024-01-10T17:59:20.573535784Z","hostname":"ip-10-150-1-187.us-west-2.compute.internal","pid":1196,"session_id":"8c9a8f98-5621-45fc-9179-97747cf80149"}
1882024-01-10T17:59:20.579Z{"msg":"da6b062f-bf6c-492a-b8a8-d3d1fa783392 is now active with session: 8c9a8f98-5621-45fc-9179-97747cf80149","v":0,"name":"crucible","level":30,"time":"2024-01-10T17:59:20.573558656Z","hostname":"ip-10-150-1-187.us-west-2.compute.internal","pid":1196,"session_id":"8c9a8f98-5621-45fc-9179-97747cf80149"}
1892024-01-10T17:59:20.579Z{"msg":"Set Active after no repair","v":0,"name":"crucible","level":30,"time":"2024-01-10T17:59:20.573601623Z","hostname":"ip-10-150-1-187.us-west-2.compute.internal","pid":1196,"session_id":"8c9a8f98-5621-45fc-9179-97747cf80149"}
1902024-01-10T17:59:20.579Z{"msg":"The guest has finished waiting for activation with:31","v":0,"name":"crucible","level":30,"time":"2024-01-10T17:59:20.573622914Z","hostname":"ip-10-150-1-187.us-west-2.compute.internal","pid":1196}
1912024-01-10T17:59:20.579ZRegion: es:10 ec:5 bs:4096 ts:204800 tb:50 max_io:50 or 204800
1922024-01-10T17:59:20.579ZFill test
1932024-01-10T17:59:20.637ZRead and Verify all blocks (0..50 range:false)
1942024-01-10T17:59:20.772ZWrote out file "/var/tmp/test_up/verify_file"
1952024-01-10T17:59:20.772ZCLIENT: Tests done. All submitted work has been ACK'd
1962024-01-10T17:59:20.804Z----------------------------------------------------------------
1972024-01-10T17:59:20.804Z Crucible gen:31 GIO:true work queues: Upstairs:0 downstairs:1
1982024-01-10T17:59:20.804ZStates: Active Active Active
1992024-01-10T17:59:20.804ZGW_ID ACK DSID TYPE BLOCKS DS:0 DS:1 DS:2 REPLAY
2002024-01-10T17:59:20.805Z 3 Acked 1002 Read 50 Done Done Done false
2012024-01-10T17:59:20.805Z STATES DS:0 DS:1 DS:2 TOTAL
2022024-01-10T17:59:20.806Z New 0 0 0 0
2032024-01-10T17:59:20.806Z Sent 0 0 0 0
2042024-01-10T17:59:20.806Z Done 1 1 1 3
2052024-01-10T17:59:20.806Z Skipped 0 0 0 0
2062024-01-10T17:59:20.806Z Error 0 0 0 0
2072024-01-10T17:59:20.806ZLast Flush: 1001 1001 1001
2082024-01-10T17:59:20.806ZDownstairs last five completed: 1001 1000
2092024-01-10T17:59:20.806ZUpstairs last five completed: 3 2 1
2102024-01-10T17:59:20.809ZCLIENT: Up:0 ds:1 act:3
2112024-01-10T17:59:24.805Z----------------------------------------------------------------
2122024-01-10T17:59:24.806Z Crucible gen:31 GIO:true work queues: Upstairs:0 downstairs:0
2132024-01-10T17:59:24.806ZDownstairs last five completed: 1003 1002 1001 1000
2142024-01-10T17:59:24.806ZUpstairs last five completed: 4 3 2 1
2152024-01-10T17:59:24.806ZCLIENT: Up:0 ds:0 act:3
2162024-01-10T17:59:24.806ZCLIENT: All crucible jobs finished, exiting program
2172024-01-10T17:59:24.817ZRepair setup passed
2182024-01-10T17:59:24.822ZCopy the 8830 file
2192024-01-10T17:59:24.824Zcp -r /var/tmp/test_up/8830 /var/tmp/test_up/previous
2202024-01-10T17:59:24.827Z/var/tmp/bins/crutest repair -g 32 -q --key boT7NTSGT7uMkx4oORu6LkvCOeLC/cizc8y5BTSIj+c= -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
2212024-01-10T17:59:24.845Z{"msg":"Upstairs starts","v":0,"name":"crucible","level":30,"time":"2024-01-10T17:59:24.849047583Z","hostname":"ip-10-150-1-187.us-west-2.compute.internal","pid":1202}
2222024-01-10T17:59:24.849Z{"msg":"Crucible Version: BuildInfo {\n version: \"0.0.1\",\n git_sha: \"99c957c6a74e6d7d6180d15bada5890df4de8432\",\n git_commit_timestamp: \"2024-01-10T17:30:23.000000000Z\",\n git_branch: \"renovate/rust-1.x\",\n rustc_semver: \"1.75.0\",\n rustc_channel: \"stable\",\n rustc_host_triple: \"x86_64-unknown-illumos\",\n rustc_commit_sha: \"82e1608dfa6e0b5569232559e3d385fea5a93112\",\n cargo_triple: \"x86_64-unknown-illumos\",\n debug: true,\n opt_level: 0,\n}","v":0,"name":"crucible","level":30,"time":"2024-01-10T17:59:24.849510869Z","hostname":"ip-10-150-1-187.us-west-2.compute.internal","pid":1202}
2232024-01-10T17:59:24.849Z{"msg":"Upstairs <-> Downstairs Message Version: 5","v":0,"name":"crucible","level":30,"time":"2024-01-10T17:59:24.849569979Z","hostname":"ip-10-150-1-187.us-west-2.compute.internal","pid":1202}
2242024-01-10T17:59:24.849Z{"msg":"Crucible da86e24c-6477-4afc-a78f-4efacefedc0d has session id: bcbae331-3b70-434d-93c2-88d7337c0d37","v":0,"name":"crucible","level":30,"time":"2024-01-10T17:59:24.849593254Z","hostname":"ip-10-150-1-187.us-west-2.compute.internal","pid":1202,"session_id":"bcbae331-3b70-434d-93c2-88d7337c0d37"}
2252024-01-10T17:59:24.849Z{"msg":"Upstairs opts: Upstairs UUID: da86e24c-6477-4afc-a78f-4efacefedc0d, Targets: [127.0.0.1:8810, 127.0.0.1:8820, 127.0.0.1:8830], lossy: false, flush_timeout: None, key populated: true, cert_pem populated: false, key_pem populated: false, root_cert_pem populated: false, Control: None, read_only: false","v":0,"name":"crucible","level":30,"time":"2024-01-10T17:59:24.849628503Z","hostname":"ip-10-150-1-187.us-west-2.compute.internal","pid":1202,"session_id":"bcbae331-3b70-434d-93c2-88d7337c0d37"}
2262024-01-10T17:59:24.849Z{"msg":"Crucible stats registered with UUID: da86e24c-6477-4afc-a78f-4efacefedc0d","v":0,"name":"crucible","level":30,"time":"2024-01-10T17:59:24.849654985Z","hostname":"ip-10-150-1-187.us-west-2.compute.internal","pid":1202,"session_id":"bcbae331-3b70-434d-93c2-88d7337c0d37"}
2272024-01-10T17:59:24.849ZCrucible runtime is spawned
2282024-01-10T17:59:24.849Z{"msg":"The guest has requested activation with gen:32","v":0,"name":"crucible","level":30,"time":"2024-01-10T17:59:24.849981777Z","hostname":"ip-10-150-1-187.us-west-2.compute.internal","pid":1202}
2292024-01-10T17:59:24.849Z{"msg":"da86e24c-6477-4afc-a78f-4efacefedc0d active request set","v":0,"name":"crucible","level":30,"time":"2024-01-10T17:59:24.850209568Z","hostname":"ip-10-150-1-187.us-west-2.compute.internal","pid":1202,"session_id":"bcbae331-3b70-434d-93c2-88d7337c0d37"}
2302024-01-10T17:59:24.849Z{"msg":"sending connect oneshot to client","v":0,"name":"crucible","level":30,"time":"2024-01-10T17:59:24.850271013Z","hostname":"ip-10-150-1-187.us-west-2.compute.internal","pid":1202,"client":"0","":"downstairs","session_id":"bcbae331-3b70-434d-93c2-88d7337c0d37"}
2312024-01-10T17:59:24.849Z{"msg":"client set_active_request while in New; waiting...","v":0,"name":"crucible","level":30,"time":"2024-01-10T17:59:24.850298039Z","hostname":"ip-10-150-1-187.us-west-2.compute.internal","pid":1202,"client":"0","":"downstairs","session_id":"bcbae331-3b70-434d-93c2-88d7337c0d37"}
2322024-01-10T17:59:24.849Z{"msg":"sending connect oneshot to client","v":0,"name":"crucible","level":30,"time":"2024-01-10T17:59:24.850339924Z","hostname":"ip-10-150-1-187.us-west-2.compute.internal","pid":1202,"client":"1","":"downstairs","session_id":"bcbae331-3b70-434d-93c2-88d7337c0d37"}
2332024-01-10T17:59:24.849Z{"msg":"client set_active_request while in New; waiting...","v":0,"name":"crucible","level":30,"time":"2024-01-10T17:59:24.850364624Z","hostname":"ip-10-150-1-187.us-west-2.compute.internal","pid":1202,"client":"1","":"downstairs","session_id":"bcbae331-3b70-434d-93c2-88d7337c0d37"}
2342024-01-10T17:59:24.849Z{"msg":"sending connect oneshot to client","v":0,"name":"crucible","level":30,"time":"2024-01-10T17:59:24.850386837Z","hostname":"ip-10-150-1-187.us-west-2.compute.internal","pid":1202,"client":"2","":"downstairs","session_id":"bcbae331-3b70-434d-93c2-88d7337c0d37"}
2352024-01-10T17:59:24.849Z{"msg":"client set_active_request while in New; waiting...","v":0,"name":"crucible","level":30,"time":"2024-01-10T17:59:24.850433397Z","hostname":"ip-10-150-1-187.us-west-2.compute.internal","pid":1202,"client":"2","":"downstairs","session_id":"bcbae331-3b70-434d-93c2-88d7337c0d37"}
2362024-01-10T17:59:24.849Z{"msg":"connecting to 127.0.0.1:8830","v":0,"name":"crucible","level":30,"time":"2024-01-10T17:59:24.850456607Z","hostname":"ip-10-150-1-187.us-west-2.compute.internal","pid":1202,"":"io task","client":"2","":"downstairs","session_id":"bcbae331-3b70-434d-93c2-88d7337c0d37"}
2372024-01-10T17:59:24.850Z{"msg":"connecting to 127.0.0.1:8820","v":0,"name":"crucible","level":30,"time":"2024-01-10T17:59:24.850479568Z","hostname":"ip-10-150-1-187.us-west-2.compute.internal","pid":1202,"":"io task","client":"1","":"downstairs","session_id":"bcbae331-3b70-434d-93c2-88d7337c0d37"}
2382024-01-10T17:59:24.850Z{"msg":"connecting to 127.0.0.1:8810","v":0,"name":"crucible","level":30,"time":"2024-01-10T17:59:24.850520191Z","hostname":"ip-10-150-1-187.us-west-2.compute.internal","pid":1202,"":"io task","client":"0","":"downstairs","session_id":"bcbae331-3b70-434d-93c2-88d7337c0d37"}
2392024-01-10T17:59:24.850Z{"msg":"ds_connection connected","v":0,"name":"crucible","level":30,"time":"2024-01-10T17:59:24.850883547Z","hostname":"ip-10-150-1-187.us-west-2.compute.internal","pid":1202,"":"io task","client":"1","":"downstairs","session_id":"bcbae331-3b70-434d-93c2-88d7337c0d37"}
2402024-01-10T17:59:24.850Z{"msg":"ds_connection connected","v":0,"name":"crucible","level":30,"time":"2024-01-10T17:59:24.85120051Z","hostname":"ip-10-150-1-187.us-west-2.compute.internal","pid":1202,"":"io task","client":"2","":"downstairs","session_id":"bcbae331-3b70-434d-93c2-88d7337c0d37"}
2412024-01-10T17:59:24.850Z{"msg":"ds_connection connected","v":0,"name":"crucible","level":30,"time":"2024-01-10T17:59:24.85128993Z","hostname":"ip-10-150-1-187.us-west-2.compute.internal","pid":1202,"":"io task","client":"0","":"downstairs","session_id":"bcbae331-3b70-434d-93c2-88d7337c0d37"}
2422024-01-10T17:59:24.850Z{"msg":"ds_transition from New to WaitActive","v":0,"name":"crucible","level":30,"time":"2024-01-10T17:59:24.851988717Z","hostname":"ip-10-150-1-187.us-west-2.compute.internal","pid":1202,"client":"1","":"downstairs","session_id":"bcbae331-3b70-434d-93c2-88d7337c0d37"}
2432024-01-10T17:59:24.850Z{"msg":"[1] Transition from New to WaitActive","v":0,"name":"crucible","level":30,"time":"2024-01-10T17:59:24.852059806Z","hostname":"ip-10-150-1-187.us-west-2.compute.internal","pid":1202,"client":"1","":"downstairs","session_id":"bcbae331-3b70-434d-93c2-88d7337c0d37"}
2442024-01-10T17:59:24.850Z{"msg":"ds_transition from New to WaitActive","v":0,"name":"crucible","level":30,"time":"2024-01-10T17:59:24.852086986Z","hostname":"ip-10-150-1-187.us-west-2.compute.internal","pid":1202,"client":"0","":"downstairs","session_id":"bcbae331-3b70-434d-93c2-88d7337c0d37"}
2452024-01-10T17:59:24.851Z{"msg":"[0] Transition from New to WaitActive","v":0,"name":"crucible","level":30,"time":"2024-01-10T17:59:24.85210977Z","hostname":"ip-10-150-1-187.us-west-2.compute.internal","pid":1202,"client":"0","":"downstairs","session_id":"bcbae331-3b70-434d-93c2-88d7337c0d37"}
2462024-01-10T17:59:24.851Z{"msg":"ds_transition from New to WaitActive","v":0,"name":"crucible","level":30,"time":"2024-01-10T17:59:24.852164839Z","hostname":"ip-10-150-1-187.us-west-2.compute.internal","pid":1202,"client":"2","":"downstairs","session_id":"bcbae331-3b70-434d-93c2-88d7337c0d37"}
2472024-01-10T17:59:24.851Z{"msg":"[2] Transition from New to WaitActive","v":0,"name":"crucible","level":30,"time":"2024-01-10T17:59:24.852221844Z","hostname":"ip-10-150-1-187.us-west-2.compute.internal","pid":1202,"client":"2","":"downstairs","session_id":"bcbae331-3b70-434d-93c2-88d7337c0d37"}
2482024-01-10T17:59:24.855Z{"msg":"downstairs client at Some(127.0.0.1:8830) has region UUID 12345678-0000-0000-0000-000000008830","v":0,"name":"crucible","level":30,"time":"2024-01-10T17:59:24.85311159Z","hostname":"ip-10-150-1-187.us-west-2.compute.internal","pid":1202,"client":"2","":"downstairs","session_id":"bcbae331-3b70-434d-93c2-88d7337c0d37"}
2492024-01-10T17:59:24.855Z{"msg":"downstairs client at Some(127.0.0.1:8810) has region UUID 12345678-0000-0000-0000-000000008810","v":0,"name":"crucible","level":30,"time":"2024-01-10T17:59:24.853269684Z","hostname":"ip-10-150-1-187.us-west-2.compute.internal","pid":1202,"client":"0","":"downstairs","session_id":"bcbae331-3b70-434d-93c2-88d7337c0d37"}
2502024-01-10T17:59:24.856Z{"msg":"downstairs client at Some(127.0.0.1:8820) has region UUID 12345678-0000-0000-0000-000000008820","v":0,"name":"crucible","level":30,"time":"2024-01-10T17:59:24.85342299Z","hostname":"ip-10-150-1-187.us-west-2.compute.internal","pid":1202,"client":"1","":"downstairs","session_id":"bcbae331-3b70-434d-93c2-88d7337c0d37"}
2512024-01-10T17:59:24.856Z{"msg":"ds_transition from WaitActive to WaitQuorum","v":0,"name":"crucible","level":30,"time":"2024-01-10T17:59:24.85380734Z","hostname":"ip-10-150-1-187.us-west-2.compute.internal","pid":1202,"client":"2","":"downstairs","session_id":"bcbae331-3b70-434d-93c2-88d7337c0d37"}
2522024-01-10T17:59:24.856Z{"msg":"[2] Transition from WaitActive to WaitQuorum","v":0,"name":"crucible","level":30,"time":"2024-01-10T17:59:24.853951246Z","hostname":"ip-10-150-1-187.us-west-2.compute.internal","pid":1202,"client":"2","":"downstairs","session_id":"bcbae331-3b70-434d-93c2-88d7337c0d37"}
2532024-01-10T17:59:24.856Z{"msg":"Waiting for true more clients to be ready","v":0,"name":"crucible","level":30,"time":"2024-01-10T17:59:24.853979136Z","hostname":"ip-10-150-1-187.us-west-2.compute.internal","pid":1202,"session_id":"bcbae331-3b70-434d-93c2-88d7337c0d37"}
2542024-01-10T17:59:24.856Z{"msg":"ds_transition from WaitActive to WaitQuorum","v":0,"name":"crucible","level":30,"time":"2024-01-10T17:59:24.854089184Z","hostname":"ip-10-150-1-187.us-west-2.compute.internal","pid":1202,"client":"1","":"downstairs","session_id":"bcbae331-3b70-434d-93c2-88d7337c0d37"}
2552024-01-10T17:59:24.856Z{"msg":"[1] Transition from WaitActive to WaitQuorum","v":0,"name":"crucible","level":30,"time":"2024-01-10T17:59:24.8541409Z","hostname":"ip-10-150-1-187.us-west-2.compute.internal","pid":1202,"client":"1","":"downstairs","session_id":"bcbae331-3b70-434d-93c2-88d7337c0d37"}
2562024-01-10T17:59:24.856Z{"msg":"Waiting for true more clients to be ready","v":0,"name":"crucible","level":30,"time":"2024-01-10T17:59:24.854165967Z","hostname":"ip-10-150-1-187.us-west-2.compute.internal","pid":1202,"session_id":"bcbae331-3b70-434d-93c2-88d7337c0d37"}
2572024-01-10T17:59:24.856Z{"msg":"ds_transition from WaitActive to WaitQuorum","v":0,"name":"crucible","level":30,"time":"2024-01-10T17:59:24.854188119Z","hostname":"ip-10-150-1-187.us-west-2.compute.internal","pid":1202,"client":"0","":"downstairs","session_id":"bcbae331-3b70-434d-93c2-88d7337c0d37"}
2582024-01-10T17:59:24.856Z{"msg":"[0] Transition from WaitActive to WaitQuorum","v":0,"name":"crucible","level":30,"time":"2024-01-10T17:59:24.854228934Z","hostname":"ip-10-150-1-187.us-west-2.compute.internal","pid":1202,"client":"0","":"downstairs","session_id":"bcbae331-3b70-434d-93c2-88d7337c0d37"}
2592024-01-10T17:59:24.857Z{"msg":"[0]R flush_numbers: [1856, 1856, 1856, 1856, 1856]","v":0,"name":"crucible","level":30,"time":"2024-01-10T17:59:24.854252536Z","hostname":"ip-10-150-1-187.us-west-2.compute.internal","pid":1202,"":"downstairs","":"downstairs","session_id":"bcbae331-3b70-434d-93c2-88d7337c0d37"}
2602024-01-10T17:59:24.857Z{"msg":"[0]R generation: [31, 31, 31, 31, 31]","v":0,"name":"crucible","level":30,"time":"2024-01-10T17:59:24.854292442Z","hostname":"ip-10-150-1-187.us-west-2.compute.internal","pid":1202,"":"downstairs","":"downstairs","session_id":"bcbae331-3b70-434d-93c2-88d7337c0d37"}
2612024-01-10T17:59:24.857Z{"msg":"[0]R dirty: [false, false, false, false, false]","v":0,"name":"crucible","level":30,"time":"2024-01-10T17:59:24.854316183Z","hostname":"ip-10-150-1-187.us-west-2.compute.internal","pid":1202,"":"downstairs","":"downstairs","session_id":"bcbae331-3b70-434d-93c2-88d7337c0d37"}
2622024-01-10T17:59:24.857Z{"msg":"[1]R flush_numbers: [1856, 1856, 1856, 1856, 1856]","v":0,"name":"crucible","level":30,"time":"2024-01-10T17:59:24.854369355Z","hostname":"ip-10-150-1-187.us-west-2.compute.internal","pid":1202,"":"downstairs","":"downstairs","session_id":"bcbae331-3b70-434d-93c2-88d7337c0d37"}
2632024-01-10T17:59:24.857Z{"msg":"[1]R generation: [31, 31, 31, 31, 31]","v":0,"name":"crucible","level":30,"Wait for a query_work_queue command to finish before sending IO
2642024-01-10T17:59:24.857Ztime":"2024-01-10T17:59:24.854392327Z","hostname":"ip-10-150-1-187.us-west-2.compute.internal","pid":1202,"":"downstairs","":"downstairs","session_id":"bcbae331-3b70-434d-93c2-88d7337c0d37"}
2652024-01-10T17:59:24.857Z{"msg":"[1]R dirty: [false, false, false, false, false]","v":0,"name":"crucible","level":30,"time":"2024-01-10T17:59:24.854419368Z","hostname":"ip-10-150-1-187.us-west-2.compute.internal","pid":1202,"":"downstairs","":"downstairs","session_id":"bcbae331-3b70-434d-93c2-88d7337c0d37"}
2662024-01-10T17:59:24.857Z{"msg":"[2]R flush_numbers: [1856, 1856, 1856, 1856, 1856]","v":0,"name":"crucible","level":30,"time":"2024-01-10T17:59:24.854441555Z","hostname":"ip-10-150-1-187.us-west-2.compute.internal","pid":1202,"":"downstairs","":"downstairs","session_id":"bcbae331-3b70-434d-93c2-88d7337c0d37"}
2672024-01-10T17:59:24.857Z{"msg":"[2]R generation: [31, 31, 31, 31, 31]","v":0,"name":"crucible","level":30,"time":"2024-01-10T17:59:24.854463095Z","hostname":"ip-10-150-1-187.us-west-2.compute.internal","pid":1202,"":"downstairs","":"downstairs","session_id":"bcbae331-3b70-434d-93c2-88d7337c0d37"}
2682024-01-10T17:59:24.857Z{"msg":"[2]R dirty: [false, false, false, false, false]","v":0,"name":"crucible","level":30,"time":"2024-01-10T17:59:24.854484824Z","hostname":"ip-10-150-1-187.us-west-2.compute.internal","pid":1202,"":"downstairs","":"downstairs","session_id":"bcbae331-3b70-434d-93c2-88d7337c0d37"}
2692024-01-10T17:59:24.858Z{"msg":"Max found gen is 32","v":0,"name":"crucible","level":30,"time":"2024-01-10T17:59:24.854510906Z","hostname":"ip-10-150-1-187.us-west-2.compute.internal","pid":1202,"":"downstairs","":"downstairs","session_id":"bcbae331-3b70-434d-93c2-88d7337c0d37"}
2702024-01-10T17:59:24.858Z{"msg":"Generation requested: 32 >= found:32","v":0,"name":"crucible","level":30,"time":"2024-01-10T17:59:24.854557469Z","hostname":"ip-10-150-1-187.us-west-2.compute.internal","pid":1202,"":"downstairs","":"downstairs","session_id":"bcbae331-3b70-434d-93c2-88d7337c0d37"}
2712024-01-10T17:59:24.858Z{"msg":"Next flush: 1857","v":0,"name":"crucible","level":30,"time":"2024-01-10T17:59:24.854581389Z","hostname":"ip-10-150-1-187.us-west-2.compute.internal","pid":1202,"":"downstairs","":"downstairs","session_id":"bcbae331-3b70-434d-93c2-88d7337c0d37"}
2722024-01-10T17:59:24.858Z{"msg":"All extents match","v":0,"name":"crucible","level":30,"time":"2024-01-10T17:59:24.854603051Z","hostname":"ip-10-150-1-187.us-west-2.compute.internal","pid":1202,"":"downstairs","":"downstairs","session_id":"bcbae331-3b70-434d-93c2-88d7337c0d37"}
2732024-01-10T17:59:24.858Z{"msg":"No downstairs repair required","v":0,"name":"crucible","level":30,"time":"2024-01-10T17:59:24.854642596Z","hostname":"ip-10-150-1-187.us-west-2.compute.internal","pid":1202,"session_id":"bcbae331-3b70-434d-93c2-88d7337c0d37"}
2742024-01-10T17:59:24.858Z{"msg":"Transition from WaitQuorum to Active","v":0,"name":"crucible","level":30,"time":"2024-01-10T17:59:24.854664144Z","hostname":"ip-10-150-1-187.us-west-2.compute.internal","pid":1202,"client":"0","":"downstairs","session_id":"bcbae331-3b70-434d-93c2-88d7337c0d37"}
2752024-01-10T17:59:24.858Z{"msg":"Transition from WaitQuorum to Active","v":0,"name":"crucible","level":30,"time":"2024-01-10T17:59:24.854685857Z","hostname":"ip-10-150-1-187.us-west-2.compute.internal","pid":1202,"client":"1","":"downstairs","session_id":"bcbae331-3b70-434d-93c2-88d7337c0d37"}
2762024-01-10T17:59:24.859Z{"msg":"Transition from WaitQuorum to Active","v":0,"name":"crucible","level":30,"time":"2024-01-10T17:59:24.854733318Z","hostname":"ip-10-150-1-187.us-west-2.compute.internal","pid":1202,"client":"2","":"downstairs","session_id":"bcbae331-3b70-434d-93c2-88d7337c0d37"}
2772024-01-10T17:59:24.859Z{"msg":"All required repair work is completed","v":0,"name":"crucible","level":30,"time":"2024-01-10T17:59:24.854756079Z","hostname":"ip-10-150-1-187.us-west-2.compute.internal","pid":1202,"session_id":"bcbae331-3b70-434d-93c2-88d7337c0d37"}
2782024-01-10T17:59:24.859Z{"msg":"Set Downstairs and Upstairs active after repairs","v":0,"name":"crucible","level":30,"time":"2024-01-10T17:59:24.85477614Z","hostname":"ip-10-150-1-187.us-west-2.compute.internal","pid":1202,"session_id":"bcbae331-3b70-434d-93c2-88d7337c0d37"}
2792024-01-10T17:59:24.860Z{"msg":"da86e24c-6477-4afc-a78f-4efacefedc0d is now active with session: bcbae331-3b70-434d-93c2-88d7337c0d37","v":0,"name":"crucible","level":30,"time":"2024-01-10T17:59:24.854820415Z","hostname":"ip-10-150-1-187.us-west-2.compute.internal","pid":1202,"session_id":"bcbae331-3b70-434d-93c2-88d7337c0d37"}
2802024-01-10T17:59:24.860Z{"msg":"Set Active after no repair","v":0,"name":"crucible","level":30,"time":"2024-01-10T17:59:24.854841184Z","hostname":"ip-10-150-1-187.us-west-2.compute.internal","pid":1202,"session_id":"bcbae331-3b70-434d-93c2-88d7337c0d37"}
2812024-01-10T17:59:24.860Z{"msg":"The guest has finished waiting for activation with:32","v":0,"name":"crucible","level":30,"Region: es:10 ec:5 bs:4096 ts:204800 tb:50 max_io:50 or 204800
2822024-01-10T17:59:24.861Ztime":"2024-01-10T17:59:24.854901798Z","hostname":"ip-10-150-1-187.us-west-2.compute.internal","pid":1202}
2832024-01-10T17:59:24.861ZLoading write count information from file "/var/tmp/test_up/verify_file"
2842024-01-10T17:59:24.861ZRun Repair workload
2852024-01-10T17:59:24.861Z01/10 Write block 30 len 40960 data: 2 2 2 2 2 2 2 2 2 2
2862024-01-10T17:59:24.866Z02/10 Write block 11 len 36864 data: 2 2 2 2 2 2 2 2 2
2872024-01-10T17:59:24.879Z03/10 Write block 38 len 20480 data: 3 3 2 2 2
2882024-01-10T17:59:24.882Z04/10 Flush
2892024-01-10T17:59:24.888Z05/10 Write block 3 len 20480 data: 2 2 2 2 2
2902024-01-10T17:59:24.894Z06/10 Flush
2912024-01-10T17:59:24.898Z07/10 Write block 29 len 20480 data: 2 3 3 3 3
2922024-01-10T17:59:24.904Z08/10 Write block 16 len 8192 data: 3 3
2932024-01-10T17:59:24.907Z09/10 Write block 30 len 12288 data: 4 4 4
2942024-01-10T17:59:24.911Z10/10 Read block 46 len 12288
2952024-01-10T17:59:24.922Z----------------------------------------------------------------
2962024-01-10T17:59:24.922Z Crucible gen:32 GIO:true work queues: Upstairs:0 downstairs:4
2972024-01-10T17:59:24.922ZStates: Active Active Active
2982024-01-10T17:59:24.922ZGW_ID ACK DSID TYPE BLOCKS DS:0 DS:1 DS:2 REPLAY
2992024-01-10T17:59:24.926Z 7 Acked 1006 Write 5 Done Done Done false
3002024-01-10T17:59:24.926Z 8 Acked 1007 Write 2 Done Done Done false
3012024-01-10T17:59:24.926Z 9 Acked 1008 Write 3 Done Done Done false
3022024-01-10T17:59:24.926Z 10 Acked 1009 Read 3 Done Done Done false
3032024-01-10T17:59:24.926Z STATES DS:0 DS:1 DS:2 TOTAL
3042024-01-10T17:59:24.926Z New 0 0 0 0
3052024-01-10T17:59:24.926Z Sent 0 0 0 0
3062024-01-10T17:59:24.926Z Done 4 4 4 12
3072024-01-10T17:59:24.926Z Skipped 0 0 0 0
3082024-01-10T17:59:24.926Z Error 0 0 0 0
3092024-01-10T17:59:24.926ZLast Flush: 1005 1005 1005
3102024-01-10T17:59:24.926ZDownstairs last five completed: 1005 1004 1003 1002 1001
3112024-01-10T17:59:24.934ZUpstairs last five completed: 10 9 8 7 6
3122024-01-10T17:59:24.934ZWrote out file "/var/tmp/test_up/verify_file"
3132024-01-10T17:59:24.934ZRepair part 1 passed
3142024-01-10T17:59:24.935Z
3152024-01-10T17:59:24.935ZKill the current downstairs
3162024-01-10T17:59:25.129Zrm -rf /var/tmp/test_up/8830
3172024-01-10T17:59:25.129ZNow put back the original so we have a mismatch
3182024-01-10T17:59:25.129Zmv /var/tmp/test_up/previous /var/tmp/test_up/8830
3192024-01-10T17:59:25.134ZRestart downstairs with old directory
3202024-01-10T17:59:25.232Z/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
3212024-01-10T17:59:25.252ZEXT BLOCKS GEN0 GEN1 GEN2 FL0 FL1 FL2 D0 D1 D2 DIFF
3222024-01-10T17:59:25.255Z 0 000-009 32 32 31 1858 1858 1856 F F F <---
3232024-01-10T17:59:25.255Z 1 010-019 32 32 31 1857 1857 1856 T T F <---
3242024-01-10T17:59:25.257Z 2 020-029 31 31 31 1856 1856 1856 T T F <---
3252024-01-10T17:59:25.257Z 3 030-039 32 32 31 1857 1857 1856 T T F <---
3262024-01-10T17:59:25.257Z 4 040-049 32 32 31 1857 1857 1856 F F F <---
3272024-01-10T17:59:25.257ZMax gen: 32, Max flush: 1858
3282024-01-10T17:59:25.257ZError: Difference in extent metadata found!
3292024-01-10T17:59:25.260Zdump test found error as expected
3302024-01-10T17:59:25.260Z
3312024-01-10T17:59:25.260Z
3322024-01-10T17:59:25.260Z/var/tmp/bins/crutest deactivate --range -g 33 -q --key boT7NTSGT7uMkx4oORu6LkvCOeLC/cizc8y5BTSIj+c= -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
3332024-01-10T17:59:25.275Z{"msg":"Upstairs starts","v":0,"name":"crucible","level":30,"time":"2024-01-10T17:59:25.279473613Z","hostname":"ip-10-150-1-187.us-west-2.compute.internal","pid":1209}
3342024-01-10T17:59:25.279Z{"msg":"Crucible Version: BuildInfo {\n version: \"0.0.1\",\n git_sha: \"99c957c6a74e6d7d6180d15bada5890df4de8432\",\n git_commit_timestamp: \"2024-01-10T17:30:23.000000000Z\",\n git_branch: \"renovate/rust-1.x\",\n rustc_semver: \"1.75.0\",\n rustc_channel: \"stable\",\n rustc_host_triple: \"x86_64-unknown-illumos\",\n rustc_commit_sha: \"82e1608dfa6e0b5569232559e3d385fea5a93112\",\n cargo_triple: \"x86_64-unknown-illumos\",\n debug: true,\n opt_level: 0,\n}","v":0,"name":"crucible","level":30,"time":"2024-01-10T17:59:25.279976772Z","hostname":"ip-10-150-1-187.us-west-2.compute.internal","pid":1209}
3352024-01-10T17:59:25.279Z{"msg":"Upstairs <-> Downstairs Message Version: 5","v":0,"name":"crucible","level":30,"time":"2024-01-10T17:59:25.280068654Z","hostname":"ip-10-150-1-187.us-west-2.compute.internal","pid":1209}
3362024-01-10T17:59:25.279Z{"msg":"Crucible 111cec26-fccc-409d-b696-61f0d5a6326e has session id: fa4dd422-1eec-409e-986b-0fd99f28724e","v":0,"name":"crucible","level":30,"time":"2024-01-10T17:59:25.280107726Z","hostname":"ip-10-150-1-187.us-west-2.compute.internal","pid":1209,"session_id":"fa4dd422-1eec-409e-986b-0fd99f28724e"}
3372024-01-10T17:59:25.280Z{"msg":"Upstairs opts: Upstairs UUID: 111cec26-fccc-409d-b696-61f0d5a6326e, Targets: [127.0.0.1:8810, 127.0.0.1:8820, 127.0.0.1:8830], lossy: false, flush_timeout: None, key populated: true, cert_pem populated: false, key_pem populated: false, root_cert_pem populated: false, Control: None, read_only: false","v":0,"name":"crucible","level":30,"time":"2024-01-10T17:59:25.280161543Z","hostname":"ip-10-150-1-187.us-west-2.compute.internal","pid":1209,"session_id":"fa4dd422-1eec-409e-986b-0fd99f28724e"}
3382024-01-10T17:59:25.280Z{"msg":"Crucible stats registered with UUID: 111cec26-fccc-409d-b696-61f0d5a6326e","v":0,"name":"crucible","level":30,"time":"2024-01-10T17:59:25.280201005Z","hostname":"ip-10-150-1-187.us-west-2.compute.internal","pid":1209,"session_id":"fa4dd422-1eec-409e-986b-0fd99f28724e"}
3392024-01-10T17:59:25.281ZCrucible runtime is spawned
3402024-01-10T17:59:25.281Z{"msg":"The guest has requested activation with gen:33","v":0,"name":"crucible","level":30,"time":"2024-01-10T17:59:25.280427878Z","hostname":"ip-10-150-1-187.us-west-2.compute.internal","pid":1209}
3412024-01-10T17:59:25.281Z{"msg":"111cec26-fccc-409d-b696-61f0d5a6326e active request set","v":0,"name":"crucible","level":30,"time":"2024-01-10T17:59:25.280590598Z","hostname":"ip-10-150-1-187.us-west-2.compute.internal","pid":1209,"session_id":"fa4dd422-1eec-409e-986b-0fd99f28724e"}
3422024-01-10T17:59:25.281Z{"msg":"sending connect oneshot to client","v":0,"name":"crucible","level":30,"time":"2024-01-10T17:59:25.280654331Z","hostname":"ip-10-150-1-187.us-west-2.compute.internal","pid":1209,"client":"0","":"downstairs","session_id":"fa4dd422-1eec-409e-986b-0fd99f28724e"}
3432024-01-10T17:59:25.281Z{"msg":"client set_active_request while in New; waiting...","v":0,"name":"crucible","level":30,"time":"2024-01-10T17:59:25.280681988Z","hostname":"ip-10-150-1-187.us-west-2.compute.internal","pid":1209,"client":"0","":"downstairs","session_id":"fa4dd422-1eec-409e-986b-0fd99f28724e"}
3442024-01-10T17:59:25.281Z{"msg":"sending connect oneshot to client","v":0,"name":"crucible","level":30,"time":"2024-01-10T17:59:25.280731494Z","hostname":"ip-10-150-1-187.us-west-2.compute.internal","pid":1209,"client":"1","":"downstairs","session_id":"fa4dd422-1eec-409e-986b-0fd99f28724e"}
3452024-01-10T17:59:25.281Z{"msg":"client set_active_request while in New; waiting...","v":0,"name":"crucible","level":30,"time":"2024-01-10T17:59:25.280811043Z","hostname":"ip-10-150-1-187.us-west-2.compute.internal","pid":1209,"client":"1","":"downstairs","session_id":"fa4dd422-1eec-409e-986b-0fd99f28724e"}
3462024-01-10T17:59:25.281Z{"msg":"sending connect oneshot to client","v":0,"name":"crucible","level":30,"time":"2024-01-10T17:59:25.280856682Z","hostname":"ip-10-150-1-187.us-west-2.compute.internal","pid":1209,"client":"2","":"downstairs","session_id":"fa4dd422-1eec-409e-986b-0fd99f28724e"}
3472024-01-10T17:59:25.281Z{"msg":"client set_active_request while in New; waiting...","v":0,"name":"crucible","level":30,"time":"2024-01-10T17:59:25.280922477Z","hostname":"ip-10-150-1-187.us-west-2.compute.internal","pid":1209,"client":"2","":"downstairs","session_id":"fa4dd422-1eec-409e-986b-0fd99f28724e"}
3482024-01-10T17:59:25.281Z{"msg":"connecting to 127.0.0.1:8810","v":0,"name":"crucible","level":30,"time":"2024-01-10T17:59:25.280965438Z","hostname":"ip-10-150-1-187.us-west-2.compute.internal","pid":1209,"":"io task","client":"0","":"downstairs","session_id":"fa4dd422-1eec-409e-986b-0fd99f28724e"}
3492024-01-10T17:59:25.281Z{"msg":"connecting to 127.0.0.1:8820","v":0,"name":"crucible","level":30,"time":"2024-01-10T17:59:25.28099722Z","hostname":"ip-10-150-1-187.us-west-2.compute.internal","pid":1209,"":"io task","client":"1","":"downstairs","session_id":"fa4dd422-1eec-409e-986b-0fd99f28724e"}
3502024-01-10T17:59:25.282Z{"msg":"connecting to 127.0.0.1:8830","v":0,"name":"crucible","level":30,"time":"2024-01-10T17:59:25.281030387Z","hostname":"ip-10-150-1-187.us-west-2.compute.internal","pid":1209,"":"io task","client":"2","":"downstairs","session_id":"fa4dd422-1eec-409e-986b-0fd99f28724e"}
3512024-01-10T17:59:25.282Z{"msg":"ds_connection connect to 127.0.0.1:8830 failure: Os { code: 146, kind: ConnectionRefused, message: \"Connection refused\" }","v":0,"name":"crucible","level":40,"time":"2024-01-10T17:59:25.281143334Z","hostname":"ip-10-150-1-187.us-west-2.compute.internal","pid":1209,"":"io task","client":"2","":"downstairs","session_id":"fa4dd422-1eec-409e-986b-0fd99f28724e"}
3522024-01-10T17:59:25.282Z{"msg":"client task is sending Done(ConnectionFailed(Os { code: 146, kind: ConnectionRefused, message: \"Connection refused\" }))","v":0,"name":"crucible","level":40,"time":"2024-01-10T17:59:25.281197057Z","hostname":"ip-10-150-1-187.us-west-2.compute.internal","pid":1209,"":"io task","client":"2","":"downstairs","session_id":"fa4dd422-1eec-409e-986b-0fd99f28724e"}
3532024-01-10T17:59:25.282Z{"msg":"ds_connection connected","v":0,"name":"crucible","level":30,"time":"2024-01-10T17:59:25.281242307Z","hostname":"ip-10-150-1-187.us-west-2.compute.internal","pid":1209,"":"io task","client":"0","":"downstairs","session_id":"fa4dd422-1eec-409e-986b-0fd99f28724e"}
3542024-01-10T17:59:25.282Z{"msg":"ds_connection connected","v":0,"name":"crucible","level":30,"time":"2024-01-10T17:59:25.281283928Z","hostname":"ip-10-150-1-187.us-west-2.compute.internal","pid":1209,"":"io task","client":"1","":"downstairs","session_id":"fa4dd422-1eec-409e-986b-0fd99f28724e"}
3552024-01-10T17:59:25.282Z{"msg":"downstairs task for 2 stopped due to ConnectionFailed(Os { code: 146, kind: ConnectionRefused, message: \"Connection refused\" })","v":0,"name":"crucible","level":40,"time":"2024-01-10T17:59:25.281330691Z","hostname":"ip-10-150-1-187.us-west-2.compute.internal","pid":1209,"session_id":"fa4dd422-1eec-409e-986b-0fd99f28724e"}
3562024-01-10T17:59:25.282Z{"msg":"Gone missing, transition from New to Disconnected","v":0,"name":"crucible","level":30,"time":"2024-01-10T17:59:25.281401682Z","hostname":"ip-10-150-1-187.us-west-2.compute.internal","pid":1209,"client":"2","":"downstairs","session_id":"fa4dd422-1eec-409e-986b-0fd99f28724e"}
3572024-01-10T17:59:25.282Z{"msg":"Disconnected -> New","v":0,"name":"crucible","level":30,"time":"2024-01-10T17:59:25.281470003Z","hostname":"ip-10-150-1-187.us-west-2.compute.internal","pid":1209,"client":"2","":"downstairs","session_id":"fa4dd422-1eec-409e-986b-0fd99f28724e"}
3582024-01-10T17:59:25.282Z{"msg":"client task is exiting","v":0,"name":"crucible","level":30,"time":"2024-01-10T17:59:25.281545754Z","hostname":"ip-10-150-1-187.us-west-2.compute.internal","pid":1209,"":"io task","client":"2","":"downstairs","session_id":"fa4dd422-1eec-409e-986b-0fd99f28724e"}
3592024-01-10T17:59:25.282Z{"msg":"ds_transition from New to WaitActive","v":0,"name":"crucible","level":30,"time":"2024-01-10T17:59:25.282347288Z","hostname":"ip-10-150-1-187.us-west-2.compute.internal","pid":1209,"client":"0","":"downstairs","session_id":"fa4dd422-1eec-409e-986b-0fd99f28724e"}
3602024-01-10T17:59:25.283Z{"msg":"[0] Transition from New to WaitActive","v":0,"name":"crucible","level":30,"time":"2024-01-10T17:59:25.282454574Z","hostname":"ip-10-150-1-187.us-west-2.compute.internal","pid":1209,"client":"0","":"downstairs","session_id":"fa4dd422-1eec-409e-986b-0fd99f28724e"}
3612024-01-10T17:59:25.283Z{"msg":"ds_transition from New to WaitActive","v":0,"name":"crucible","level":30,"time":"2024-01-10T17:59:25.282583827Z","hostname":"ip-10-150-1-187.us-west-2.compute.internal","pid":1209,"client":"1","":"downstairs","session_id":"fa4dd422-1eec-409e-986b-0fd99f28724e"}
3622024-01-10T17:59:25.283Z{"msg":"[1] Transition from New to WaitActive","v":0,"name":"crucible","level":30,"time":"2024-01-10T17:59:25.282669282Z","hostname":"ip-10-150-1-187.us-west-2.compute.internal","pid":1209,"client":"1","":"downstairs","session_id":"fa4dd422-1eec-409e-986b-0fd99f28724e"}
3632024-01-10T17:59:25.287Z{"msg":"downstairs client at Some(127.0.0.1:8820) has region UUID 12345678-0000-0000-0000-000000008820","v":0,"name":"crucible","level":30,"time":"2024-01-10T17:59:25.283346441Z","hostname":"ip-10-150-1-187.us-west-2.compute.internal","pid":1209,"client":"1","":"downstairs","session_id":"fa4dd422-1eec-409e-986b-0fd99f28724e"}
3642024-01-10T17:59:25.287Z{"msg":"downstairs client at Some(127.0.0.1:8810) has region UUID 12345678-0000-0000-0000-000000008810","v":0,"name":"crucible","level":30,"time":"2024-01-10T17:59:25.28343969Z","hostname":"ip-10-150-1-187.us-west-2.compute.internal","pid":1209,"client":"0","":"downstairs","session_id":"fa4dd422-1eec-409e-986b-0fd99f28724e"}
3652024-01-10T17:59:25.287Z{"msg":"ds_transition from WaitActive to WaitQuorum","v":0,"name":"crucible","level":30,"time":"2024-01-10T17:59:25.283963398Z","hostname":"ip-10-150-1-187.us-west-2.compute.internal","pid":1209,"client":"1","":"downstairs","session_id":"fa4dd422-1eec-409e-986b-0fd99f28724e"}
3662024-01-10T17:59:25.287Z{"msg":"[1] Transition from WaitActive to WaitQuorum","v":0,"name":"crucible","level":30,"time":"2024-01-10T17:59:25.284033318Z","hostname":"ip-10-150-1-187.us-west-2.compute.internal","pid":1209,"client":"1","":"downstairs","session_id":"fa4dd422-1eec-409e-986b-0fd99f28724e"}
3672024-01-10T17:59:25.287Z{"msg":"Waiting for true more clients to be ready","v":0,"name":"crucible","level":30,"time":"2024-01-10T17:59:25.284115502Z","hostname":"ip-10-150-1-187.us-west-2.compute.internal","pid":1209,"session_id":"fa4dd422-1eec-409e-986b-0fd99f28724e"}
3682024-01-10T17:59:25.287Z{"msg":"ds_transition from WaitActive to WaitQuorum","v":0,"name":"crucible","level":30,"time":"2024-01-10T17:59:25.284156638Z","hostname":"ip-10-150-1-187.us-west-2.compute.internal","pid":1209,"client":"0","":"downstairs","session_id":"fa4dd422-1eec-409e-986b-0fd99f28724e"}
3692024-01-10T17:59:25.287Z{"msg":"[0] Transition from WaitActive to WaitQuorum","v":0,"name":"crucible","level":30,"time":"2024-01-10T17:59:25.284180302Z","hostname":"ip-10-150-1-187.us-west-2.compute.internal","pid":1209,"client":"0","":"downstairs","session_id":"fa4dd422-1eec-409e-986b-0fd99f28724e"}
3702024-01-10T17:59:25.287Z{"msg":"Waiting for true more clients to be ready","v":0,"name":"crucible","level":30,"time":"2024-01-10T17:59:25.284202324Z","hostname":"ip-10-150-1-187.us-west-2.compute.internal","pid":1209,"session_id":"fa4dd422-1eec-409e-986b-0fd99f28724e"}
3712024-01-10T17:59:26.279Z{"msg":"connecting to 127.0.0.1:8830","v":0,"name":"crucible","level":30,"time":"2024-01-10T17:59:26.283141733Z","hostname":"ip-10-150-1-187.us-west-2.compute.internal","pid":1209,"":"io task","client":"2","":"downstairs","session_id":"fa4dd422-1eec-409e-986b-0fd99f28724e"}
3722024-01-10T17:59:26.279Z{"msg":"ds_connection connect to 127.0.0.1:8830 failure: Os { code: 146, kind: ConnectionRefused, message: \"Connection refused\" }","v":0,"name":"crucible","level":40,"time":"2024-01-10T17:59:26.283268773Z","hostname":"ip-10-150-1-187.us-west-2.compute.internal","pid":1209,"":"io task","client":"2","":"downstairs","session_id":"fa4dd422-1eec-409e-986b-0fd99f28724e"}
3732024-01-10T17:59:26.279Z{"msg":"client task is sending Done(ConnectionFailed(Os { code: 146, kind: ConnectionRefused, message: \"Connection refused\" }))","v":0,"name":"crucible","level":40,"time":"2024-01-10T17:59:26.283299762Z","hostname":"ip-10-150-1-187.us-west-2.compute.internal","pid":1209,"":"io task","client":"2","":"downstairs","session_id":"fa4dd422-1eec-409e-986b-0fd99f28724e"}
3742024-01-10T17:59:26.279Z{"msg":"downstairs task for 2 stopped due to ConnectionFailed(Os { code: 146, kind: ConnectionRefused, message: \"Connection refused\" })","v":0,"name":"crucible","level":40,"time":"2024-01-10T17:59:26.283328409Z","hostname":"ip-10-150-1-187.us-west-2.compute.internal","pid":1209,"session_id":"fa4dd422-1eec-409e-986b-0fd99f28724e"}
3752024-01-10T17:59:26.283Z{"msg":"Gone missing, transition from New to Disconnected","v":0,"name":"crucible","level":30,"time":"2024-01-10T17:59:26.28338304Z","hostname":"ip-10-150-1-187.us-west-2.compute.internal","pid":1209,"client":"2","":"downstairs","session_id":"fa4dd422-1eec-409e-986b-0fd99f28724e"}
3762024-01-10T17:59:26.283Z{"msg":"Disconnected -> New","v":0,"name":"crucible","level":30,"time":"2024-01-10T17:59:26.283444554Z","hostname":"ip-10-150-1-187.us-west-2.compute.internal","pid":1209,"client":"2","":"downstairs","session_id":"fa4dd422-1eec-409e-986b-0fd99f28724e"}
3772024-01-10T17:59:26.283Z{"msg":"client task is exiting","v":0,"name":"crucible","level":30,"time":"2024-01-10T17:59:26.283666111Z","hostname":"ip-10-150-1-187.us-west-2.compute.internal","pid":1209,"":"io task","client":"2","":"downstairs","session_id":"fa4dd422-1eec-409e-986b-0fd99f28724e"}
3782024-01-10T17:59:27.281Z{"msg":"connecting to 127.0.0.1:8830","v":0,"name":"crucible","level":30,"time":"2024-01-10T17:59:27.284705687Z","hostname":"ip-10-150-1-187.us-west-2.compute.internal","pid":1209,"":"io task","client":"2","":"downstairs","session_id":"fa4dd422-1eec-409e-986b-0fd99f28724e"}
3792024-01-10T17:59:27.281Z{"msg":"ds_connection connect to 127.0.0.1:8830 failure: Os { code: 146, kind: ConnectionRefused, message: \"Connection refused\" }","v":0,"name":"crucible","level":40,"time":"2024-01-10T17:59:27.284796835Z","hostname":"ip-10-150-1-187.us-west-2.compute.internal","pid":1209,"":"io task","client":"2","":"downstairs","session_id":"fa4dd422-1eec-409e-986b-0fd99f28724e"}
3802024-01-10T17:59:27.282Z{"msg":"client task is sending Done(ConnectionFailed(Os { code: 146, kind: ConnectionRefused, message: \"Connection refused\" }))","v":0,"name":"crucible","level":40,"time":"2024-01-10T17:59:27.284826648Z","hostname":"ip-10-150-1-187.us-west-2.compute.internal","pid":1209,"":"io task","client":"2","":"downstairs","session_id":"fa4dd422-1eec-409e-986b-0fd99f28724e"}
3812024-01-10T17:59:27.285Z{"msg":"downstairs task for 2 stopped due to ConnectionFailed(Os { code: 146, kind: ConnectionRefused, message: \"Connection refused\" })","v":0,"name":"crucible","level":40,"time":"2024-01-10T17:59:27.284854923Z","hostname":"ip-10-150-1-187.us-west-2.compute.internal","pid":1209,"session_id":"fa4dd422-1eec-409e-986b-0fd99f28724e"}
3822024-01-10T17:59:27.285Z{"msg":"Gone missing, transition from New to Disconnected","v":0,"name":"crucible","level":30,"time":"2024-01-10T17:59:27.284903423Z","hostname":"ip-10-150-1-187.us-west-2.compute.internal","pid":1209,"client":"2","":"downstairs","session_id":"fa4dd422-1eec-409e-986b-0fd99f28724e"}
3832024-01-10T17:59:27.285Z{"msg":"Disconnected -> New","v":0,"name":"crucible","level":30,"time":"2024-01-10T17:59:27.284927744Z","hostname":"ip-10-150-1-187.us-west-2.compute.internal","pid":1209,"client":"2","":"downstairs","session_id":"fa4dd422-1eec-409e-986b-0fd99f28724e"}
3842024-01-10T17:59:27.285Z{"msg":"client task is exiting","v":0,"name":"crucible","level":30,"time":"2024-01-10T17:59:27.284990217Z","hostname":"ip-10-150-1-187.us-west-2.compute.internal","pid":1209,"":"io task","client":"2","":"downstairs","session_id":"fa4dd422-1eec-409e-986b-0fd99f28724e"}
3852024-01-10T17:59:28.290Z{"msg":"connecting to 127.0.0.1:8830","v":0,"name":"crucible","level":30,"time":"2024-01-10T17:59:28.285883298Z","hostname":"ip-10-150-1-187.us-west-2.compute.internal","pid":1209,"":"io task","client":"2","":"downstairs","session_id":"fa4dd422-1eec-409e-986b-0fd99f28724e"}
3862024-01-10T17:59:28.290Z{"msg":"ds_connection connect to 127.0.0.1:8830 failure: Os { code: 146, kind: ConnectionRefused, message: \"Connection refused\" }","v":0,"name":"crucible","level":40,"time":"2024-01-10T17:59:28.285978712Z","hostname":"ip-10-150-1-187.us-west-2.compute.internal","pid":1209,"":"io task","client":"2","":"downstairs","session_id":"fa4dd422-1eec-409e-986b-0fd99f28724e"}
3872024-01-10T17:59:28.291Z{"msg":"client task is sending Done(ConnectionFailed(Os { code: 146, kind: ConnectionRefused, message: \"Connection refused\" }))","v":0,"name":"crucible","level":40,"time":"2024-01-10T17:59:28.286009794Z","hostname":"ip-10-150-1-187.us-west-2.compute.internal","pid":1209,"":"io task","client":"2","":"downstairs","session_id":"fa4dd422-1eec-409e-986b-0fd99f28724e"}
3882024-01-10T17:59:28.291Z{"msg":"downstairs task for 2 stopped due to ConnectionFailed(Os { code: 146, kind: ConnectionRefused, message: \"Connection refused\" })","v":0,"name":"crucible","level":40,"time":"2024-01-10T17:59:28.286037347Z","hostname":"ip-10-150-1-187.us-west-2.compute.internal","pid":1209,"session_id":"fa4dd422-1eec-409e-986b-0fd99f28724e"}
3892024-01-10T17:59:28.294Z{"msg":"Gone missing, transition from New to Disconnected","v":0,"name":"crucible","level":30,"time":"2024-01-10T17:59:28.286059796Z","hostname":"ip-10-150-1-187.us-west-2.compute.internal","pid":1209,"client":"2","":"downstairs","session_id":"fa4dd422-1eec-409e-986b-0fd99f28724e"}
3902024-01-10T17:59:28.294Z{"msg":"Disconnected -> New","v":0,"name":"crucible","level":30,"time":"2024-01-10T17:59:28.286120489Z","hostname":"ip-10-150-1-187.us-west-2.compute.internal","pid":1209,"client":"2","":"downstairs","session_id":"fa4dd422-1eec-409e-986b-0fd99f28724e"}
3912024-01-10T17:59:28.294Z{"msg":"client task is exiting","v":0,"name":"crucible","level":30,"time":"2024-01-10T17:59:28.286190003Z","hostname":"ip-10-150-1-187.us-west-2.compute.internal","pid":1209,"":"io task","client":"2","":"downstairs","session_id":"fa4dd422-1eec-409e-986b-0fd99f28724e"}
3922024-01-10T17:59:29.283Z{"msg":"connecting to 127.0.0.1:8830","v":0,"name":"crucible","level":30,"time":"2024-01-10T17:59:29.287117777Z","hostname":"ip-10-150-1-187.us-west-2.compute.internal","pid":1209,"":"io task","client":"2","":"downstairs","session_id":"fa4dd422-1eec-409e-986b-0fd99f28724e"}
3932024-01-10T17:59:29.283Z{"msg":"ds_connection connected","v":0,"name":"crucible","level":30,"time":"2024-01-10T17:59:29.287215114Z","hostname":"ip-10-150-1-187.us-west-2.compute.internal","pid":1209,"":"io task","client":"2","":"downstairs","session_id":"fa4dd422-1eec-409e-986b-0fd99f28724e"}
3942024-01-10T17:59:29.375Z{"msg":"ds_transition from New to WaitActive","v":0,"name":"crucible","level":30,"time":"2024-01-10T17:59:29.288297058Z","hostname":"ip-10-150-1-187.us-west-2.compute.internal","pid":1209,"client":"2","":"downstairs","session_id":"fa4dd422-1eec-409e-986b-0fd99f28724e"}
3952024-01-10T17:59:29.377Z{"msg":"[2] Transition from New to WaitActive","v":0,"name":"crucible","level":30,"time":"2024-01-10T17:59:29.288369698Z","hostname":"ip-10-150-1-187.us-west-2.compute.internal","pid":1209,"client":"2","":"downstairs","session_id":"fa4dd422-1eec-409e-986b-0fd99f28724e"}
3962024-01-10T17:59:29.377Z{"msg":"downstairs client at Some(127.0.0.1:8830) has region UUID 12345678-0000-0000-0000-000000008830","v":0,"name":"crucible","level":30,"time":"2024-01-10T17:59:29.289085516Z","hostname":"ip-10-150-1-187.us-west-2.compute.internal","pid":1209,"client":"2","":"downstairs","session_id":"fa4dd422-1eec-409e-986b-0fd99f28724e"}
3972024-01-10T17:59:29.377Z{"msg":"ds_transition from WaitActive to WaitQuorum","v":0,"name":"crucible","level":30,"time":"2024-01-10T17:59:29.289563482Z","hostname":"ip-10-150-1-187.us-west-2.compute.internal","pid":1209,"client":"2","":"downstairs","session_id":"fa4dd422-1eec-409e-986b-0fd99f28724e"}
3982024-01-10T17:59:29.377Z{"msg":"[2] Transition from WaitActive to WaitQuorum","v":0,"name":"crucible","level":30,"time":"2024-01-10T17:59:29.289624429Z","hostname":"ip-10-150-1-187.us-west-2.compute.internal","pid":1209,"client":"2","":"downstairs","session_id":"fa4dd422-1eec-409e-986b-0fd99f28724e"}
3992024-01-10T17:59:29.377Z{"msg":"[0]R flush_numbers: [1858, 1857, 1856, 1857, 1857]","v":0,"name":"crucible","level":30,"time":"2024-01-10T17:59:29.289650306Z","hostname":"ip-10-150-1-187.us-west-2.compute.internal","pid":1209,"":"downstairs","":"downstairs","session_id":"fa4dd422-1eec-409e-986b-0fd99f28724e"}
4002024-01-10T17:59:29.378Z{"msg":"[0]R generation: [32, 32, 31, 32, 32]","v":0,"name":"crucible","level":30,"time":"2024-01-10T17:59:29.289708078Z","hostname":"ip-10-150-1-187.us-west-2.compute.internal","pid":1209,"":"downstairs","":"downstairs","session_id":"fa4dd422-1eec-409e-986b-0fd99f28724e"}
4012024-01-10T17:59:29.378Z{"msg":"[0]R dirty: [false, true, true, true, false]","v":0,"name":"crucible","level":30,"time":"2024-01-10T17:59:29.289741282Z","hostname":"ip-10-150-1-187.us-west-2.compute.internal","pid":1209,"":"downstairs","":"downstairs","session_id":"fa4dd422-1eec-409e-986b-0fd99f28724e"}
4022024-01-10T17:59:29.378Z{"msg":"[1]R flush_numbers: [1858, 1857, 1856, 1857, 1857]","v":0,"name":"crucible","level":30,"time":"2024-01-10T17:59:29.289797473Z","hostname":"ip-10-150-1-187.us-west-2.compute.internal","pid":1209,"":"downstairs","":"downstairs","session_id":"fa4dd422-1eec-409e-986b-0fd99f28724e"}
4032024-01-10T17:59:29.378Z{"msg":"[1]R generation: [32, 32, 31, 32, 32]","v":0,"name":"crucible","level":30,"time":"2024-01-10T17:59:29.289828937Z","hostname":"ip-10-150-1-187.us-west-2.compute.internal","pid":1209,"":"downstairs","":"downstairs","session_id":"fa4dd422-1eec-409e-986b-0fd99f28724e"}
4042024-01-10T17:59:29.379Z{"msg":"[1]R dirty: [false, true, true, true, false]","v":0,"name":"crucible","level":30,"time":"2024-01-10T17:59:29.289885986Z","hostname":"ip-10-150-1-187.us-west-2.compute.internal","pid":1209,"":"downstairs","":"downstairs","session_id":"fa4dd422-1eec-409e-986b-0fd99f28724e"}
4052024-01-10T17:59:29.379Z{"msg":"[2]R flush_numbers: [1856, 1856, 1856, 1856, 1856]","v":0,"name":"crucible","level":30,"time":"2024-01-10T17:59:29.289913741Z","hostname":"ip-10-150-1-187.us-west-2.compute.internal","pid":1209,"":"downstairs","":"downstairs","session_id":"fa4dd422-1eec-409e-986b-0fd99f28724e"}
4062024-01-10T17:59:29.379Z{"msg":"[2]R generation: [31, 31, 31, 31, 31]","v":0,"name":"crucible","level":30,"time":"2024-01-10T17:59:29.289971987Z","hostname":"ip-10-150-1-187.us-west-2.compute.internal","pid":1209,"":"downstairs","":"downstairs","session_id":"fa4dd422-1eec-409e-986b-0fd99f28724e"}
4072024-01-10T17:59:29.379Z{"msg":"[2]R dirty: [false, false, false, false, false]","v":0,"name":"crucible","level":30,"time":"2024-01-10T17:59:29.290004258Z","hostname":"ip-10-150-1-187.us-west-2.compute.internal","pid":1209,"":"downstairs","":"downstairs","session_id":"fa4dd422-1eec-409e-986b-0fd99f28724e"}
4082024-01-10T17:59:29.379Z{"msg":"Max found gen is 33","v":0,"name":"crucible","level":30,"time":"2024-01-10T17:59:29.290059133Z","hostname":"ip-10-150-1-187.us-west-2.compute.internal","pid":1209,"":"downstairs","":"downstairs","session_id":"fa4dd422-1eec-409e-986b-0fd99f28724e"}
4092024-01-10T17:59:29.379Z{"msg":"Generation requested: 33 >= found:33","v":0,"name":"crucible","level":30,"time":"2024-01-10T17:59:29.290090933Z","hostname":"ip-10-150-1-187.us-west-2.compute.internal","pid":1209,"":"downstairs","":"downstairs","session_id":"fa4dd422-1eec-409e-986b-0fd99f28724e"}
4102024-01-10T17:59:29.380Z{"msg":"Next flush: 1859","v":0,"name":"crucible","level":30,"time":"2024-01-10T17:59:29.29014636Z","hostname":"ip-10-150-1-187.us-west-2.compute.internal","pid":1209,"":"downstairs","":"downstairs","session_id":"fa4dd422-1eec-409e-986b-0fd99f28724e"}
4112024-01-10T17:59:29.381Z{"msg":"Extents 1 dirty","v":0,"name":"crucible","level":30,"time":"2024-01-10T17:59:29.290173723Z","hostname":"ip-10-150-1-187.us-west-2.compute.internal","pid":1209,"":"mend","":"downstairs","":"downstairs","session_id":"fa4dd422-1eec-409e-986b-0fd99f28724e"}
4122024-01-10T17:59:29.381Z{"msg":"First source client ID for extent 1","v":0,"name":"crucible","level":30,"time":"2024-01-10T17:59:29.290232531Z","hostname":"ip-10-150-1-187.us-west-2.compute.internal","pid":1209,"mrl":"dirty","":"mend","":"downstairs","":"downstairs","session_id":"fa4dd422-1eec-409e-986b-0fd99f28724e"}
4132024-01-10T17:59:29.381Z{"msg":"extent:1 gens: 32 32 31","v":0,"name":"crucible","level":30,"time":"2024-01-10T17:59:29.290293477Z","hostname":"ip-10-150-1-187.us-west-2.compute.internal","pid":1209,"mrl":"dirty","":"mend","":"downstairs","":"downstairs","session_id":"fa4dd422-1eec-409e-986b-0fd99f28724e"}
4142024-01-10T17:59:29.381Z{"msg":"extent:1 flush: 1857 1857 1856 scs: [ClientId(0), ClientId(1)]","v":0,"name":"crucible","level":30,"time":"2024-01-10T17:59:29.290356731Z","hostname":"ip-10-150-1-187.us-west-2.compute.internal","pid":1209,"mrl":"dirty","":"mend","":"downstairs","":"downstairs","session_id":"fa4dd422-1eec-409e-986b-0fd99f28724e"}
4152024-01-10T17:59:29.381Z{"msg":"max_flush now has: [ClientId(0), ClientId(1)]","v":0,"name":"crucible","level":30,"time":"2024-01-10T17:59:29.290418586Z","hostname":"ip-10-150-1-187.us-west-2.compute.internal","pid":1209,"mrl":"dirty","":"mend","":"downstairs","":"downstairs","session_id":"fa4dd422-1eec-409e-986b-0fd99f28724e"}
4162024-01-10T17:59:29.381Z{"msg":"extent:1 dirty: true true false","v":0,"name":"crucible","level":30,"time":"2024-01-10T17:59:29.290479333Z","hostname":"ip-10-150-1-187.us-west-2.compute.internal","pid":1209,"mrl":"dirty","":"mend","":"downstairs","":"downstairs","session_id":"fa4dd422-1eec-409e-986b-0fd99f28724e"}
4172024-01-10T17:59:29.382Z{"msg":"find dest for source 0 for extent at index 1","v":0,"name":"crucible","level":30,"time":"2024-01-10T17:59:29.29054036Z","hostname":"ip-10-150-1-187.us-west-2.compute.internal","pid":1209,"mrl":"dirty","":"mend","":"downstairs","":"downstairs","session_id":"fa4dd422-1eec-409e-986b-0fd99f28724e"}
4182024-01-10T17:59:29.382Z{"msg":"source 0, add dest 1 source flush","v":0,"name":"crucible","level":30,"time":"2024-01-10T17:59:29.290569864Z","hostname":"ip-10-150-1-187.us-west-2.compute.internal","pid":1209,"mrl":"dirty","":"mend","":"downstairs","":"downstairs","session_id":"fa4dd422-1eec-409e-986b-0fd99f28724e"}
4192024-01-10T17:59:29.382Z{"msg":"source 0, add dest 2 gen","v":0,"name":"crucible","level":30,"time":"2024-01-10T17:59:29.290628285Z","hostname":"ip-10-150-1-187.us-west-2.compute.internal","pid":1209,"mrl":"dirty","":"mend","":"downstairs","":"downstairs","session_id":"fa4dd422-1eec-409e-986b-0fd99f28724e"}
4202024-01-10T17:59:29.383Z{"msg":"Extents 2 dirty","v":0,"name":"crucible","level":30,"time":"2024-01-10T17:59:29.290658241Z","hostname":"ip-10-150-1-187.us-west-2.compute.internal","pid":1209,"":"mend","":"downstairs","":"downstairs","session_id":"fa4dd422-1eec-409e-986b-0fd99f28724e"}
4212024-01-10T17:59:29.383Z{"msg":"First source client ID for extent 2","v":0,"name":"crucible","level":30,"time":"2024-01-10T17:59:29.290691352Z","hostname":"ip-10-150-1-187.us-west-2.compute.internal","pid":1209,"mrl":"dirty","":"mend","":"downstairs","":"downstairs","session_id":"fa4dd422-1eec-409e-986b-0fd99f28724e"}
4222024-01-10T17:59:29.383Z{"msg":"extent:2 gens: 31 31 31","v":0,"name":"crucible","level":30,"time":"2024-01-10T17:59:29.290725559Z","hostname":"ip-10-150-1-187.us-west-2.compute.internal","pid":1209,"mrl":"dirty","":"mend","":"downstairs","":"downstairs","session_id":"fa4dd422-1eec-409e-986b-0fd99f28724e"}
4232024-01-10T17:59:29.383Z{"msg":"extent:2 flush: 1856 1856 1856 scs: [ClientId(0), ClientId(1), ClientId(2)]","v":0,"name":"crucible","level":30,"time":"2024-01-10T17:59:29.290786596Z","hostname":"ip-10-150-1-187.us-west-2.compute.internal","pid":1209,"mrl":"dirty","":"mend","":"downstairs","":"downstairs","session_id":"fa4dd422-1eec-409e-986b-0fd99f28724e"}
4242024-01-10T17:59:29.385Z{"msg":"max_flush now has: [ClientId(0), ClientId(1), ClientId(2)]","v":0,"name":"crucible","level":30,"time":"2024-01-10T17:59:29.290816988Z","hostname":"ip-10-150-1-187.us-west-2.compute.internal","pid":1209,"mrl":"dirty","":"mend","":"downstairs","":"downstairs","session_id":"fa4dd422-1eec-409e-986b-0fd99f28724e"}
4252024-01-10T17:59:29.385Z{"msg":"extent:2 dirty: true true false","v":0,"name":"crucible","level":30,"time":"2024-01-10T17:59:29.290877304Z","hostname":"ip-10-150-1-187.us-west-2.compute.internal","pid":1209,"mrl":"dirty","":"mend","":"downstairs","":"downstairs","session_id":"fa4dd422-1eec-409e-986b-0fd99f28724e"}
4262024-01-10T17:59:29.385Z{"msg":"find dest for source 0 for extent at index 2","v":0,"name":"crucible","level":30,"time":"2024-01-10T17:59:29.290906436Z","hostname":"ip-10-150-1-187.us-west-2.compute.internal","pid":1209,"mrl":"dirty","":"mend","":"downstairs","":"downstairs","session_id":"fa4dd422-1eec-409e-986b-0fd99f28724e"}
4272024-01-10T17:59:29.386Z{"msg":"source 0, add dest 1 source flush","v":0,"name":"crucible","level":30,"time":"2024-01-10T17:59:29.290949645Z","hostname":"ip-10-150-1-187.us-west-2.compute.internal","pid":1209,"mrl":"dirty","":"mend","":"downstairs","":"downstairs","session_id":"fa4dd422-1eec-409e-986b-0fd99f28724e"}
4282024-01-10T17:59:29.386Z{"msg":"source 0, add dest 2 source flush","v":0,"name":"crucible","level":30,"time":"2024-01-10T17:59:29.290974916Z","hostname":"ip-10-150-1-187.us-west-2.compute.internal","pid":1209,"mrl":"dirty","":"mend","":"downstairs","":"downstairs","session_id":"fa4dd422-1eec-409e-986b-0fd99f28724e"}
4292024-01-10T17:59:29.388Z{"msg":"Extents 3 dirty","v":0,"name":"crucible","level":30,"time":"2024-01-10T17:59:29.291017244Z","hostname":"ip-10-150-1-187.us-west-2.compute.internal","pid":1209,"":"mend","":"downstairs","":"downstairs","session_id":"fa4dd422-1eec-409e-986b-0fd99f28724e"}
4302024-01-10T17:59:29.388Z{"msg":"First source client ID for extent 3","v":0,"name":"crucible","level":30,"time":"2024-01-10T17:59:29.291041935Z","hostname":"ip-10-150-1-187.us-west-2.compute.internal","pid":1209,"mrl":"dirty","":"mend","":"downstairs","":"downstairs","session_id":"fa4dd422-1eec-409e-986b-0fd99f28724e"}
4312024-01-10T17:59:29.388Z{"msg":"extent:3 gens: 32 32 31","v":0,"name":"crucible","level":30,"time":"2024-01-10T17:59:29.291083517Z","hostname":"ip-10-150-1-187.us-west-2.compute.internal","pid":1209,"mrl":"dirty","":"mend","":"downstairs","":"downstairs","session_id":"fa4dd422-1eec-409e-986b-0fd99f28724e"}
4322024-01-10T17:59:29.389Z{"msg":"extent:3 flush: 1857 1857 1856 scs: [ClientId(0), ClientId(1)]","v":0,"name":"crucible","level":30,"time":"2024-01-10T17:59:29.291109401Z","hostname":"ip-10-150-1-187.us-west-2.compute.internal","pid":1209,"mrl":"dirty","":"mend","":"downstairs","":"downstairs","session_id":"fa4dd422-1eec-409e-986b-0fd99f28724e"}
4332024-01-10T17:59:29.407Z{"msg":"max_flush now has: [ClientId(0), ClientId(1)]","v":0,"name":"crucible","level":30,"time":"2024-01-10T17:59:29.291151954Z","hostname":"ip-10-150-1-187.us-west-2.compute.internal","pid":1209,"mrl":"dirty","":"mend","":"downstairs","":"downstairs","session_id":"fa4dd422-1eec-409e-986b-0fd99f28724e"}
4342024-01-10T17:59:29.407Z{"msg":"extent:3 dirty: true true false","v":0,"name":"crucible","level":30,"time":"2024-01-10T17:59:29.291177019Z","hostname":"ip-10-150-1-187.us-west-2.compute.internal","pid":1209,"mrl":"dirty","":"mend","":"downstairs","":"downstairs","session_id":"fa4dd422-1eec-409e-986b-0fd99f28724e"}
4352024-01-10T17:59:29.407Z{"msg":"find dest for source 0 for extent at index 3","v":0,"name":"crucible","level":30,"time":"2024-01-10T17:59:29.291218743Z","hostname":"ip-10-150-1-187.us-west-2.compute.internal","pid":1209,"mrl":"dirty","":"mend","":"downstairs","":"downstairs","session_id":"fa4dd422-1eec-409e-986b-0fd99f28724e"}
4362024-01-10T17:59:29.407Z{"msg":"source 0, add dest 1 source flush","v":0,"name":"crucible","level":30,"time":"2024-01-10T17:59:29.291243801Z","hostname":"ip-10-150-1-187.us-west-2.compute.internal","pid":1209,"mrl":"dirty","":"mend","":"downstairs","":"downstairs","session_id":"fa4dd422-1eec-409e-986b-0fd99f28724e"}
4372024-01-10T17:59:29.407Z{"msg":"source 0, add dest 2 gen","v":0,"name":"crucible","level":30,"time":"2024-01-10T17:59:29.291290833Z","hostname":"ip-10-150-1-187.us-west-2.compute.internal","pid":1209,"mrl":"dirty","":"mend","":"downstairs","":"downstairs","session_id":"fa4dd422-1eec-409e-986b-0fd99f28724e"}
4382024-01-10T17:59:29.426Z{"msg":"Extent 0 has flush number mismatch","v":0,"name":"crucible","level":30,"time":"2024-01-10T17:59:29.291316223Z","hostname":"ip-10-150-1-187.us-west-2.compute.internal","pid":1209,"":"mend","":"downstairs","":"downstairs","session_id":"fa4dd422-1eec-409e-986b-0fd99f28724e"}
4392024-01-10T17:59:29.426Z{"msg":"First source client ID for extent 0","v":0,"name":"crucible","level":30,"time":"2024-01-10T17:59:29.291357321Z","hostname":"ip-10-150-1-187.us-west-2.compute.internal","pid":1209,"mrl":"flush_mismatch","":"mend","":"downstairs","":"downstairs","session_id":"fa4dd422-1eec-409e-986b-0fd99f28724e"}
4402024-01-10T17:59:29.426Z{"msg":"extent:0 gens: 32 32 31","v":0,"name":"crucible","level":30,"time":"2024-01-10T17:59:29.291382428Z","hostname":"ip-10-150-1-187.us-west-2.compute.internal","pid":1209,"mrl":"flush_mismatch","":"mend","":"downstairs","":"downstairs","session_id":"fa4dd422-1eec-409e-986b-0fd99f28724e"}
4412024-01-10T17:59:29.426Z{"msg":"extent:0 flush: 1858 1858 1856 scs: [ClientId(0), ClientId(1)]","v":0,"name":"crucible","level":30,"time":"2024-01-10T17:59:29.291407119Z","hostname":"ip-10-150-1-187.us-west-2.compute.internal","pid":1209,"mrl":"flush_mismatch","":"mend","":"downstairs","":"downstairs","session_id":"fa4dd422-1eec-409e-986b-0fd99f28724e"}
4422024-01-10T17:59:29.426Z{"msg":"max_flush now has: [ClientId(0), ClientId(1)]","v":0,"name":"crucible","level":30,"time":"2024-01-10T17:59:29.291437786Z","hostname":"ip-10-150-1-187.us-west-2.compute.internal","pid":1209,"mrl":"flush_mismatch","":"mend","":"downstairs","":"downstairs","session_id":"fa4dd422-1eec-409e-986b-0fd99f28724e"}
4432024-01-10T17:59:29.426Z{"msg":"extent:0 dirty: false false false","v":0,"name":"crucible","level":30,"time":"2024-01-10T17:59:29.291497255Z","hostname":"ip-10-150-1-187.us-west-2.compute.internal","pid":1209,"mrl":"flush_mismatch","":"mend","":"downstairs","":"downstairs","session_id":"fa4dd422-1eec-409e-986b-0fd99f28724e"}
4442024-01-10T17:59:29.426Z{"msg":"No maxes found, left with: [ClientId(0), ClientId(1)]","v":0,"name":"crucible","level":30,"time":"2024-01-10T17:59:29.291523972Z","hostname":"ip-10-150-1-187.us-west-2.compute.internal","pid":1209,"mrl":"flush_mismatch","":"mend","":"downstairs","":"downstairs","session_id":"fa4dd422-1eec-409e-986b-0fd99f28724e"}
4452024-01-10T17:59:29.426Z{"msg":"find dest for source 0 for extent at index 0","v":0,"name":"crucible","level":30,"time":"2024-01-10T17:59:29.291594131Z","hostname":"ip-10-150-1-187.us-west-2.compute.internal","pid":1209,"mrl":"flush_mismatch","":"mend","":"downstairs","":"downstairs","session_id":"fa4dd422-1eec-409e-986b-0fd99f28724e"}
4462024-01-10T17:59:29.426Z{"msg":"source 0, add dest 2 gen","v":0,"name":"crucible","level":30,"time":"2024-01-10T17:59:29.291621576Z","hostname":"ip-10-150-1-187.us-west-2.compute.internal","pid":1209,"mrl":"flush_mismatch","":"mend","":"downstairs","":"downstairs","session_id":"fa4dd422-1eec-409e-986b-0fd99f28724e"}
4472024-01-10T17:59:29.426Z{"msg":"Extent 4 has flush number mismatch","v":0,"name":"crucible","level":30,"time":"2024-01-10T17:59:29.291670074Z","hostname":"ip-10-150-1-187.us-west-2.compute.internal","pid":1209,"":"mend","":"downstairs","":"downstairs","session_id":"fa4dd422-1eec-409e-986b-0fd99f28724e"}
4482024-01-10T17:59:29.439Z{"msg":"First source client ID for extent 4","v":0,"name":"crucible","level":30,"time":"2024-01-10T17:59:29.291694549Z","hostname":"ip-10-150-1-187.us-west-2.compute.internal","pid":1209,"mrl":"flush_mismatch","":"mend","":"downstairs","":"downstairs","session_id":"fa4dd422-1eec-409e-986b-0fd99f28724e"}
4492024-01-10T17:59:29.439Z{"msg":"extent:4 gens: 32 32 31","v":0,"name":"crucible","level":30,"time":"2024-01-10T17:59:29.291736789Z","hostname":"ip-10-150-1-187.us-west-2.compute.internal","pid":1209,"mrl":"flush_mismatch","":"mend","":"downstairs","":"downstairs","session_id":"fa4dd422-1eec-409e-986b-0fd99f28724e"}
4502024-01-10T17:59:29.440Z{"msg":"extent:4 flush: 1857 1857 1856 scs: [ClientId(0), ClientId(1)]","v":0,"name":"crucible","level":30,"time":"2024-01-10T17:59:29.291762757Z","hostname":"ip-10-150-1-187.us-west-2.compute.internal","pid":1209,"mrl":"flush_mismatch","":"mend","":"downstairs","":"downstairs","session_id":"fa4dd422-1eec-409e-986b-0fd99f28724e"}
4512024-01-10T17:59:29.440Z{"msg":"max_flush now has: [ClientId(0), ClientId(1)]","v":0,"name":"crucible","level":30,"time":"2024-01-10T17:59:29.291818778Z","hostname":"ip-10-150-1-187.us-west-2.compute.internal","pid":1209,"mrl":"flush_mismatch","":"mend","":"downstairs","":"downstairs","session_id":"fa4dd422-1eec-409e-986b-0fd99f28724e"}
4522024-01-10T17:59:29.440Z{"msg":"extent:4 dirty: false false false","v":0,"name":"crucible","level":30,"time":"2024-01-10T17:59:29.291844265Z","hostname":"ip-10-150-1-187.us-west-2.compute.internal","pid":1209,"mrl":"flush_mismatch","":"mend","":"downstairs","":"downstairs","session_id":"fa4dd422-1eec-409e-986b-0fd99f28724e"}
4532024-01-10T17:59:29.440Z{"msg":"No maxes found, left with: [ClientId(0), ClientId(1)]","v":0,"name":"crucible","level":30,"time":"2024-01-10T17:59:29.291870469Z","hostname":"ip-10-150-1-187.us-west-2.compute.internal","pid":1209,"mrl":"flush_mismatch","":"mend","":"downstairs","":"downstairs","session_id":"fa4dd422-1eec-409e-986b-0fd99f28724e"}
4542024-01-10T17:59:29.440Z{"msg":"find dest for source 0 for extent at index 4","v":0,"name":"crucible","level":30,"time":"2024-01-10T17:59:29.291945871Z","hostname":"ip-10-150-1-187.us-west-2.compute.internal","pid":1209,"mrl":"flush_mismatch","":"mend","":"downstairs","":"downstairs","session_id":"fa4dd422-1eec-409e-986b-0fd99f28724e"}
4552024-01-10T17:59:29.440Z{"msg":"source 0, add dest 2 gen","v":0,"name":"crucible","level":30,"time":"2024-01-10T17:59:29.291970753Z","hostname":"ip-10-150-1-187.us-west-2.compute.internal","pid":1209,"mrl":"flush_mismatch","":"mend","":"downstairs","":"downstairs","session_id":"fa4dd422-1eec-409e-986b-0fd99f28724e"}
4562024-01-10T17:59:29.440Z{"msg":"Transition from WaitQuorum to Repair","v":0,"name":"crucible","level":30,"time":"2024-01-10T17:59:29.291995692Z","hostname":"ip-10-150-1-187.us-west-2.compute.internal","pid":1209,"client":"0","":"downstairs","session_id":"fa4dd422-1eec-409e-986b-0fd99f28724e"}
4572024-01-10T17:59:29.441Z{"msg":"Transition from WaitQuorum to Repair","v":0,"name":"crucible","level":30,"time":"2024-01-10T17:59:29.292036431Z","hostname":"ip-10-150-1-187.us-west-2.compute.internal","pid":1209,"client":"1","":"downstairs","session_id":"fa4dd422-1eec-409e-986b-0fd99f28724e"}
4582024-01-10T17:59:29.441Z{"msg":"Transition from WaitQuorum to Repair","v":0,"name":"crucible","level":30,"time":"2024-01-10T17:59:29.292060096Z","hostname":"ip-10-150-1-187.us-west-2.compute.internal","pid":1209,"client":"2","":"downstairs","session_id":"fa4dd422-1eec-409e-986b-0fd99f28724e"}
4592024-01-10T17:59:29.441Z{"msg":"Found 5 extents that need repair","v":0,"name":"crucible","level":30,"time":"2024-01-10T17:59:29.292082172Z","hostname":"ip-10-150-1-187.us-west-2.compute.internal","pid":1209,"":"downstairs","":"downstairs","session_id":"fa4dd422-1eec-409e-986b-0fd99f28724e"}
4602024-01-10T17:59:29.441Z{"msg":"Full repair list: {2: ExtentFix { source: ClientId(0), dest: [ClientId(1), ClientId(2)] }, 1: ExtentFix { source: ClientId(0), dest: [ClientId(1), ClientId(2)] }, 3: ExtentFix { source: ClientId(0), dest: [ClientId(1), ClientId(2)] }, 0: ExtentFix { source: ClientId(0), dest: [ClientId(2)] }, 4: ExtentFix { source: ClientId(0), dest: [ClientId(2)] }}","v":0,"name":"crucible","level":30,"time":"2024-01-10T17:59:29.292132338Z","hostname":"ip-10-150-1-187.us-west-2.compute.internal","pid":1209,"":"downstairs","":"downstairs","session_id":"fa4dd422-1eec-409e-986b-0fd99f28724e"}
4612024-01-10T17:59:29.441Z{"msg":"Task list: [ReconcileIO { id: ReconciliationId(0), op: ExtentFlush { repair_id: ReconciliationId(0), extent_id: 2, client_id: ClientId(0), flush_number: 1859, gen_number: 33 }, state: ClientData([New, New, New]) }, ReconcileIO { id: ReconciliationId(1), op: ExtentClose { repair_id: ReconciliationId(1), extent_id: 2 }, state: ClientData([New, New, New]) }, ReconcileIO { id: ReconciliationId(2), op: ExtentRepair { repair_id: ReconciliationId(2), extent_id: 2, source_client_id: ClientId(0), source_repair_address: 0.0.0.0:12810, dest_clients: [ClientId(1), ClientId(2)] }, state: ClientData([New, New, New]) }, ReconcileIO { id: ReconciliationId(3), op: ExtentReopen { repair_id: ReconciliationId(3), extent_id: 2 }, state: ClientData([New, New, New]) }, ReconcileIO { id: ReconciliationId(4), op: ExtentFlush { repair_id: ReconciliationId(4), extent_id: 1, client_id: ClientId(0), flush_number: 1859, gen_number: 33 }, state: ClientData([New, New, New]) }, ReconcileIO { id: ReconciliationId(5), op: ExtentClose { repair_id: ReconciliationId(5), extent_id: 1 }, state: ClientData([New, New, New]) }, ReconcileIO { id: ReconciliationId(6), op: ExtentRepair { repair_id: ReconciliationId(6), extent_id: 1, source_client_id: ClientId(0), source_repair_address: 0.0.0.0:12810, dest_clients: [ClientId(1), ClientId(2)] }, state: ClientData([New, New, New]) }, ReconcileIO { id: ReconciliationId(7), op: ExtentReopen { repair_id: ReconciliationId(7), extent_id: 1 }, state: ClientData([New, New, New]) }, ReconcileIO { id: ReconciliationId(8), op: ExtentFlush { repair_id: ReconciliationId(8), extent_id: 3, client_id: ClientId(0), flush_number: 1859, gen_number: 33 }, state: ClientData([New, New, New]) }, ReconcileIO { id: ReconciliationId(9), op: ExtentClose { repair_id: ReconciliationId(9), extent_id: 3 }, state: ClientData([New, New, New]) }, ReconcileIO { id: ReconciliationId(10), op: ExtentRepair { repair_id: ReconciliationId(10), extent_id: 3, source_client_id: ClientId(0), source_repair_address: 0.0.0.0:12810, dest_clients: [ClientId(1), ClientId(2)] }, state: ClientData([New, New, New]) }, ReconcileIO { id: ReconciliationId(11), op: ExtentReopen { repair_id: ReconciliationId(11), extent_id: 3 }, state: ClientData([New, New, New]) }, ReconcileIO { id: ReconciliationId(12), op: ExtentFlush { repair_id: ReconciliationId(12), extent_id: 0, client_id: ClientId(0), flush_number: 1859, gen_number: 33 }, state: ClientData([New, New, New]) }, ReconcileIO { id: ReconciliationId(13), op: ExtentClose { repair_id: ReconciliationId(13), extent_id: 0 }, state: ClientData([New, New, New]) }, ReconcileIO { id: ReconciliationId(14), op: ExtentRepair { repair_id: ReconciliationId(14), extent_id: 0, source_client_id: ClientId(0), source_repair_address: 0.0.0.0:12810, dest_clients: [ClientId(2)] }, state: ClientData([New, New, New]) }, ReconcileIO { id: ReconciliationId(15), op: ExtentReopen { repair_id: ReconciliationId(15), extent_id: 0 }, state: ClientData([New, New, New]) }, ReconcileIO { id: ReconciliationId(16), op: ExtentFlush { repair_id: ReconciliationId(16), extent_id: 4, client_id: ClientId(0), flush_number: 1859, gen_number: 33 }, state: ClientData([New, New, New]) }, ReconcileIO { id: ReconciliationId(17), op: ExtentClose { repair_id: ReconciliationId(17), extent_id: 4 }, state: ClientData([New, New, New]) }, ReconcileIO { id: ReconciliationId(18), op: ExtentRepair { repair_id: ReconciliationId(18), extent_id: 4, source_client_id: ClientId(0), source_repair_address: 0.0.0.0:12810, dest_clients: [ClientId(2)] }, state: ClientData([New, New, New]) }, ReconcileIO { id: ReconciliationId(19), op: ExtentReopen { repair_id: ReconciliationId(19), extent_id: 4 }, state: ClientData([New, New, New]) }]","v":0,"name":"crucible","level":30,"time":"2024-01-10T17:59:29.292320338Z","hostname":"ip-10-150-1-187.us-west-2.compute.internal","pid":1209,"":"downstairs","":"downstairs","session_id":"fa4dd422-1eec-409e-986b-0fd99f28724e"}
4622024-01-10T17:59:29.441Z{"msg":"sending flush request ReconciliationId(0)","v":0,"name":"crucible","level":30,"time":"2024-01-10T17:59:29.292354442Z","hostname":"ip-10-150-1-187.us-west-2.compute.internal","pid":1209,"client":"0","":"downstairs","session_id":"fa4dd422-1eec-409e-986b-0fd99f28724e"}
4632024-01-10T17:59:29.441Z{"msg":"skipping flush request ReconciliationId(0)","v":0,"name":"crucible","level":30,"time":"2024-01-10T17:59:29.292377712Z","hostname":"ip-10-150-1-187.us-west-2.compute.internal","pid":1209,"client":"1","":"downstairs","session_id":"fa4dd422-1eec-409e-986b-0fd99f28724e"}
4642024-01-10T17:59:29.442Z{"msg":"skipping flush request ReconciliationId(0)","v":0,"name":"crucible","level":30,"time":"2024-01-10T17:59:29.292399786Z","hostname":"ip-10-150-1-187.us-west-2.compute.internal","pid":1209,"client":"2","":"downstairs","session_id":"fa4dd422-1eec-409e-986b-0fd99f28724e"}
4652024-01-10T17:59:29.442Z{"msg":"no action needed request ReconciliationId(2)","v":0,"name":"crucible","level":30,"time":"2024-01-10T17:59:29.292421771Z","hostname":"ip-10-150-1-187.us-west-2.compute.internal","pid":1209,"client":"0","":"downstairs","session_id":"fa4dd422-1eec-409e-986b-0fd99f28724e"}
4662024-01-10T17:59:29.442Z{"msg":"sending repair request ReconciliationId(2)","v":0,"name":"crucible","level":30,"time":"2024-01-10T17:59:29.292443472Z","hostname":"ip-10-150-1-187.us-west-2.compute.internal","pid":1209,"client":"1","":"downstairs","session_id":"fa4dd422-1eec-409e-986b-0fd99f28724e"}
4672024-01-10T17:59:29.442Z{"msg":"sending repair request ReconciliationId(2)","v":0,"name":"crucible","level":30,"time":"2024-01-10T17:59:29.292507098Z","hostname":"ip-10-150-1-187.us-west-2.compute.internal","pid":1209,"client":"2","":"downstairs","session_id":"fa4dd422-1eec-409e-986b-0fd99f28724e"}
4682024-01-10T17:59:29.442Z{"msg":"sending flush request ReconciliationId(4)","v":0,"name":"crucible","level":30,"time":"2024-01-10T17:59:29.404498325Z","hostname":"ip-10-150-1-187.us-west-2.compute.internal","pid":1209,"client":"0","":"downstairs","session_id":"fa4dd422-1eec-409e-986b-0fd99f28724e"}
4692024-01-10T17:59:29.442Z{"msg":"skipping flush request ReconciliationId(4)","v":0,"name":"crucible","level":30,"time":"2024-01-10T17:59:29.40460465Z","hostname":"ip-10-150-1-187.us-west-2.compute.internal","pid":1209,"client":"1","":"downstairs","session_id":"fa4dd422-1eec-409e-986b-0fd99f28724e"}
4702024-01-10T17:59:29.442Z{"msg":"skipping flush request ReconciliationId(4)","v":0,"name":"crucible","level":30,"time":"2024-01-10T17:59:29.404697391Z","hostname":"ip-10-150-1-187.us-west-2.compute.internal","pid":1209,"client":"2","":"downstairs","session_id":"fa4dd422-1eec-409e-986b-0fd99f28724e"}
4712024-01-10T17:59:29.442Z{"msg":"no action needed request ReconciliationId(6)","v":0,"name":"crucible","level":30,"time":"2024-01-10T17:59:29.406460399Z","hostname":"ip-10-150-1-187.us-west-2.compute.internal","pid":1209,"client":"0","":"downstairs","session_id":"fa4dd422-1eec-409e-986b-0fd99f28724e"}
4722024-01-10T17:59:29.442Z{"msg":"sending repair request ReconciliationId(6)","v":0,"name":"crucible","level":30,"time":"2024-01-10T17:59:29.406548936Z","hostname":"ip-10-150-1-187.us-west-2.compute.internal","pid":1209,"client":"1","":"downstairs","session_id":"fa4dd422-1eec-409e-986b-0fd99f28724e"}
4732024-01-10T17:59:29.442Z{"msg":"sending repair request ReconciliationId(6)","v":0,"name":"crucible","level":30,"time":"2024-01-10T17:59:29.406622528Z","hostname":"ip-10-150-1-187.us-west-2.compute.internal","pid":1209,"client":"2","":"downstairs","session_id":"fa4dd422-1eec-409e-986b-0fd99f28724e"}
4742024-01-10T17:59:29.480Z{"msg":"sending flush request ReconciliationId(8)","v":0,"name":"crucible","level":30,"time":"2024-01-10T17:59:29.483541925Z","hostname":"ip-10-150-1-187.us-west-2.compute.internal","pid":1209,"client":"0","":"downstairs","session_id":"fa4dd422-1eec-409e-986b-0fd99f28724e"}
4752024-01-10T17:59:29.480Z{"msg":"skipping flush request ReconciliationId(8)","v":0,"name":"crucible","level":30,"time":"2024-01-10T17:59:29.483642055Z","hostname":"ip-10-150-1-187.us-west-2.compute.internal","pid":1209,"client":"1","":"downstairs","session_id":"fa4dd422-1eec-409e-986b-0fd99f28724e"}
4762024-01-10T17:59:29.483Z{"msg":"skipping flush request ReconciliationId(8)","v":0,"name":"crucible","level":30,"time":"2024-01-10T17:59:29.483730772Z","hostname":"ip-10-150-1-187.us-west-2.compute.internal","pid":1209,"client":"2","":"downstairs","session_id":"fa4dd422-1eec-409e-986b-0fd99f28724e"}
4772024-01-10T17:59:29.483Z{"msg":"no action needed request ReconciliationId(10)","v":0,"name":"crucible","level":30,"time":"2024-01-10T17:59:29.485637797Z","hostname":"ip-10-150-1-187.us-west-2.compute.internal","pid":1209,"client":"0","":"downstairs","session_id":"fa4dd422-1eec-409e-986b-0fd99f28724e"}
4782024-01-10T17:59:29.496Z{"msg":"sending repair request ReconciliationId(10)","v":0,"name":"crucible","level":30,"time":"2024-01-10T17:59:29.485704984Z","hostname":"ip-10-150-1-187.us-west-2.compute.internal","pid":1209,"client":"1","":"downstairs","session_id":"fa4dd422-1eec-409e-986b-0fd99f28724e"}
4792024-01-10T17:59:29.496Z{"msg":"sending repair request ReconciliationId(10)","v":0,"name":"crucible","level":30,"time":"2024-01-10T17:59:29.485732357Z","hostname":"ip-10-150-1-187.us-west-2.compute.internal","pid":1209,"client":"2","":"downstairs","session_id":"fa4dd422-1eec-409e-986b-0fd99f28724e"}
4802024-01-10T17:59:29.557Z{"msg":"sending flush request ReconciliationId(12)","v":0,"name":"crucible","level":30,"time":"2024-01-10T17:59:29.561351489Z","hostname":"ip-10-150-1-187.us-west-2.compute.internal","pid":1209,"client":"0","":"downstairs","session_id":"fa4dd422-1eec-409e-986b-0fd99f28724e"}
4812024-01-10T17:59:29.558Z{"msg":"skipping flush request ReconciliationId(12)","v":0,"name":"crucible","level":30,"time":"2024-01-10T17:59:29.561462589Z","hostname":"ip-10-150-1-187.us-west-2.compute.internal","pid":1209,"client":"1","":"downstairs","session_id":"fa4dd422-1eec-409e-986b-0fd99f28724e"}
4822024-01-10T17:59:29.558Z{"msg":"skipping flush request ReconciliationId(12)","v":0,"name":"crucible","level":30,"time":"2024-01-10T17:59:29.561492028Z","hostname":"ip-10-150-1-187.us-west-2.compute.internal","pid":1209,"client":"2","":"downstairs","session_id":"fa4dd422-1eec-409e-986b-0fd99f28724e"}
4832024-01-10T17:59:29.561Z{"msg":"no action needed request ReconciliationId(14)","v":0,"name":"crucible","level":30,"time":"2024-01-10T17:59:29.562345924Z","hostname":"ip-10-150-1-187.us-west-2.compute.internal","pid":1209,"client":"0","":"downstairs","session_id":"fa4dd422-1eec-409e-986b-0fd99f28724e"}
4842024-01-10T17:59:29.561Z{"msg":"no action needed request ReconciliationId(14)","v":0,"name":"crucible","level":30,"time":"2024-01-10T17:59:29.562407828Z","hostname":"ip-10-150-1-187.us-west-2.compute.internal","pid":1209,"client":"1","":"downstairs","session_id":"fa4dd422-1eec-409e-986b-0fd99f28724e"}
4852024-01-10T17:59:29.561Z{"msg":"sending repair request ReconciliationId(14)","v":0,"name":"crucible","level":30,"time":"2024-01-10T17:59:29.562434131Z","hostname":"ip-10-150-1-187.us-west-2.compute.internal","pid":1209,"client":"2","":"downstairs","session_id":"fa4dd422-1eec-409e-986b-0fd99f28724e"}
4862024-01-10T17:59:29.633Z{"msg":"sending flush request ReconciliationId(16)","v":0,"name":"crucible","level":30,"time":"2024-01-10T17:59:29.637280123Z","hostname":"ip-10-150-1-187.us-west-2.compute.internal","pid":1209,"client":"0","":"downstairs","session_id":"fa4dd422-1eec-409e-986b-0fd99f28724e"}
4872024-01-10T17:59:29.633Z{"msg":"skipping flush request ReconciliationId(16)","v":0,"name":"crucible","level":30,"time":"2024-01-10T17:59:29.6373503Z","hostname":"ip-10-150-1-187.us-west-2.compute.internal","pid":1209,"client":"1","":"downstairs","session_id":"fa4dd422-1eec-409e-986b-0fd99f28724e"}
4882024-01-10T17:59:29.633Z{"msg":"skipping flush request ReconciliationId(16)","v":0,"name":"crucible","level":30,"time":"2024-01-10T17:59:29.637377021Z","hostname":"ip-10-150-1-187.us-west-2.compute.internal","pid":1209,"client":"2","":"downstairs","session_id":"fa4dd422-1eec-409e-986b-0fd99f28724e"}
4892024-01-10T17:59:29.637Z{"msg":"no action needed request ReconciliationId(18)","v":0,"name":"crucible","level":30,"time":"2024-01-10T17:59:29.638157064Z","hostname":"ip-10-150-1-187.us-west-2.compute.internal","pid":1209,"client":"0","":"downstairs","session_id":"fa4dd422-1eec-409e-986b-0fd99f28724e"}
4902024-01-10T17:59:29.637Z{"msg":"no action needed request ReconciliationId(18)","v":0,"name":"crucible","level":30,"time":"2024-01-10T17:59:29.638218222Z","hostname":"ip-10-150-1-187.us-west-2.compute.internal","pid":1209,"client":"1","":"downstairs","session_id":"fa4dd422-1eec-409e-986b-0fd99f28724e"}
4912024-01-10T17:59:29.637Z{"msg":"sending repair request ReconciliationId(18)","v":0,"name":"crucible","level":30,"time":"2024-01-10T17:59:29.638244229Z","hostname":"ip-10-150-1-187.us-west-2.compute.internal","pid":1209,"client":"2","":"downstairs","session_id":"fa4dd422-1eec-409e-986b-0fd99f28724e"}
4922024-01-10T17:59:29.706Z{"msg":"done with reconciliation","v":0,"name":"crucible","level":30,"time":"2024-01-10T17:59:29.710436351Z","hostname":"ip-10-150-1-187.us-west-2.compute.internal","pid":1209,"":"downstairs","":"downstairs","session_id":"fa4dd422-1eec-409e-986b-0fd99f28724e"}
4932024-01-10T17:59:29.706ZWait for a query_work_queue command to finish before sending IO
4942024-01-10T17:59:29.706Z{"msg":"Transition from Repair to Active","v":0,"name":"crucible","level":30,"time":"2024-01-10T17:59:29.710503883Z","hostname":"ip-10-150-1-187.us-west-2.compute.internal","pid":1209,"client":"0","":"downstairs","session_id":"fa4dd422-1eec-409e-986b-0fd99f28724e"}
4952024-01-10T17:59:29.706Z{"msg":"Transition from Repair to Active","v":0,"name":"crucible","level":30,"time":"2024-01-10T17:59:29.710530864Z","hostname":"ip-10-150-1-187.us-west-2.compute.internal","pid":1209,"client":"1","":"downstairs","session_id":"fa4dd422-1eec-409e-986b-0fd99f28724e"}
4962024-01-10T17:59:29.709Z{"msg":"Transition from Repair to Active","v":0,"name":"crucible","level":30,"time":"2024-01-10T17:59:29.710572763Z","hostname":"ip-10-150-1-187.us-west-2.compute.internal","pid":1209,"client":"2","":"downstairs","session_id":"fa4dd422-1eec-409e-986b-0fd99f28724e"}
4972024-01-10T17:59:29.709Z{"msg":"All required repair work is completed","v":0,"name":"crucible","level":30,"time":"2024-01-10T17:59:29.710615598Z","hostname":"ip-10-150-1-187.us-west-2.compute.internal","pid":1209,"session_id":"fa4dd422-1eec-409e-986b-0fd99f28724e"}
4982024-01-10T17:59:29.713Z{"msg":"Set Downstairs and Upstairs active after repairs","v":0,"name":"crucible","level":30,"time":"2024-01-10T17:59:29.7106377Z","hostname":"ip-10-150-1-187.us-west-2.compute.internal","pid":1209,"session_id":"fa4dd422-1eec-409e-986b-0fd99f28724e"}
4992024-01-10T17:59:29.713Z{"msg":"111cec26-fccc-409d-b696-61f0d5a6326e is now active with session: fa4dd422-1eec-409e-986b-0fd99f28724e","v":0,"name":"crucible","level":30,"time":"2024-01-10T17:59:29.71066434Z","hostname":"ip-10-150-1-187.us-west-2.compute.internal","pid":1209,"session_id":"fa4dd422-1eec-409e-986b-0fd99f28724e"}
5002024-01-10T17:59:29.713Z{"msg":"The guest has finished waiting for activation with:33","v":0,"name":"crucible","level":30,"time":"2024-01-10T17:59:29.710729566Z","hostname":"ip-10-150-1-187.us-west-2.compute.internal","pid":1209}
5012024-01-10T17:59:29.713ZRegion: es:10 ec:5 bs:4096 ts:204800 tb:50 max_io:50 or 204800
5022024-01-10T17:59:29.713ZLoading write count information from file "/var/tmp/test_up/verify_file"
5032024-01-10T17:59:29.714ZRead and Verify all blocks (0..50 range:true)
5042024-01-10T17:59:29.779ZWrote out file "/var/tmp/test_up/verify_file"
5052024-01-10T17:59:29.779ZVerify test completed
5062024-01-10T17:59:29.782ZWrote out file "/var/tmp/test_up/verify_file"
5072024-01-10T17:59:29.782ZCLIENT: Tests done. All submitted work has been ACK'd
5082024-01-10T17:59:29.879Z----------------------------------------------------------------
5092024-01-10T17:59:29.879Z Crucible gen:33 GIO:true work queues: Upstairs:1 downstairs:2
5102024-01-10T17:59:29.879ZStates: Active Active Active
5112024-01-10T17:59:29.879ZGW_ID ACK DSID TYPE BLOCKS DS:0 DS:1 DS:2 REPLAY
5122024-01-10T17:59:29.879Z 1 Acked 1000 Read 50 Done Done Done false
5132024-01-10T17:59:29.879Z 2 NotAcked 1001 Flush 0 Sent Sent Sent false
5142024-01-10T17:59:29.879Z STATES DS:0 DS:1 DS:2 TOTAL
5152024-01-10T17:59:29.879Z New 0 0 0 0
5162024-01-10T17:59:29.879Z Sent 1 1 1 3
5172024-01-10T17:59:29.879Z Done 1 1 1 3
5182024-01-10T17:59:29.881Z Skipped 0 0 0 0
5192024-01-10T17:59:29.881Z Error 0 0 0 0
5202024-01-10T17:59:29.881ZLast Flush: 0 0 0
5212024-01-10T17:59:29.881ZDownstairs last five completed:
5222024-01-10T17:59:29.881ZUpstairs last five completed: 1
5232024-01-10T17:59:29.885ZCLIENT: Up:1 ds:2 act:3
5242024-01-10T17:59:33.881Z----------------------------------------------------------------
5252024-01-10T17:59:33.881Z Crucible gen:33 GIO:true work queues: Upstairs:0 downstairs:0
5262024-01-10T17:59:33.881ZDownstairs last five completed: 1001 1000
5272024-01-10T17:59:33.881ZUpstairs last five completed: 2 1
5282024-01-10T17:59:33.882ZCLIENT: Up:0 ds:0 act:3
5292024-01-10T17:59:33.882ZCLIENT: All crucible jobs finished, exiting program
5302024-01-10T17:59:33.888ZRepair part 2 passed
5312024-01-10T17:59:33.891Z/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
5322024-01-10T17:59:33.906ZEXT BLOCKS GEN0 GEN1 GEN2 FL0 FL1 FL2 D0 D1 D2 DIFF
5332024-01-10T17:59:33.906Z 0 000-009 32 32 32 1858 1858 1858 F F F
5342024-01-10T17:59:33.906Z 1 010-019 33 33 33 1859 1859 1859 F F F
5352024-01-10T17:59:33.906Z 2 020-029 33 33 33 1859 1859 1859 F F F
5362024-01-10T17:59:33.906Z 3 030-039 33 33 33 1859 1859 1859 F F F
5372024-01-10T17:59:33.910Z 4 040-049 32 32 32 1857 1857 1857 F F F
5382024-01-10T17:59:33.910ZMax gen: 33, Max flush: 1859
5392024-01-10T17:59:33.914Zdump test passed
5402024-01-10T17:59:33.914Z/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
5412024-01-10T17:59:33.927Z Extent 1
5422024-01-10T17:59:33.927ZGEN 33 33 33
5432024-01-10T17:59:33.927ZFLUSH_ID 1859 1859 1859
5442024-01-10T17:59:33.927ZDIRTY
5452024-01-10T17:59:33.927Z
5462024-01-10T17:59:33.931ZBLOCK D0 D1 D2 C0 C1 C2 DIFF
5472024-01-10T17:59:33.931Z010 A A A A A A
5482024-01-10T17:59:33.931Z011 A A A A A A
5492024-01-10T17:59:33.931Z012 A A A A A A
5502024-01-10T17:59:33.931Z013 A A A A A A
5512024-01-10T17:59:33.934Z014 A A A A A A
5522024-01-10T17:59:33.934Z015 A A A A A A
5532024-01-10T17:59:33.934Z016 A A A A A A
5542024-01-10T17:59:33.934Z017 A A A A A A
5552024-01-10T17:59:33.937Z018 A A A A A A
5562024-01-10T17:59:33.937Z019 A A A A A A
5572024-01-10T17:59:33.941Zdump extent test passed
5582024-01-10T17:59:33.941Z/var/tmp/bins/crucible-downstairs dump --no-color -d /var/tmp/test_up/8810 -d /var/tmp/test_up/8820 -d /var/tmp/test_up/8830 -b 20
5592024-01-10T17:59:33.957ZExtent 2 Block in extent 0 Actual block 20
5602024-01-10T17:59:33.957Z
5612024-01-10T17:59:33.964Z DATA SHA256 VER
5622024-01-10T17:59:33.964Z------ ---------------------------------------------------------------- ---
5632024-01-10T17:59:33.964Z 0 0d89a6a1ed5c64ad9357b0b4d0c23094d5e30dab05dabcf088c953763e60733a A
5642024-01-10T17:59:33.964Z 1 0d89a6a1ed5c64ad9357b0b4d0c23094d5e30dab05dabcf088c953763e60733a A
5652024-01-10T17:59:33.964Z 2 0d89a6a1ed5c64ad9357b0b4d0c23094d5e30dab05dabcf088c953763e60733a A
5662024-01-10T17:59:33.964Z
5672024-01-10T17:59:33.964ZNONCES 0 1 2 DIFF
5682024-01-10T17:59:33.964Z------ ------------------------ ------------------------ ------------------------ -----
5692024-01-10T17:59:33.964Z 0 790ee30140f05f1059c08734 790ee30140f05f1059c08734 790ee30140f05f1059c08734
5702024-01-10T17:59:33.964Z
5712024-01-10T17:59:33.964Z TAGS 0 1 2 DIFF
5722024-01-10T17:59:33.964Z------ -------------------------------- -------------------------------- -------------------------------- -----
5732024-01-10T17:59:33.964Z 0 a89c4b3236e933ace14f5b0a44d70021 a89c4b3236e933ace14f5b0a44d70021 a89c4b3236e933ace14f5b0a44d70021
5742024-01-10T17:59:33.964Z
5752024-01-10T17:59:33.965ZHASHES 0 1 2 DIFF
5762024-01-10T17:59:33.965Z------ ---------------- ---------------- ---------------- -----
5772024-01-10T17:59:33.965Z 0 d19c7bdfaf84253c d19c7bdfaf84253c d19c7bdfaf84253c
5782024-01-10T17:59:33.965Z
5792024-01-10T17:59:33.970Zdump block test passed
5802024-01-10T17:59:33.970ZUpstairs tests have completed, stopping all downstairs
5812024-01-10T17:59:34.066Z
5822024-01-10T17:59:34.066ZAll Tests have passed
5832024-01-10T17:59:34.069Z4:24 Test duration
5842024-01-10T17:59:34.069Z
5852024-01-10T17:59:34.069Zreal 4:22.441672070
5862024-01-10T17:59:34.069Zuser 4:01.269560433
5872024-01-10T17:59:34.070Zsys 13.921245215
5882024-01-10T17:59:34.070Ztrap 0.223621260
5892024-01-10T17:59:34.070Ztflt 0.113754310
5902024-01-10T17:59:34.070Zdflt 0.066284313
5912024-01-10T17:59:34.070Zkflt 0.000996347
5922024-01-10T17:59:34.072Zlock 1:05:19.814208216
5932024-01-10T17:59:34.072Zslp 8:14.279396707
5942024-01-10T17:59:34.072Zlat 18.406844745
5952024-01-10T17:59:34.072Zstop 0.027922706
5962024-01-10T17:59:34.072Zprocess exited: duration 274945 ms, exit code 0
 
5972024-01-10T17:59:34.092Zfound 5 output files
5982024-01-10T17:59:34.092Zuploading: /tmp/test_up/dsc-out.txt (4484 bytes)
5992024-01-10T17:59:35.111Zuploaded: /tmp/test_up/dsc-out.txt
6002024-01-10T17:59:35.111Zuploading: /tmp/test_up/test_up_out.txt (4528320 bytes)
6012024-01-10T17:59:37.058Zuploaded: /tmp/test_up/test_up_out.txt
6022024-01-10T17:59:37.058Zuploading: /tmp/test_up/dsc/downstairs-8810.txt (56347 bytes)
6032024-01-10T17:59:38.073Zuploaded: /tmp/test_up/dsc/downstairs-8810.txt
6042024-01-10T17:59:38.073Zuploading: /tmp/test_up/dsc/downstairs-8820.txt (51939 bytes)
6052024-01-10T17:59:39.087Zuploaded: /tmp/test_up/dsc/downstairs-8820.txt
6062024-01-10T17:59:39.088Zuploading: /tmp/test_up/dsc/downstairs-8830.txt (10942 bytes)
6072024-01-10T17:59:40.099Zuploaded: /tmp/test_up/dsc/downstairs-8830.txt