01J2EK6TAWY5MMM0P231XPS3J4: 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: 01J2EK7515P3J3K6A4N5VTQYDY

Tags:

Artefacts:

Output:

SEQ GLOBAL TIME DETAILS
12024-07-10T15:25:09.876Zjob dependencies complete; ready to run (waiting for 13 m 8 s)
22024-07-10T15:26:15.229Zjob assigned to worker 01J2EKZEVPA6452PKBGH6J05BH (queued for 1 m 5 s)
32024-07-10T15:26:22.562Zdownloading input: /input/build/work/bins/crucible-downstairs.gz
42024-07-10T15:26:23.824Zdownloaded input: /input/build/work/bins/crucible-downstairs.gz
52024-07-10T15:26:23.824Zdownloading input: /input/build/work/bins/crucible-hammer.gz
62024-07-10T15:26:24.880Zdownloaded input: /input/build/work/bins/crucible-hammer.gz
72024-07-10T15:26:24.880Zdownloading input: /input/build/work/bins/crutest.gz
82024-07-10T15:26:25.899Zdownloaded input: /input/build/work/bins/crutest.gz
92024-07-10T15:26:25.899Zdownloading input: /input/build/work/bins/dsc.gz
102024-07-10T15:26:26.548Zdownloaded input: /input/build/work/bins/dsc.gz
112024-07-10T15:26:26.552Zdownloading input: /input/build/work/scripts/perf-downstairs-tick.d
122024-07-10T15:26:26.566Zdownloaded input: /input/build/work/scripts/perf-downstairs-tick.d
132024-07-10T15:26:26.566Zdownloading input: /input/build/work/scripts/test_ds.sh
142024-07-10T15:26:26.587Zdownloaded input: /input/build/work/scripts/test_ds.sh
152024-07-10T15:26:26.587Zdownloading input: /input/build/work/scripts/test_live_repair.sh
162024-07-10T15:26:26.606Zdownloaded input: /input/build/work/scripts/test_live_repair.sh
172024-07-10T15:26:26.607Zdownloading input: /input/build/work/scripts/test_repair.sh
182024-07-10T15:26:26.629Zdownloaded input: /input/build/work/scripts/test_repair.sh
192024-07-10T15:26:26.629Zdownloading input: /input/build/work/scripts/test_replay.sh
202024-07-10T15:26:26.649Zdownloaded input: /input/build/work/scripts/test_replay.sh
212024-07-10T15:26:26.649Zdownloading input: /input/build/work/scripts/test_up.sh
222024-07-10T15:26:26.667Zdownloaded input: /input/build/work/scripts/test_up.sh
232024-07-10T15:26:26.667Zdownloading input: /input/build/work/scripts/upstairs_info.d
242024-07-10T15:26:26.686Zdownloaded input: /input/build/work/scripts/upstairs_info.d
252024-07-10T15:26:26.689Zdownloading input: /input/build/tmp/cargo-test-out.log
262024-07-10T15:26:27.519Zdownloaded input: /input/build/tmp/cargo-test-out.log
 
272024-07-10T15:26:27.519Zstarting task 0: "setup"
282024-07-10T15:26:27.522Z++ uname -s
292024-07-10T15:26:27.526Z+ kern=SunOS
302024-07-10T15:26:27.526Z+ case "$kern" in
312024-07-10T15:26:27.526Z+ groupadd -g 12345 build
322024-07-10T15:26:27.526Z+ useradd -u 12345 -g build -d /home/build -s /bin/bash -c build -P 'Primary Administrator' build
332024-07-10T15:26:29.537Z+ zfs create -o mountpoint=/work rpool/work
342024-07-10T15:26:29.679Z++ awk '$2 == "/home" { print $3 }' /etc/mnttab
352024-07-10T15:26:29.682Z+ home_fs=zfs
362024-07-10T15:26:29.682Z+ [[ zfs == autofs ]]
372024-07-10T15:26:29.682Z+ mkdir -p /home/build
382024-07-10T15:26:29.685Z+ chown build:build /home/build /work
392024-07-10T15:26:30.687Z+ chmod 0700 /home/build /work
402024-07-10T15:26:30.692Zprocess exited: duration 3177 ms, exit code 0
 
412024-07-10T15:26:30.703Zstarting task 1: "authentication"
422024-07-10T15:26:30.718Zprocess exited: duration 16 ms, exit code 0
 
432024-07-10T15:26:30.728Zstarting task 2: "build"
442024-07-10T15:26:30.732Z+ banner cores
452024-07-10T15:26:30.735Z
462024-07-10T15:26:30.736Z #### #### ##### ###### ####
472024-07-10T15:26:30.736Z # # # # # # # #
482024-07-10T15:26:30.736Z # # # # # ##### ####
492024-07-10T15:26:30.736Z # # # ##### # #
502024-07-10T15:26:30.736Z # # # # # # # # #
512024-07-10T15:26:30.736Z #### #### # # ###### ####
522024-07-10T15:26:30.736Z
532024-07-10T15:26:30.736Z+ pfexec coreadm -i /tmp/core.%f.%p -g /tmp/core.%f.%p -e global -e log -e proc-setid -e global-setid
542024-07-10T15:26:30.745Z+ echo 'input bins dir contains:'
552024-07-10T15:26:30.745Zinput bins dir contains:
562024-07-10T15:26:30.748Z+ ls -ltr /input/build/work/bins
572024-07-10T15:26:30.748Ztotal 687211
582024-07-10T15:26:30.748Z-rw-r--r-- 1 root root 104011619 Jul 10 15:26 crucible-downstairs.gz
592024-07-10T15:26:30.748Z-rw-r--r-- 1 root root 81939727 Jul 10 15:26 crucible-hammer.gz
602024-07-10T15:26:30.748Z-rw-r--r-- 1 root root 101309809 Jul 10 15:26 crutest.gz
612024-07-10T15:26:30.748Z-rw-r--r-- 1 root root 64339917 Jul 10 15:26 dsc.gz
622024-07-10T15:26:30.749Z+ banner unpack
632024-07-10T15:26:30.749Z
642024-07-10T15:26:30.749Z # # # # ##### ## #### # #
652024-07-10T15:26:30.749Z # # ## # # # # # # # # #
662024-07-10T15:26:30.749Z # # # # # # # # # # ####
672024-07-10T15:26:30.749Z # # # # # ##### ###### # # #
682024-07-10T15:26:30.749Z # # # ## # # # # # # #
692024-07-10T15:26:30.749Z #### # # # # # #### # #
702024-07-10T15:26:30.749Z
712024-07-10T15:26:30.749Z+ mkdir -p /var/tmp/bins
722024-07-10T15:26:30.753Z+ for t in "$input/bins/"*.gz
732024-07-10T15:26:30.753Z++ basename /input/build/work/bins/crucible-downstairs.gz
742024-07-10T15:26:30.753Z+ b=crucible-downstairs.gz
752024-07-10T15:26:30.753Z+ b=crucible-downstairs
762024-07-10T15:26:30.753Z+ gunzip
772024-07-10T15:26:32.926Z+ chmod +x /var/tmp/bins/crucible-downstairs
782024-07-10T15:26:32.929Z+ for t in "$input/bins/"*.gz
792024-07-10T15:26:32.936Z++ basename /input/build/work/bins/crucible-hammer.gz
802024-07-10T15:26:32.936Z+ b=crucible-hammer.gz
812024-07-10T15:26:32.936Z+ b=crucible-hammer
822024-07-10T15:26:32.936Z+ gunzip
832024-07-10T15:26:34.682Z+ chmod +x /var/tmp/bins/crucible-hammer
842024-07-10T15:26:34.685Z+ for t in "$input/bins/"*.gz
852024-07-10T15:26:34.687Z++ basename /input/build/work/bins/crutest.gz
862024-07-10T15:26:34.690Z+ b=crutest.gz
872024-07-10T15:26:34.690Z+ b=crutest
882024-07-10T15:26:34.690Z+ gunzip
892024-07-10T15:26:36.765Z+ chmod +x /var/tmp/bins/crutest
902024-07-10T15:26:36.768Z+ for t in "$input/bins/"*.gz
912024-07-10T15:26:36.770Z++ basename /input/build/work/bins/dsc.gz
922024-07-10T15:26:36.770Z+ b=dsc.gz
932024-07-10T15:26:36.770Z+ b=dsc
942024-07-10T15:26:36.770Z+ gunzip
952024-07-10T15:26:38.123Z+ chmod +x /var/tmp/bins/dsc
962024-07-10T15:26:38.127Z+ export BINDIR=/var/tmp/bins
972024-07-10T15:26:38.127Z+ BINDIR=/var/tmp/bins
982024-07-10T15:26:38.127Z+ banner test_up_encrypted
992024-07-10T15:26:38.130Z
1002024-07-10T15:26:38.130Z ##### ###### #### ##### # # ##### ###### # #
1012024-07-10T15:26:38.130Z # # # # # # # # # ## #
1022024-07-10T15:26:38.130Z # ##### #### # # # # # ##### # # #
1032024-07-10T15:26:38.130Z # # # # # # ##### # # # #
1042024-07-10T15:26:38.130Z # # # # # # # # # # ##
1052024-07-10T15:26:38.130Z # ###### #### # ####### #### # ####### ###### # #
1062024-07-10T15:26:38.130Z
1072024-07-10T15:26:38.130Z+ ptime -m bash /input/build/work/scripts/test_up.sh -N encrypted
1082024-07-10T15:26:38.139Z/input/build/work
1092024-07-10T15:26:38.147ZTurn off color for downstairs dump
1102024-07-10T15:26:38.161ZUpstairs using key: 5adfxo8TdR2DA0dgdB9zHHj0JZt5b7nBJdIde9AVmzQ=
1112024-07-10T15:26:38.164Zdsc output goes to /tmp/test_up/dsc-out.txt
1122024-07-10T15:26:38.164ZCreating three downstairs regions
1132024-07-10T15:26:38.278ZStarting three downstairs
1142024-07-10T15:26:43.282ZDisable automatic restart on all downstairs
1152024-07-10T15:26:43.339Z
1162024-07-10T15:26:43.339ZBegin tests, output goes to /tmp/test_up/test_up_out.txt
1172024-07-10T15:26:43.342ZRunning test: span
1182024-07-10T15:26:47.396ZCompleted test: span
1192024-07-10T15:26:52.403ZRunning test: big
1202024-07-10T15:26:56.694ZCompleted test: big
1212024-07-10T15:27:01.701ZRunning test: dep
1222024-07-10T15:27:48.700ZCompleted test: dep
1232024-07-10T15:27:53.707ZRunning test: balloon
1242024-07-10T15:28:31.636ZCompleted test: balloon
1252024-07-10T15:28:36.641ZRunning test: deactivate
1262024-07-10T15:29:31.281ZCompleted test: deactivate
1272024-07-10T15:29:36.276ZRunning hammer
1282024-07-10T15:29:47.495ZRun repair tests
1292024-07-10T15:29:47.500Z/var/tmp/bins/crutest fill -g 31 -q --key 5adfxo8TdR2DA0dgdB9zHHj0JZt5b7nBJdIde9AVmzQ= -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-07-10T15:29:47.515Z{"msg":"Upstairs starts","v":0,"name":"crucible","level":30,"time":"2024-07-10T15:29:46.892429738Z","hostname":"w-01J2EKZEVPA6452PKBGH6J05BH","pid":1207}
1312024-07-10T15:29:47.520Z{"msg":"Crucible Version: BuildInfo {\n version: \"0.0.1\",\n git_sha: \"6b815a43cfc10bcc32090edef97cce2a57967dc5\",\n git_commit_timestamp: \"2024-07-10T15:11:32.000000000Z\",\n git_branch: \"renovate/nbd-0.x\",\n rustc_semver: \"1.76.0\",\n rustc_channel: \"stable\",\n rustc_host_triple: \"x86_64-unknown-illumos\",\n rustc_commit_sha: \"07dca489ac2d933c78d3c5158e3f43beefeb02ce\",\n cargo_triple: \"x86_64-unknown-illumos\",\n debug: true,\n opt_level: 0,\n}","v":0,"name":"crucible","level":30,"time":"2024-07-10T15:29:46.892707865Z","hostname":"w-01J2EKZEVPA6452PKBGH6J05BH","pid":1207}
1322024-07-10T15:29:47.520Z{"msg":"Upstairs <-> Downstairs Message Version: 8","v":0,"name":"crucible","level":30,"time":"2024-07-10T15:29:46.892739195Z","hostname":"w-01J2EKZEVPA6452PKBGH6J05BH","pid":1207}
1332024-07-10T15:29:47.520Z{"msg":"Crucible 707a85a9-4caf-4953-88cd-ce1392055c4e has session id: b088ca7a-e703-496b-a062-4c8f9e989d97","v":0,"name":"crucible","level":30,"time":"2024-07-10T15:29:46.893187391Z","hostname":"w-01J2EKZEVPA6452PKBGH6J05BH","pid":1207,"session_id":"b088ca7a-e703-496b-a062-4c8f9e989d97"}
1342024-07-10T15:29:47.520Z{"msg":"Upstairs opts: Upstairs UUID: 707a85a9-4caf-4953-88cd-ce1392055c4e, 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-07-10T15:29:46.893224821Z","hostname":"w-01J2EKZEVPA6452PKBGH6J05BH","pid":1207,"session_id":"b088ca7a-e703-496b-a062-4c8f9e989d97"}
1352024-07-10T15:29:47.520Z{"msg":"Crucible stats registered with UUID: 707a85a9-4caf-4953-88cd-ce1392055c4e","v":0,"name":"crucible","level":30,"time":"2024-07-10T15:29:46.893242061Z","hostname":"w-01J2EKZEVPA6452PKBGH6J05BH","pid":1207,"session_id":"b088ca7a-e703-496b-a062-4c8f9e989d97"}
1362024-07-10T15:29:47.520ZCrucible runtime is spawned
1372024-07-10T15:29:47.520Z{"msg":"The guest has requested activation with gen:31","v":0,"name":"crucible","level":30,"time":"2024-07-10T15:29:46.893536738Z","hostname":"w-01J2EKZEVPA6452PKBGH6J05BH","pid":1207}
1382024-07-10T15:29:47.520Z{"msg":"707a85a9-4caf-4953-88cd-ce1392055c4e active request set","v":0,"name":"crucible","level":30,"time":"2024-07-10T15:29:46.893573068Z","hostname":"w-01J2EKZEVPA6452PKBGH6J05BH","pid":1207,"session_id":"b088ca7a-e703-496b-a062-4c8f9e989d97"}
1392024-07-10T15:29:47.520Z{"msg":"sending connect oneshot to client","v":0,"name":"crucible","level":30,"time":"2024-07-10T15:29:46.893596828Z","hostname":"w-01J2EKZEVPA6452PKBGH6J05BH","pid":1207,"client":"0","":"downstairs","session_id":"b088ca7a-e703-496b-a062-4c8f9e989d97"}
1402024-07-10T15:29:47.520Z{"msg":"client set_active_request while in New; waiting...","v":0,"name":"crucible","level":30,"time":"2024-07-10T15:29:46.893619538Z","hostname":"w-01J2EKZEVPA6452PKBGH6J05BH","pid":1207,"client":"0","":"downstairs","session_id":"b088ca7a-e703-496b-a062-4c8f9e989d97"}
1412024-07-10T15:29:47.520Z{"msg":"sending connect oneshot to client","v":0,"name":"crucible","level":30,"time":"2024-07-10T15:29:46.893640968Z","hostname":"w-01J2EKZEVPA6452PKBGH6J05BH","pid":1207,"client":"1","":"downstairs","session_id":"b088ca7a-e703-496b-a062-4c8f9e989d97"}
1422024-07-10T15:29:47.520Z{"msg":"client set_active_request while in New; waiting...","v":0,"name":"crucible","level":30,"time":"2024-07-10T15:29:46.893664408Z","hostname":"w-01J2EKZEVPA6452PKBGH6J05BH","pid":1207,"client":"1","":"downstairs","session_id":"b088ca7a-e703-496b-a062-4c8f9e989d97"}
1432024-07-10T15:29:47.520Z{"msg":"sending connect oneshot to client","v":0,"name":"crucible","level":30,"time":"2024-07-10T15:29:46.893696737Z","hostname":"w-01J2EKZEVPA6452PKBGH6J05BH","pid":1207,"client":"2","":"downstairs","session_id":"b088ca7a-e703-496b-a062-4c8f9e989d97"}
1442024-07-10T15:29:47.520Z{"msg":"client set_active_request while in New; waiting...","v":0,"name":"crucible","level":30,"time":"2024-07-10T15:29:46.893721477Z","hostname":"w-01J2EKZEVPA6452PKBGH6J05BH","pid":1207,"client":"2","":"downstairs","session_id":"b088ca7a-e703-496b-a062-4c8f9e989d97"}
1452024-07-10T15:29:47.520Z{"msg":"connecting to 127.0.0.1:8810","v":0,"name":"crucible","level":30,"time":"2024-07-10T15:29:46.893750267Z","hostname":"w-01J2EKZEVPA6452PKBGH6J05BH","pid":1207,"":"io task","client":"0","":"downstairs","session_id":"b088ca7a-e703-496b-a062-4c8f9e989d97"}
1462024-07-10T15:29:47.520Z{"msg":"connecting to 127.0.0.1:8820","v":0,"name":"crucible","level":30,"time":"2024-07-10T15:29:46.893775096Z","hostname":"w-01J2EKZEVPA6452PKBGH6J05BH","pid":1207,"":"io task","client":"1","":"downstairs","session_id":"b088ca7a-e703-496b-a062-4c8f9e989d97"}
1472024-07-10T15:29:47.520Z{"msg":"connecting to 127.0.0.1:8830","v":0,"name":"crucible","level":30,"time":"2024-07-10T15:29:46.893797146Z","hostname":"w-01J2EKZEVPA6452PKBGH6J05BH","pid":1207,"":"io task","client":"2","":"downstairs","session_id":"b088ca7a-e703-496b-a062-4c8f9e989d97"}
1482024-07-10T15:29:47.520Z{"msg":"ds_connection connected from Ok(127.0.0.1:63513)","v":0,"name":"crucible","level":30,"time":"2024-07-10T15:29:46.893990205Z","hostname":"w-01J2EKZEVPA6452PKBGH6J05BH","pid":1207,"":"io task","client":"1","":"downstairs","session_id":"b088ca7a-e703-496b-a062-4c8f9e989d97"}
1492024-07-10T15:29:47.520Z{"msg":"ds_connection connected from Ok(127.0.0.1:35682)","v":0,"name":"crucible","level":30,"time":"2024-07-10T15:29:46.894028054Z","hostname":"w-01J2EKZEVPA6452PKBGH6J05BH","pid":1207,"":"io task","client":"0","":"downstairs","session_id":"b088ca7a-e703-496b-a062-4c8f9e989d97"}
1502024-07-10T15:29:47.520Z{"msg":"ds_connection connected from Ok(127.0.0.1:58837)","v":0,"name":"crucible","level":30,"time":"2024-07-10T15:29:46.894165653Z","hostname":"w-01J2EKZEVPA6452PKBGH6J05BH","pid":1207,"":"io task","client":"2","":"downstairs","session_id":"b088ca7a-e703-496b-a062-4c8f9e989d97"}
1512024-07-10T15:29:47.520Z{"msg":"ds_transition from New to WaitActive","v":0,"name":"crucible","level":30,"time":"2024-07-10T15:29:46.894830368Z","hostname":"w-01J2EKZEVPA6452PKBGH6J05BH","pid":1207,"client":"0","":"downstairs","session_id":"b088ca7a-e703-496b-a062-4c8f9e989d97"}
1522024-07-10T15:29:47.520Z{"msg":"[0] Transition from New to WaitActive","v":0,"name":"crucible","level":30,"time":"2024-07-10T15:29:46.894885157Z","hostname":"w-01J2EKZEVPA6452PKBGH6J05BH","pid":1207,"client":"0","":"downstairs","session_id":"b088ca7a-e703-496b-a062-4c8f9e989d97"}
1532024-07-10T15:29:47.520Z{"msg":"ds_transition from New to WaitActive","v":0,"name":"crucible","level":30,"time":"2024-07-10T15:29:46.894917327Z","hostname":"w-01J2EKZEVPA6452PKBGH6J05BH","pid":1207,"client":"2","":"downstairs","session_id":"b088ca7a-e703-496b-a062-4c8f9e989d97"}
1542024-07-10T15:29:47.520Z{"msg":"[2] Transition from New to WaitActive","v":0,"name":"crucible","level":30,"time":"2024-07-10T15:29:46.894943737Z","hostname":"w-01J2EKZEVPA6452PKBGH6J05BH","pid":1207,"client":"2","":"downstairs","session_id":"b088ca7a-e703-496b-a062-4c8f9e989d97"}
1552024-07-10T15:29:47.520Z{"msg":"ds_transition from New to WaitActive","v":0,"name":"crucible","level":30,"time":"2024-07-10T15:29:46.894979247Z","hostname":"w-01J2EKZEVPA6452PKBGH6J05BH","pid":1207,"client":"1","":"downstairs","session_id":"b088ca7a-e703-496b-a062-4c8f9e989d97"}
1562024-07-10T15:29:47.520Z{"msg":"[1] Transition from New to WaitActive","v":0,"name":"crucible","level":30,"time":"2024-07-10T15:29:46.895005336Z","hostname":"w-01J2EKZEVPA6452PKBGH6J05BH","pid":1207,"client":"1","":"downstairs","session_id":"b088ca7a-e703-496b-a062-4c8f9e989d97"}
1572024-07-10T15:29:47.520Z{"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-07-10T15:29:46.895558282Z","hostname":"w-01J2EKZEVPA6452PKBGH6J05BH","pid":1207,"client":"2","":"downstairs","session_id":"b088ca7a-e703-496b-a062-4c8f9e989d97"}
1582024-07-10T15:29:47.520Z{"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-07-10T15:29:46.895610161Z","hostname":"w-01J2EKZEVPA6452PKBGH6J05BH","pid":1207,"client":"1","":"downstairs","session_id":"b088ca7a-e703-496b-a062-4c8f9e989d97"}
1592024-07-10T15:29:47.520Z{"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-07-10T15:29:46.895657151Z","hostname":"w-01J2EKZEVPA6452PKBGH6J05BH","pid":1207,"client":"0","":"downstairs","session_id":"b088ca7a-e703-496b-a062-4c8f9e989d97"}
1602024-07-10T15:29:47.520Z{"msg":"ds_transition from WaitActive to WaitQuorum","v":0,"name":"crucible","level":30,"time":"2024-07-10T15:29:46.896002578Z","hostname":"w-01J2EKZEVPA6452PKBGH6J05BH","pid":1207,"client":"2","":"downstairs","session_id":"b088ca7a-e703-496b-a062-4c8f9e989d97"}
1612024-07-10T15:29:47.520Z{"msg":"[2] Transition from WaitActive to WaitQuorum","v":0,"name":"crucible","level":30,"time":"2024-07-10T15:29:46.896050068Z","hostname":"w-01J2EKZEVPA6452PKBGH6J05BH","pid":1207,"client":"2","":"downstairs","session_id":"b088ca7a-e703-496b-a062-4c8f9e989d97"}
1622024-07-10T15:29:47.520Z{"msg":"Waiting for more clients to be ready","v":0,"name":"crucible","level":30,"time":"2024-07-10T15:29:46.896067778Z","hostname":"w-01J2EKZEVPA6452PKBGH6J05BH","pid":1207,"session_id":"b088ca7a-e703-496b-a062-4c8f9e989d97"}
1632024-07-10T15:29:47.520Z{"msg":"ds_transition from WaitActive to WaitQuorum","v":0,"name":"crucible","level":30,"time":"2024-07-10T15:29:46.896088528Z","hostname":"w-01J2EKZEVPA6452PKBGH6J05BH","pid":1207,"client":"1","":"downstairs","session_id":"b088ca7a-e703-496b-a062-4c8f9e989d97"}
1642024-07-10T15:29:47.520Z{"msg":"[1] Transition from WaitActive to WaitQuorum","v":0,"name":"crucible","level":30,"time":"2024-07-10T15:29:46.896103017Z","hostname":"w-01J2EKZEVPA6452PKBGH6J05BH","pid":1207,"client":"1","":"downstairs","session_id":"b088ca7a-e703-496b-a062-4c8f9e989d97"}
1652024-07-10T15:29:47.521Z{"msg":"Waiting for more clients to be ready","v":0,"name":"crucible","level":30,"time":"2024-07-10T15:29:46.896116357Z","hostname":"w-01J2EKZEVPA6452PKBGH6J05BH","pid":1207,"session_id":"b088ca7a-e703-496b-a062-4c8f9e989d97"}
1662024-07-10T15:29:47.521Z{"msg":"ds_transition from WaitActive to WaitQuorum","v":0,"name":"crucible","level":30,"time":"2024-07-10T15:29:46.896128837Z","hostname":"w-01J2EKZEVPA6452PKBGH6J05BH","pid":1207,"client":"0","":"downstairs","session_id":"b088ca7a-e703-496b-a062-4c8f9e989d97"}
1672024-07-10T15:29:47.521Z{"msg":"[0] Transition from WaitActive to WaitQuorum","v":0,"name":"crucible","level":30,"time":"2024-07-10T15:29:46.896142297Z","hostname":"w-01J2EKZEVPA6452PKBGH6J05BH","pid":1207,"client":"0","":"downstairs","session_id":"b088ca7a-e703-496b-a062-4c8f9e989d97"}
1682024-07-10T15:29:47.521Z{"msg":"[0]R flush_numbers: [1656, 1656, 1656, 1656, 1656]","v":0,"name":"crucible","level":30,"time":"2024-07-10T15:29:46.896155697Z","hostname":"w-01J2EKZEVPA6452PKBGH6J05BH","pid":1207,"":"downstairs","":"downstairs","session_id":"b088ca7a-e703-496b-a062-4c8f9e989d97"}
1692024-07-10T15:29:47.521Z{"msg":"[0]R generation: [25, 25, 25, 25, 25]","v":0,"name":"crucible","level":30,"time":"2024-07-10T15:29:46.896169227Z","hostname":"w-01J2EKZEVPA6452PKBGH6J05BH","pid":1207,"":"downstairs","":"downstairs","session_id":"b088ca7a-e703-496b-a062-4c8f9e989d97"}
1702024-07-10T15:29:47.521ZWait for a query_work_queue command to finish before sending IO
1712024-07-10T15:29:47.521Z{"msg":"[0]R dirty: [false, false, false, false, false]","v":0,"name":"crucible","level":30,"time":"2024-07-10T15:29:46.896198456Z","hostname":"w-01J2EKZEVPA6452PKBGH6J05BH","pid":1207,"":"downstairs","":"downstairs","session_id":"b088ca7a-e703-496b-a062-4c8f9e989d97"}
1722024-07-10T15:29:47.521Z{"msg":"[1]R flush_numbers: [1656, 1656, 1656, 1656, 1656]","v":0,"name":"crucible","level":30,"time":"2024-07-10T15:29:46.896232476Z","hostname":"w-01J2EKZEVPA6452PKBGH6J05BH","pid":1207,"":"downstairs","":"downstairs","session_id":"b088ca7a-e703-496b-a062-4c8f9e989d97"}
1732024-07-10T15:29:47.521Z{"msg":"[1]R generation: [25, 25, 25, 25, 25]","v":0,"name":"crucible","level":30,"time":"2024-07-10T15:29:46.896267026Z","hostname":"w-01J2EKZEVPA6452PKBGH6J05BH","pid":1207,"":"downstairs","":"downstairs","session_id":"b088ca7a-e703-496b-a062-4c8f9e989d97"}
1742024-07-10T15:29:47.521Z{"msg":"[1]R dirty: [false, false, false, false, false]","v":0,"name":"crucible","level":30,"time":"2024-07-10T15:29:46.896303146Z","hostname":"w-01J2EKZEVPA6452PKBGH6J05BH","pid":1207,"":"downstairs","":"downstairs","session_id":"b088ca7a-e703-496b-a062-4c8f9e989d97"}
1752024-07-10T15:29:47.521Z{"msg":"[2]R flush_numbers: [1656, 1656, 1656, 1656, 1656]","v":0,"name":"crucible","level":30,"time":"2024-07-10T15:29:46.896337735Z","hostname":"w-01J2EKZEVPA6452PKBGH6J05BH","pid":1207,"":"downstairs","":"downstairs","session_id":"b088ca7a-e703-496b-a062-4c8f9e989d97"}
1762024-07-10T15:29:47.521Z{"msg":"[2]R generation: [25, 25, 25, 25, 25]","v":0,"name":"crucible","level":30,"time":"2024-07-10T15:29:46.896372145Z","hostname":"w-01J2EKZEVPA6452PKBGH6J05BH","pid":1207,"":"downstairs","":"downstairs","session_id":"b088ca7a-e703-496b-a062-4c8f9e989d97"}
1772024-07-10T15:29:47.521Z{"msg":"[2]R dirty: [false, false, false, false, false]","v":0,"name":"crucible","level":30,"time":"2024-07-10T15:29:46.896407955Z","hostname":"w-01J2EKZEVPA6452PKBGH6J05BH","pid":1207,"":"downstairs","":"downstairs","session_id":"b088ca7a-e703-496b-a062-4c8f9e989d97"}
1782024-07-10T15:29:47.521Z{"msg":"Max found gen is 26","v":0,"name":"crucible","level":30,"time":"2024-07-10T15:29:46.896434095Z","hostname":"w-01J2EKZEVPA6452PKBGH6J05BH","pid":1207,"":"downstairs","":"downstairs","session_id":"b088ca7a-e703-496b-a062-4c8f9e989d97"}
1792024-07-10T15:29:47.521Z{"msg":"Generation requested: 31 >= found:26","v":0,"name":"crucible","level":30,"time":"2024-07-10T15:29:46.896467494Z","hostname":"w-01J2EKZEVPA6452PKBGH6J05BH","pid":1207,"":"downstairs","":"downstairs","session_id":"b088ca7a-e703-496b-a062-4c8f9e989d97"}
1802024-07-10T15:29:47.521Z{"msg":"Next flush: 1657","v":0,"name":"crucible","level":30,"time":"2024-07-10T15:29:46.896501244Z","hostname":"w-01J2EKZEVPA6452PKBGH6J05BH","pid":1207,"":"downstairs","":"downstairs","session_id":"b088ca7a-e703-496b-a062-4c8f9e989d97"}
1812024-07-10T15:29:47.521Z{"msg":"All extents match","v":0,"name":"crucible","level":30Region: es:10 ec:5 bs:4096 ts:204800 tb:50 max_io:50 or 204800
1822024-07-10T15:29:47.521Z,"time":"2024-07-10T15:29:46.896535024Z","hostname":"w-01J2EKZEVPA6452PKBGH6J05BH","pid":1207,"":"downstairs","":"downstairs","session_id":"b088ca7a-e703-496b-a062-4c8f9e989d97"}
1832024-07-10T15:29:47.521Z{"msg":"No downstairs reconciliation required","v":0,"name":"crucible","level":30Fill test
1842024-07-10T15:29:47.521Z,"time":"2024-07-10T15:29:46.896570404Z","hostname":"w-01J2EKZEVPA6452PKBGH6J05BH","pid":1207,"session_id":"b088ca7a-e703-496b-a062-4c8f9e989d97"}
1852024-07-10T15:29:47.521Z{"msg":"Transition from WaitQuorum to Active","v":0,"name":"crucible","level":30,"time":"2024-07-10T15:29:46.896595743Z","hostname":"w-01J2EKZEVPA6452PKBGH6J05BH","pid":1207,"client":"0","":"downstairs","session_id":"b088ca7a-e703-496b-a062-4c8f9e989d97"}
1862024-07-10T15:29:47.521Z{"msg":"Transition from WaitQuorum to Active","v":0,"name":"crucible","level":30,"time":"2024-07-10T15:29:46.896610333Z","hostname":"w-01J2EKZEVPA6452PKBGH6J05BH","pid":1207,"client":"1","":"downstairs","session_id":"b088ca7a-e703-496b-a062-4c8f9e989d97"}
1872024-07-10T15:29:47.521Z{"msg":"Transition from WaitQuorum to Active","v":0,"name":"crucible","level":30,"time":"2024-07-10T15:29:46.896631153Z","hostname":"w-01J2EKZEVPA6452PKBGH6J05BH","pid":1207,"client":"2","":"downstairs","session_id":"b088ca7a-e703-496b-a062-4c8f9e989d97"}
1882024-07-10T15:29:47.521Z{"msg":"All required reconciliation work is completed","v":0,"name":"crucible","level":30,"time":"2024-07-10T15:29:46.896644973Z","hostname":"w-01J2EKZEVPA6452PKBGH6J05BH","pid":1207,"session_id":"b088ca7a-e703-496b-a062-4c8f9e989d97"}
1892024-07-10T15:29:47.521Z{"msg":"Set Downstairs and Upstairs active after reconciliation","v":0,"name":"crucible","level":30,"time":"2024-07-10T15:29:46.896664073Z","hostname":"w-01J2EKZEVPA6452PKBGH6J05BH","pid":1207,"session_id":"b088ca7a-e703-496b-a062-4c8f9e989d97"}
1902024-07-10T15:29:47.521Z{"msg":"707a85a9-4caf-4953-88cd-ce1392055c4e is now active with session: b088ca7a-e703-496b-a062-4c8f9e989d97","v":0,"name":"crucible","level":30,"time":"2024-07-10T15:29:46.896677803Z","hostname":"w-01J2EKZEVPA6452PKBGH6J05BH","pid":1207,"session_id":"b088ca7a-e703-496b-a062-4c8f9e989d97"}
1912024-07-10T15:29:47.521Z{"msg":"Set Active after no reconciliation","v":0,"name":"crucible","level":30,"time":"2024-07-10T15:29:46.896696712Z","hostname":"w-01J2EKZEVPA6452PKBGH6J05BH","pid":1207,"session_id":"b088ca7a-e703-496b-a062-4c8f9e989d97"}
1922024-07-10T15:29:47.521Z{"msg":"The guest has finished waiting for activation with:31","v":0,"name":"crucible","level":30,"time":"2024-07-10T15:29:46.896709132Z","hostname":"w-01J2EKZEVPA6452PKBGH6J05BH","pid":1207}
1932024-07-10T15:29:47.553ZRead and Verify all blocks (0..50 range:false)
1942024-07-10T15:29:47.611ZWrote out file "/var/tmp/test_up/verify_file"
1952024-07-10T15:29:47.611ZCLIENT: Tests done. All submitted work has been ACK'd
1962024-07-10T15:29:47.614Z----------------------------------------------------------------
1972024-07-10T15:29:47.614Z Crucible gen:31 GIO:true work queues: Upstairs:0 downstairs:1
1982024-07-10T15:29:47.614ZStates: Active Active Active
1992024-07-10T15:29:47.614ZGW_ID ACK DSID TYPE BKS/EXT DS:0 DS:1 DS:2 REPLAY
2002024-07-10T15:29:47.614Z 3 Acked 1002 Read 50 Done Done Done false
2012024-07-10T15:29:47.614Z STATES DS:0 DS:1 DS:2 TOTAL
2022024-07-10T15:29:47.614Z New 0 0 0 0
2032024-07-10T15:29:47.614Z Sent 0 0 0 0
2042024-07-10T15:29:47.614Z Done 1 1 1 3
2052024-07-10T15:29:47.614Z Skipped 0 0 0 0
2062024-07-10T15:29:47.614Z Error 0 0 0 0
2072024-07-10T15:29:47.614ZLast Flush: 1001 1001 1001
2082024-07-10T15:29:47.614ZDownstairs last five completed: 1001 1000
2092024-07-10T15:29:47.614ZUpstairs last five completed: 3 2 1
2102024-07-10T15:29:47.614ZCLIENT: Up:0 ds:1 act:3
2112024-07-10T15:29:51.602Z----------------------------------------------------------------
2122024-07-10T15:29:51.602Z Crucible gen:31 GIO:true work queues: Upstairs:0 downstairs:0
2132024-07-10T15:29:51.602ZDownstairs last five completed: 1003 1002 1001 1000
2142024-07-10T15:29:51.603ZUpstairs last five completed: 4 3 2 1
2152024-07-10T15:29:51.603ZCLIENT: Up:0 ds:0 act:3
2162024-07-10T15:29:51.603ZCLIENT: All crucible jobs finished, exiting program
2172024-07-10T15:29:51.606Z{"msg":"Guest handle has been dropped","v":0,"name":"crucible","level":40,"time":"2024-07-10T15:29:50.98273933Z","hostname":"w-01J2EKZEVPA6452PKBGH6J05BH","pid":1207}
2182024-07-10T15:29:51.636ZRepair setup passed
2192024-07-10T15:29:51.637ZCopy the 8830 file
2202024-07-10T15:29:51.637Zcp -r /var/tmp/test_up/8830 /var/tmp/test_up/previous
2212024-07-10T15:29:51.637Z/var/tmp/bins/crutest repair -g 32 -q --key 5adfxo8TdR2DA0dgdB9zHHj0JZt5b7nBJdIde9AVmzQ= -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
2222024-07-10T15:29:51.644Z{"msg":"Upstairs starts","v":0,"name":"crucible","level":30,"time":"2024-07-10T15:29:51.010986057Z","hostname":"w-01J2EKZEVPA6452PKBGH6J05BH","pid":1213}
2232024-07-10T15:29:51.644Z{"msg":"Crucible Version: BuildInfo {\n version: \"0.0.1\",\n git_sha: \"6b815a43cfc10bcc32090edef97cce2a57967dc5\",\n git_commit_timestamp: \"2024-07-10T15:11:32.000000000Z\",\n git_branch: \"renovate/nbd-0.x\",\n rustc_semver: \"1.76.0\",\n rustc_channel: \"stable\",\n rustc_host_triple: \"x86_64-unknown-illumos\",\n rustc_commit_sha: \"07dca489ac2d933c78d3c5158e3f43beefeb02ce\",\n cargo_triple: \"x86_64-unknown-illumos\",\n debug: true,\n opt_level: 0,\n}","v":0,"name":"crucible","level":30,"time":"2024-07-10T15:29:51.011297054Z","hostname":"w-01J2EKZEVPA6452PKBGH6J05BH","pid":1213}
2242024-07-10T15:29:51.644Z{"msg":"Upstairs <-> Downstairs Message Version: 8","v":0,"name":"crucible","level":30,"time":"2024-07-10T15:29:51.011328424Z","hostname":"w-01J2EKZEVPA6452PKBGH6J05BH","pid":1213}
2252024-07-10T15:29:51.644Z{"msg":"Crucible a2c676d0-8e9d-4561-880a-be498e7477a7 has session id: 92ac4f91-35a9-498d-92d0-ba51cd2afcfb","v":0,"name":"crucible","level":30,"time":"2024-07-10T15:29:51.011695121Z","hostname":"w-01J2EKZEVPA6452PKBGH6J05BH","pid":1213,"session_id":"92ac4f91-35a9-498d-92d0-ba51cd2afcfb"}
2262024-07-10T15:29:51.644Z{"msg":"Upstairs opts: Upstairs UUID: a2c676d0-8e9d-4561-880a-be498e7477a7, 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-07-10T15:29:51.011749501Z","hostname":"w-01J2EKZEVPA6452PKBGH6J05BH","pid":1213,"session_id":"92ac4f91-35a9-498d-92d0-ba51cd2afcfb"}
2272024-07-10T15:29:51.644Z{"msg":"Crucible stats registered with UUID: a2c676d0-8e9d-4561-880a-be498e7477a7","v":0,"name":"crucible","level":30,"time":"2024-07-10T15:29:51.0117757Z","hostname":"w-01J2EKZEVPA6452PKBGH6J05BH","pid":1213,"session_id":"92ac4f91-35a9-498d-92d0-ba51cd2afcfb"}
2282024-07-10T15:29:51.644ZCrucible runtime is spawned
2292024-07-10T15:29:51.644Z{"msg":"The guest has requested activation with gen:32","v":0,"name":"crucible","level":30,"time":"2024-07-10T15:29:51.012066378Z","hostname":"w-01J2EKZEVPA6452PKBGH6J05BH","pid":1213}
2302024-07-10T15:29:51.644Z{"msg":"a2c676d0-8e9d-4561-880a-be498e7477a7 active request set","v":0,"name":"crucible","level":30,"time":"2024-07-10T15:29:51.012127538Z","hostname":"w-01J2EKZEVPA6452PKBGH6J05BH","pid":1213,"session_id":"92ac4f91-35a9-498d-92d0-ba51cd2afcfb"}
2312024-07-10T15:29:51.644Z{"msg":"sending connect oneshot to client","v":0,"name":"crucible","level":30,"time":"2024-07-10T15:29:51.012171767Z","hostname":"w-01J2EKZEVPA6452PKBGH6J05BH","pid":1213,"client":"0","":"downstairs","session_id":"92ac4f91-35a9-498d-92d0-ba51cd2afcfb"}
2322024-07-10T15:29:51.644Z{"msg":"client set_active_request while in New; waiting...","v":0,"name":"crucible","level":30,"time":"2024-07-10T15:29:51.012200197Z","hostname":"w-01J2EKZEVPA6452PKBGH6J05BH","pid":1213,"client":"0","":"downstairs","session_id":"92ac4f91-35a9-498d-92d0-ba51cd2afcfb"}
2332024-07-10T15:29:51.644Z{"msg":"sending connect oneshot to client","v":0,"name":"crucible","level":30,"time":"2024-07-10T15:29:51.012240397Z","hostname":"w-01J2EKZEVPA6452PKBGH6J05BH","pid":1213,"client":"1","":"downstairs","session_id":"92ac4f91-35a9-498d-92d0-ba51cd2afcfb"}
2342024-07-10T15:29:51.644Z{"msg":"client set_active_request while in New; waiting...","v":0,"name":"crucible","level":30,"time":"2024-07-10T15:29:51.012268956Z","hostname":"w-01J2EKZEVPA6452PKBGH6J05BH","pid":1213,"client":"1","":"downstairs","session_id":"92ac4f91-35a9-498d-92d0-ba51cd2afcfb"}
2352024-07-10T15:29:51.644Z{"msg":"sending connect oneshot to client","v":0,"name":"crucible","level":30,"time":"2024-07-10T15:29:51.012306526Z","hostname":"w-01J2EKZEVPA6452PKBGH6J05BH","pid":1213,"client":"2","":"downstairs","session_id":"92ac4f91-35a9-498d-92d0-ba51cd2afcfb"}
2362024-07-10T15:29:51.644Z{"msg":"client set_active_request while in New; waiting...","v":0,"name":"crucible","level":30,"time":"2024-07-10T15:29:51.012351686Z","hostname":"w-01J2EKZEVPA6452PKBGH6J05BH","pid":1213,"client":"2","":"downstairs","session_id":"92ac4f91-35a9-498d-92d0-ba51cd2afcfb"}
2372024-07-10T15:29:51.644Z{"msg":"connecting to 127.0.0.1:8810","v":0,"name":"crucible","level":30,"time":"2024-07-10T15:29:51.012377245Z","hostname":"w-01J2EKZEVPA6452PKBGH6J05BH","pid":1213,"":"io task","client":"0","":"downstairs","session_id":"92ac4f91-35a9-498d-92d0-ba51cd2afcfb"}
2382024-07-10T15:29:51.644Z{"msg":"connecting to 127.0.0.1:8820","v":0,"name":"crucible","level":30,"time":"2024-07-10T15:29:51.012403195Z","hostname":"w-01J2EKZEVPA6452PKBGH6J05BH","pid":1213,"":"io task","client":"1","":"downstairs","session_id":"92ac4f91-35a9-498d-92d0-ba51cd2afcfb"}
2392024-07-10T15:29:51.644Z{"msg":"connecting to 127.0.0.1:8830","v":0,"name":"crucible","level":30,"time":"2024-07-10T15:29:51.012428525Z","hostname":"w-01J2EKZEVPA6452PKBGH6J05BH","pid":1213,"":"io task","client":"2","":"downstairs","session_id":"92ac4f91-35a9-498d-92d0-ba51cd2afcfb"}
2402024-07-10T15:29:51.644Z{"msg":"ds_connection connected from Ok(127.0.0.1:65059)","v":0,"name":"crucible","level":30,"time":"2024-07-10T15:29:51.012628493Z","hostname":"w-01J2EKZEVPA6452PKBGH6J05BH","pid":1213,"":"io task","client":"0","":"downstairs","session_id":"92ac4f91-35a9-498d-92d0-ba51cd2afcfb"}
2412024-07-10T15:29:51.644Z{"msg":"ds_connection connected from Ok(127.0.0.1:37883)","v":0,"name":"crucible","level":30,"time":"2024-07-10T15:29:51.012690313Z","hostname":"w-01J2EKZEVPA6452PKBGH6J05BH","pid":1213,"":"io task","client":"1","":"downstairs","session_id":"92ac4f91-35a9-498d-92d0-ba51cd2afcfb"}
2422024-07-10T15:29:51.644Z{"msg":"ds_connection connected from Ok(127.0.0.1:58133)","v":0,"name":"crucible","level":30,"time":"2024-07-10T15:29:51.012717403Z","hostname":"w-01J2EKZEVPA6452PKBGH6J05BH","pid":1213,"":"io task","client":"2","":"downstairs","session_id":"92ac4f91-35a9-498d-92d0-ba51cd2afcfb"}
2432024-07-10T15:29:51.644Z{"msg":"ds_transition from New to WaitActive","v":0,"name":"crucible","level":30,"time":"2024-07-10T15:29:51.013348957Z","hostname":"w-01J2EKZEVPA6452PKBGH6J05BH","pid":1213,"client":"0","":"downstairs","session_id":"92ac4f91-35a9-498d-92d0-ba51cd2afcfb"}
2442024-07-10T15:29:51.644Z{"msg":"[0] Transition from New to WaitActive","v":0,"name":"crucible","level":30,"time":"2024-07-10T15:29:51.013375187Z","hostname":"w-01J2EKZEVPA6452PKBGH6J05BH","pid":1213,"client":"0","":"downstairs","session_id":"92ac4f91-35a9-498d-92d0-ba51cd2afcfb"}
2452024-07-10T15:29:51.645Z{"msg":"ds_transition from New to WaitActive","v":0,"name":"crucible","level":30,"time":"2024-07-10T15:29:51.013389877Z","hostname":"w-01J2EKZEVPA6452PKBGH6J05BH","pid":1213,"client":"1","":"downstairs","session_id":"92ac4f91-35a9-498d-92d0-ba51cd2afcfb"}
2462024-07-10T15:29:51.645Z{"msg":"[1] Transition from New to WaitActive","v":0,"name":"crucible","level":30,"time":"2024-07-10T15:29:51.013403977Z","hostname":"w-01J2EKZEVPA6452PKBGH6J05BH","pid":1213,"client":"1","":"downstairs","session_id":"92ac4f91-35a9-498d-92d0-ba51cd2afcfb"}
2472024-07-10T15:29:51.645Z{"msg":"ds_transition from New to WaitActive","v":0,"name":"crucible","level":30,"time":"2024-07-10T15:29:51.013432437Z","hostname":"w-01J2EKZEVPA6452PKBGH6J05BH","pid":1213,"client":"2","":"downstairs","session_id":"92ac4f91-35a9-498d-92d0-ba51cd2afcfb"}
2482024-07-10T15:29:51.645Z{"msg":"[2] Transition from New to WaitActive","v":0,"name":"crucible","level":30,"time":"2024-07-10T15:29:51.013459636Z","hostname":"w-01J2EKZEVPA6452PKBGH6J05BH","pid":1213,"client":"2","":"downstairs","session_id":"92ac4f91-35a9-498d-92d0-ba51cd2afcfb"}
2492024-07-10T15:29:51.645Z{"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-07-10T15:29:51.013992812Z","hostname":"w-01J2EKZEVPA6452PKBGH6J05BH","pid":1213,"client":"2","":"downstairs","session_id":"92ac4f91-35a9-498d-92d0-ba51cd2afcfb"}
2502024-07-10T15:29:51.645Z{"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-07-10T15:29:51.014125751Z","hostname":"w-01J2EKZEVPA6452PKBGH6J05BH","pid":1213,"client":"0","":"downstairs","session_id":"92ac4f91-35a9-498d-92d0-ba51cd2afcfb"}
2512024-07-10T15:29:51.645Z{"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-07-10T15:29:51.014157691Z","hostname":"w-01J2EKZEVPA6452PKBGH6J05BH","pid":1213,"client":"1","":"downstairs","session_id":"92ac4f91-35a9-498d-92d0-ba51cd2afcfb"}
2522024-07-10T15:29:51.645Z{"msg":"ds_transition from WaitActive to WaitQuorum","v":0,"name":"crucible","level":30,"time":"2024-07-10T15:29:51.014336479Z","hostname":"w-01J2EKZEVPA6452PKBGH6J05BH","pid":1213,"client":"2","":"downstairs","session_id":"92ac4f91-35a9-498d-92d0-ba51cd2afcfb"}
2532024-07-10T15:29:51.645Z{"msg":"[2] Transition from WaitActive to WaitQuorum","v":0,"name":"crucible","level":30,"time":"2024-07-10T15:29:51.014387069Z","hostname":"w-01J2EKZEVPA6452PKBGH6J05BH","pid":1213,"client":"2","":"downstairs","session_id":"92ac4f91-35a9-498d-92d0-ba51cd2afcfb"}
2542024-07-10T15:29:51.645Z{"msg":"Waiting for more clients to be ready","v":0,"name":"crucible","level":30,"time":"2024-07-10T15:29:51.014414699Z","hostname":"w-01J2EKZEVPA6452PKBGH6J05BH","pid":1213,"session_id":"92ac4f91-35a9-498d-92d0-ba51cd2afcfb"}
2552024-07-10T15:29:51.645Z{"msg":"ds_transition from WaitActive to WaitQuorum","v":0,"name":"crucible","level":30,"time":"2024-07-10T15:29:51.014503928Z","hostname":"w-01J2EKZEVPA6452PKBGH6J05BH","pid":1213,"client":"1","":"downstairs","session_id":"92ac4f91-35a9-498d-92d0-ba51cd2afcfb"}
2562024-07-10T15:29:51.645Z{"msg":"[1] Transition from WaitActive to WaitQuorum","v":0,"name":"crucible","level":30,"time":"2024-07-10T15:29:51.014546998Z","hostname":"w-01J2EKZEVPA6452PKBGH6J05BH","pid":1213,"client":"1","":"downstairs","session_id":"92ac4f91-35a9-498d-92d0-ba51cd2afcfb"}
2572024-07-10T15:29:51.645Z{"msg":"Waiting for more clients to be ready","v":0,"name":"crucible","level":30,"time":"2024-07-10T15:29:51.014593387Z","hostname":"w-01J2EKZEVPA6452PKBGH6J05BH","pid":1213,"session_id":"92ac4f91-35a9-498d-92d0-ba51cd2afcfb"}
2582024-07-10T15:29:51.645Z{"msg":"ds_transition from WaitActive to WaitQuorum","v":0,"name":"crucible","level":30,"time":"2024-07-10T15:29:51.014627967Z","hostname":"w-01J2EKZEVPA6452PKBGH6J05BH","pid":1213,"client":"0","":"downstairs","session_id":"92ac4f91-35a9-498d-92d0-ba51cd2afcfb"}
2592024-07-10T15:29:51.645Z{"msg":"[0] Transition from WaitActive to WaitQuorum","v":0,"name":"crucible","level":30,"time":"2024-07-10T15:29:51.014662227Z","hostname":"w-01J2EKZEVPA6452PKBGH6J05BH","pid":1213,"client":"0","":"downstairs","session_id":"92ac4f91-35a9-498d-92d0-ba51cd2afcfb"}
2602024-07-10T15:29:51.645Z{"msg":"[0]R flush_numbers: [1657, 1657, 1657, 1657, 1657]","v":0,"name":"crucible","level":30,"time":"2024-07-10T15:29:51.014696636Z","hostname":"w-01J2EKZEVPA6452PKBGH6J05BH","pid":1213,"":"downstairs","":"downstairs","session_id":"92ac4f91-35a9-498d-92d0-ba51cd2afcfb"}
2612024-07-10T15:29:51.645Z{"msg":"[0]R generation: [31, 31, 31, 31, 31]","v":0,"name":"crucible","level":30Wait for a query_work_queue command to finish before sending IO
2622024-07-10T15:29:51.645Z,"time":"2024-07-10T15:29:51.014731086Z","hostname":"w-01J2EKZEVPA6452PKBGH6J05BH","pid":1213,"":"downstairs","":"downstairs","session_id":"92ac4f91-35a9-498d-92d0-ba51cd2afcfb"}
2632024-07-10T15:29:51.645Z{"msg":"[0]R dirty: [false, false, false, false, false]","v":0,"name":"crucible","level":30,"time":"2024-07-10T15:29:51.014766076Z","hostname":"w-01J2EKZEVPA6452PKBGH6J05BH","pid":1213,"":"downstairs","":"downstairs","session_id":"92ac4f91-35a9-498d-92d0-ba51cd2afcfb"}
2642024-07-10T15:29:51.645Z{"msg":"[1]R flush_numbers: [1657, 1657, 1657, 1657, 1657]","v":0,"name":"crucible","level":30,"time":"2024-07-10T15:29:51.014802716Z","hostname":"w-01J2EKZEVPA6452PKBGH6J05BH","pid":1213,"":"downstairs","":"downstairs","session_id":"92ac4f91-35a9-498d-92d0-ba51cd2afcfb"}
2652024-07-10T15:29:51.645Z{"msg":"[1]R generation: [31, 31, 31, 31, 31]","v":0,"name":"crucible","level":30,"time":"2024-07-10T15:29:51.014838435Z","hostname":"w-01J2EKZEVPA6452PKBGH6J05BH","pid":1213,"":"downstairs","":"downstairs","session_id":"92ac4f91-35a9-498d-92d0-ba51cd2afcfb"}
2662024-07-10T15:29:51.645Z{"msg":"[1]R dirty: [false, false, false, false, false]","v":0,"name":"crucible","level":30,"time":"2024-07-10T15:29:51.014877105Z","hostname":"w-01J2EKZEVPA6452PKBGH6J05BH","pid":1213,"":"downstairs","":"downstairs","session_id":"92ac4f91-35a9-498d-92d0-ba51cd2afcfb"}
2672024-07-10T15:29:51.645Z{"msg":"[2]R flush_numbers: [1657, 1657, 1657, 1657, 1657]","v":0,"name":"crucible","level":30,"time":"2024-07-10T15:29:51.014915464Z","hostname":"w-01J2EKZEVPA6452PKBGH6J05BH","pid":1213,"":"downstairs","":"downstairs","session_id":"92ac4f91-35a9-498d-92d0-ba51cd2afcfb"}
2682024-07-10T15:29:51.645Z{"msg":"[2]R generation: [31, 31, 31, 31, 31]","v":0,"name":"crucible","level":30,"time":"2024-07-10T15:29:51.014952214Z","hostname":"w-01J2EKZEVPA6452PKBGH6J05BH","pid":1213,"":"downstairs","":"downstairs","session_id":"92ac4f91-35a9-498d-92d0-ba51cd2afcfb"}
2692024-07-10T15:29:51.645Z{"msg":"[2]R dirty: [false, false, false, false, false]","v":0,"name":"crucible","level":30,"time":"2024-07-10T15:29:51.014980024Z","hostname":"w-01J2EKZEVPA6452PKBGH6J05BH","pid":1213,"":"downstairs","":"downstairs","session_id":"92ac4f91-35a9-498d-92d0-ba51cd2afcfb"}
2702024-07-10T15:29:51.645Z{"msg":"Max found gen is 32","v":0,"name":"crucible","level":30,"time":"2024-07-10T15:29:51.015035583Z","hostname":"w-01J2EKZEVPA6452PKBGH6J05BH","pid":1213,"":"downstairs","":"downstairs","session_id":"92ac4f91-35a9-498d-92d0-ba51cd2afcfb"}
2712024-07-10T15:29:51.645Z{"msg":"Generation requested: 32 >= found:32","v":0,"name":"crucible","level":30Region: es:10 ec:5 bs:4096 ts:204800 tb:50 max_io:50 or 204800
2722024-07-10T15:29:51.645Z,"time":"2024-07-10T15:29:51.015074373Z","hostname":"w-01J2EKZEVPA6452PKBGH6J05BH","pid":1213,"":"downstairs","":"downstairs","session_id":"92ac4f91-35a9-498d-92d0-ba51cd2afcfb"}
2732024-07-10T15:29:51.645Z{"msg":"Next flush: 1658","v":0,"name":"crucible","level":30,"time":"2024-07-10T15:29:51.015112393Z","hostname":"w-01J2EKZEVPA6452PKBGH6J05BH","pid":1213,"":"downstairs","":"downstairs","session_id":"92ac4f91-35a9-498d-92d0-ba51cd2afcfb"}
2742024-07-10T15:29:51.645Z{"msg":"All extents match","v":0,"name":"crucible","level":30,"time":"2024-07-10T15:29:51.015136933Z","hostname":"w-01J2EKZEVPA6452PKBGH6J05BH","pid":1213,"":"downstairs","":"downstairs","session_id":"92ac4f91-35a9-498d-92d0-ba51cd2afcfb"}
2752024-07-10T15:29:51.645Z{"msg":"No downstairs reconciliation required","v":0,"name":"crucible","level":30,"time":"2024-07-10T15:29:51.015151193Z","hostname":"w-01J2EKZEVPA6452PKBGH6J05BH","pid":1213,"session_id":"92ac4f91-35a9-498d-92d0-ba51cd2afcfb"}
2762024-07-10T15:29:51.645Z{"msg":"Transition from WaitQuorum to Active","v":0,"name":"crucible","level":30,"time":"2024-07-10T15:29:51.015163422Z","hostname":"w-01J2EKZEVPA6452PKBGH6J05BH","pid":1213,"client":"0","":"downstairs","session_id":"92ac4f91-35a9-498d-92d0-ba51cd2afcfb"}
2772024-07-10T15:29:51.646Z{"msg":"Transition from WaitQuorum to Active","v":0,"name":"crucible","level":30,"time":"2024-07-10T15:29:51.015183592Z","hostname":"w-01J2EKZEVPA6452PKBGH6J05BH","pid":1213,"client":"1","":"downstairs","session_id":"92ac4f91-35a9-498d-92d0-ba51cd2afcfb"}
2782024-07-10T15:29:51.646Z{"msg":"Transition from WaitQuorum to Active","v":0,"name":"crucible","level":30,"time":"2024-07-10T15:29:51.015197252Z","hostname":"w-01J2EKZEVPA6452PKBGH6J05BH","pid":1213,"client":"2","":"downstairs","session_id":"92ac4f91-35a9-498d-92d0-ba51cd2afcfb"}
2792024-07-10T15:29:51.646Z{"msg":"All required reconciliation work is completed","v":0,"name":"crucible","level":30,"time":"2024-07-10T15:29:51.015210892Z","hostname":"w-01J2EKZEVPA6452PKBGH6J05BH","pid":1213,"session_id":"92ac4f91-35a9-498d-92d0-ba51cd2afcfb"}
2802024-07-10T15:29:51.646Z{"msg":"Set Downstairs and Upstairs active after reconciliation","v":0,"name":"crucible","level":30,"time":"2024-07-10T15:29:51.015223812Z","hostname":"w-01J2EKZEVPA6452PKBGH6J05BH","pid":1213,"session_id":"92ac4f91-35a9-498d-92d0-ba51cd2afcfb"}
2812024-07-10T15:29:51.646Z{"msg":"a2c676d0-8e9d-4561-880a-be498e7477a7 is now active with session: 92ac4f91-35a9-498d-92d0-ba51cd2afcfb","v":0,"name":"crucible","level":30,"time":"2024-07-10T15:29:51.015236662Z","hostname":"w-01J2EKZEVPA6452PKBGH6J05BH","pid":1213,"session_id":"92ac4f91-35a9-498d-92d0-ba51cd2afcfb"}
2822024-07-10T15:29:51.646Z{"msg":"Set Active after no reconciliation","v":0,"name":"crucible","level":30,"time":"2024-07-10T15:29:51.015255672Z","hostname":"w-01J2EKZEVPA6452PKBGH6J05BH","pid":1213,"session_id":"92ac4f91-35a9-498d-92d0-ba51cd2afcfb"}
2832024-07-10T15:29:51.646Z{"msg":"The guest has finished waiting for activation with:32","v":0,"name":"crucible","level":30,"time":"2024-07-10T15:29:51.015268272Z","hostname":"w-01J2EKZEVPA6452PKBGH6J05BH","pid":1213}
2842024-07-10T15:29:51.646ZLoading write count information from file "/var/tmp/test_up/verify_file"
2852024-07-10T15:29:51.646ZRun Repair workload
2862024-07-10T15:29:51.646Z01/10 Write block 40 len 16384 data: 2 2 2 2
2872024-07-10T15:29:51.646Z02/10 Read block 41 len 16384
2882024-07-10T15:29:51.646Z03/10 Read block 1 len 28672
2892024-07-10T15:29:51.649Z04/10 Read block 37 len 12288
2902024-07-10T15:29:51.652Z05/10 Write block 36 len 36864 data: 2 2 2 2 3 3 3 3 2
2912024-07-10T15:29:51.656Z06/10 Read block 8 len 8192
2922024-07-10T15:29:51.660Z07/10 Write block 44 len 16384 data: 3 2 2 2
2932024-07-10T15:29:51.668Z08/10 Read block 7 len 4096
2942024-07-10T15:29:51.685Z09/10 Write block 7 len 12288 data: 2 2 2
2952024-07-10T15:29:51.685Z10/10 Read block 37 len 36864
2962024-07-10T15:29:51.709Z----------------------------------------------------------------
2972024-07-10T15:29:51.710Z Crucible gen:32 GIO:true work queues: Upstairs:0 downstairs:10
2982024-07-10T15:29:51.710ZStates: Active Active Active
2992024-07-10T15:29:51.710ZGW_ID ACK DSID TYPE BKS/EXT DS:0 DS:1 DS:2 REPLAY
3002024-07-10T15:29:51.710Z 1 Acked 1000 Write 4 Done Done Done false
3012024-07-10T15:29:51.710Z 2 Acked 1001 Read 4 Done Done Done false
3022024-07-10T15:29:51.710Z 3 Acked 1002 Read 7 Done Done Done false
3032024-07-10T15:29:51.715Z 4 Acked 1003 Read 3 Done Done Done false
3042024-07-10T15:29:51.715Z 5 Acked 1004 Write 9 Done Done Done false
3052024-07-10T15:29:51.715Z 6 Acked 1005 Read 2 Done Done Done false
3062024-07-10T15:29:51.715Z 7 Acked 1006 Write 4 Done Done Done false
3072024-07-10T15:29:51.715Z 8 Acked 1007 Read 1 Done Done Done false
3082024-07-10T15:29:51.715Z 9 Acked 1008 Write 3 Done Done Done false
3092024-07-10T15:29:51.715Z 10 Acked 1009 Read 9 Done Sent Done false
3102024-07-10T15:29:51.716Z STATES DS:0 DS:1 DS:2 TOTAL
3112024-07-10T15:29:51.716Z New 0 0 0 0
3122024-07-10T15:29:51.716Z Sent 0 1 0 1
3132024-07-10T15:29:51.716Z Done 10 9 10 29
3142024-07-10T15:29:51.716Z Skipped 0 0 0 0
3152024-07-10T15:29:51.716Z Error 0 0 0 0
3162024-07-10T15:29:51.716ZLast Flush: 0 0 0
3172024-07-10T15:29:51.716ZDownstairs last five completed:
3182024-07-10T15:29:51.716ZUpstairs last five completed: 10 9 8 7 6
3192024-07-10T15:29:51.717Z{"msg":"Guest handle has been dropped","v":0,"name":"crucible","level":40,"time":"2024-07-10T15:29:51.057405385Z","hostname":"w-01J2EKZEVPA6452PKBGH6J05BH","pid":1213}
3202024-07-10T15:29:51.717ZWrote out file "/var/tmp/test_up/verify_file"
3212024-07-10T15:29:51.717ZRepair part 1 passed
3222024-07-10T15:29:51.717Z
3232024-07-10T15:29:51.718ZKill the current downstairs
3242024-07-10T15:29:51.799Zrm -rf /var/tmp/test_up/8830
3252024-07-10T15:29:51.799ZNow put back the original so we have a mismatch
3262024-07-10T15:29:51.799Zmv /var/tmp/test_up/previous /var/tmp/test_up/8830
3272024-07-10T15:29:51.845ZRestart downstairs with old directory
3282024-07-10T15:29:51.861Z/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
3292024-07-10T15:29:51.876ZEXT BLOCKS GEN0 GEN1 GEN2 FL0 FL1 FL2 D0 D1 D2 DIFF
3302024-07-10T15:29:51.876Z 0 000-009 31 31 31 1657 1657 1657 T T F <---
3312024-07-10T15:29:51.876Z 1 010-019 31 31 31 1657 1657 1657 F F F
3322024-07-10T15:29:51.876Z 2 020-029 31 31 31 1657 1657 1657 F F F
3332024-07-10T15:29:51.876Z 3 030-039 31 31 31 1657 1657 1657 T T F <---
3342024-07-10T15:29:51.876Z 4 040-049 31 31 31 1657 1657 1657 T T F <---
3352024-07-10T15:29:51.876ZMax gen: 31, Max flush: 1657
3362024-07-10T15:29:51.876ZError: Difference in extent metadata found!
3372024-07-10T15:29:51.876Zdump test found error as expected
3382024-07-10T15:29:51.877Z
3392024-07-10T15:29:51.877Z
3402024-07-10T15:29:51.877Z/var/tmp/bins/crutest deactivate --range -g 33 -q --key 5adfxo8TdR2DA0dgdB9zHHj0JZt5b7nBJdIde9AVmzQ= -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
3412024-07-10T15:29:51.899Z{"msg":"Upstairs starts","v":0,"name":"crucible","level":30,"time":"2024-07-10T15:29:51.251118179Z","hostname":"w-01J2EKZEVPA6452PKBGH6J05BH","pid":1220}
3422024-07-10T15:29:51.900Z{"msg":"Crucible Version: BuildInfo {\n version: \"0.0.1\",\n git_sha: \"6b815a43cfc10bcc32090edef97cce2a57967dc5\",\n git_commit_timestamp: \"2024-07-10T15:11:32.000000000Z\",\n git_branch: \"renovate/nbd-0.x\",\n rustc_semver: \"1.76.0\",\n rustc_channel: \"stable\",\n rustc_host_triple: \"x86_64-unknown-illumos\",\n rustc_commit_sha: \"07dca489ac2d933c78d3c5158e3f43beefeb02ce\",\n cargo_triple: \"x86_64-unknown-illumos\",\n debug: true,\n opt_level: 0,\n}","v":0,"name":"crucible","level":30,"time":"2024-07-10T15:29:51.251360557Z","hostname":"w-01J2EKZEVPA6452PKBGH6J05BH","pid":1220}
3432024-07-10T15:29:51.900Z{"msg":"Upstairs <-> Downstairs Message Version: 8","v":0,"name":"crucible","level":30,"time":"2024-07-10T15:29:51.251388616Z","hostname":"w-01J2EKZEVPA6452PKBGH6J05BH","pid":1220}
3442024-07-10T15:29:51.900Z{"msg":"Crucible 5009db20-421b-48e6-8ffa-36117ff0b3a4 has session id: 409adfbc-b612-4139-a33e-13a64ab56962","v":0,"name":"crucible","level":30,"time":"2024-07-10T15:29:51.251900852Z","hostname":"w-01J2EKZEVPA6452PKBGH6J05BH","pid":1220,"session_id":"409adfbc-b612-4139-a33e-13a64ab56962"}
3452024-07-10T15:29:51.900Z{"msg":"Upstairs opts: Upstairs UUID: 5009db20-421b-48e6-8ffa-36117ff0b3a4, 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-07-10T15:29:51.251945672Z","hostname":"w-01J2EKZEVPA6452PKBGH6J05BH","pid":1220,"session_id":"409adfbc-b612-4139-a33e-13a64ab56962"}
3462024-07-10T15:29:51.900Z{"msg":"Crucible stats registered with UUID: 5009db20-421b-48e6-8ffa-36117ff0b3a4","v":0,"name":"crucible","level":30,"time":"2024-07-10T15:29:51.252002411Z","hostname":"w-01J2EKZEVPA6452PKBGH6J05BH","pid":1220,"session_id":"409adfbc-b612-4139-a33e-13a64ab56962"}
3472024-07-10T15:29:51.901ZCrucible runtime is spawned
3482024-07-10T15:29:51.901Z{"msg":"The guest has requested activation with gen:33","v":0,"name":"crucible","level":30,"time":"2024-07-10T15:29:51.252276109Z","hostname":"w-01J2EKZEVPA6452PKBGH6J05BH","pid":1220}
3492024-07-10T15:29:51.901Z{"msg":"5009db20-421b-48e6-8ffa-36117ff0b3a4 active request set","v":0,"name":"crucible","level":30,"time":"2024-07-10T15:29:51.252372978Z","hostname":"w-01J2EKZEVPA6452PKBGH6J05BH","pid":1220,"session_id":"409adfbc-b612-4139-a33e-13a64ab56962"}
3502024-07-10T15:29:51.901Z{"msg":"sending connect oneshot to client","v":0,"name":"crucible","level":30,"time":"2024-07-10T15:29:51.252391918Z","hostname":"w-01J2EKZEVPA6452PKBGH6J05BH","pid":1220,"client":"0","":"downstairs","session_id":"409adfbc-b612-4139-a33e-13a64ab56962"}
3512024-07-10T15:29:51.901Z{"msg":"client set_active_request while in New; waiting...","v":0,"name":"crucible","level":30,"time":"2024-07-10T15:29:51.252407348Z","hostname":"w-01J2EKZEVPA6452PKBGH6J05BH","pid":1220,"client":"0","":"downstairs","session_id":"409adfbc-b612-4139-a33e-13a64ab56962"}
3522024-07-10T15:29:51.901Z{"msg":"sending connect oneshot to client","v":0,"name":"crucible","level":30,"time":"2024-07-10T15:29:51.252421428Z","hostname":"w-01J2EKZEVPA6452PKBGH6J05BH","pid":1220,"client":"1","":"downstairs","session_id":"409adfbc-b612-4139-a33e-13a64ab56962"}
3532024-07-10T15:29:51.901Z{"msg":"client set_active_request while in New; waiting...","v":0,"name":"crucible","level":30,"time":"2024-07-10T15:29:51.252435348Z","hostname":"w-01J2EKZEVPA6452PKBGH6J05BH","pid":1220,"client":"1","":"downstairs","session_id":"409adfbc-b612-4139-a33e-13a64ab56962"}
3542024-07-10T15:29:51.901Z{"msg":"sending connect oneshot to client","v":0,"name":"crucible","level":30,"time":"2024-07-10T15:29:51.252449638Z","hostname":"w-01J2EKZEVPA6452PKBGH6J05BH","pid":1220,"client":"2","":"downstairs","session_id":"409adfbc-b612-4139-a33e-13a64ab56962"}
3552024-07-10T15:29:51.901Z{"msg":"client set_active_request while in New; waiting...","v":0,"name":"crucible","level":30,"time":"2024-07-10T15:29:51.252463887Z","hostname":"w-01J2EKZEVPA6452PKBGH6J05BH","pid":1220,"client":"2","":"downstairs","session_id":"409adfbc-b612-4139-a33e-13a64ab56962"}
3562024-07-10T15:29:51.901Z{"msg":"connecting to 127.0.0.1:8830","v":0,"name":"crucible","level":30,"time":"2024-07-10T15:29:51.252552457Z","hostname":"w-01J2EKZEVPA6452PKBGH6J05BH","pid":1220,"":"io task","client":"2","":"downstairs","session_id":"409adfbc-b612-4139-a33e-13a64ab56962"}
3572024-07-10T15:29:51.901Z{"msg":"connecting to 127.0.0.1:8820","v":0,"name":"crucible","level":30,"time":"2024-07-10T15:29:51.252579357Z","hostname":"w-01J2EKZEVPA6452PKBGH6J05BH","pid":1220,"":"io task","client":"1","":"downstairs","session_id":"409adfbc-b612-4139-a33e-13a64ab56962"}
3582024-07-10T15:29:51.902Z{"msg":"connecting to 127.0.0.1:8810","v":0,"name":"crucible","level":30,"time":"2024-07-10T15:29:51.252593997Z","hostname":"w-01J2EKZEVPA6452PKBGH6J05BH","pid":1220,"":"io task","client":"0","":"downstairs","session_id":"409adfbc-b612-4139-a33e-13a64ab56962"}
3592024-07-10T15:29:51.902Z{"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-07-10T15:29:51.252789935Z","hostname":"w-01J2EKZEVPA6452PKBGH6J05BH","pid":1220,"":"io task","client":"2","":"downstairs","session_id":"409adfbc-b612-4139-a33e-13a64ab56962"}
3602024-07-10T15:29:51.902Z{"msg":"ds_connection connected from Ok(127.0.0.1:47063)","v":0,"name":"crucible","level":30,"time":"2024-07-10T15:29:51.252837144Z","hostname":"w-01J2EKZEVPA6452PKBGH6J05BH","pid":1220,"":"io task","client":"1","":"downstairs","session_id":"409adfbc-b612-4139-a33e-13a64ab56962"}
3612024-07-10T15:29:51.902Z{"msg":"client task is sending Done(ConnectionFailed(Os { code: 146, kind: ConnectionRefused, message: \"Connection refused\" }))","v":0,"name":"crucible","level":40,"time":"2024-07-10T15:29:51.252868264Z","hostname":"w-01J2EKZEVPA6452PKBGH6J05BH","pid":1220,"":"io task","client":"2","":"downstairs","session_id":"409adfbc-b612-4139-a33e-13a64ab56962"}
3622024-07-10T15:29:51.902Z{"msg":"ds_connection connected from Ok(127.0.0.1:57066)","v":0,"name":"crucible","level":30,"time":"2024-07-10T15:29:51.252895944Z","hostname":"w-01J2EKZEVPA6452PKBGH6J05BH","pid":1220,"":"io task","client":"0","":"downstairs","session_id":"409adfbc-b612-4139-a33e-13a64ab56962"}
3632024-07-10T15:29:51.902Z{"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-07-10T15:29:51.252925294Z","hostname":"w-01J2EKZEVPA6452PKBGH6J05BH","pid":1220,"session_id":"409adfbc-b612-4139-a33e-13a64ab56962"}
3642024-07-10T15:29:51.902Z{"msg":"Gone missing, transition from New to Disconnected","v":0,"name":"crucible","level":30,"time":"2024-07-10T15:29:51.252986683Z","hostname":"w-01J2EKZEVPA6452PKBGH6J05BH","pid":1220,"client":"2","":"downstairs","session_id":"409adfbc-b612-4139-a33e-13a64ab56962"}
3652024-07-10T15:29:51.902Z{"msg":"Disconnected -> New","v":0,"name":"crucible","level":30,"time":"2024-07-10T15:29:51.253043223Z","hostname":"w-01J2EKZEVPA6452PKBGH6J05BH","pid":1220,"client":"2","":"downstairs","session_id":"409adfbc-b612-4139-a33e-13a64ab56962"}
3662024-07-10T15:29:51.902Z{"msg":"client task is exiting","v":0,"name":"crucible","level":30,"time":"2024-07-10T15:29:51.253075462Z","hostname":"w-01J2EKZEVPA6452PKBGH6J05BH","pid":1220,"":"io task","client":"2","":"downstairs","session_id":"409adfbc-b612-4139-a33e-13a64ab56962"}
3672024-07-10T15:29:51.902Z{"msg":"ds_transition from New to WaitActive","v":0,"name":"crucible","level":30,"time":"2024-07-10T15:29:51.253457849Z","hostname":"w-01J2EKZEVPA6452PKBGH6J05BH","pid":1220,"client":"0","":"downstairs","session_id":"409adfbc-b612-4139-a33e-13a64ab56962"}
3682024-07-10T15:29:51.903Z{"msg":"[0] Transition from New to WaitActive","v":0,"name":"crucible","level":30,"time":"2024-07-10T15:29:51.253490619Z","hostname":"w-01J2EKZEVPA6452PKBGH6J05BH","pid":1220,"client":"0","":"downstairs","session_id":"409adfbc-b612-4139-a33e-13a64ab56962"}
3692024-07-10T15:29:51.903Z{"msg":"ds_transition from New to WaitActive","v":0,"name":"crucible","level":30,"time":"2024-07-10T15:29:51.253505539Z","hostname":"w-01J2EKZEVPA6452PKBGH6J05BH","pid":1220,"client":"1","":"downstairs","session_id":"409adfbc-b612-4139-a33e-13a64ab56962"}
3702024-07-10T15:29:51.903Z{"msg":"[1] Transition from New to WaitActive","v":0,"name":"crucible","level":30,"time":"2024-07-10T15:29:51.253519319Z","hostname":"w-01J2EKZEVPA6452PKBGH6J05BH","pid":1220,"client":"1","":"downstairs","session_id":"409adfbc-b612-4139-a33e-13a64ab56962"}
3712024-07-10T15:29:51.903Z{"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-07-10T15:29:51.254103184Z","hostname":"w-01J2EKZEVPA6452PKBGH6J05BH","pid":1220,"client":"1","":"downstairs","session_id":"409adfbc-b612-4139-a33e-13a64ab56962"}
3722024-07-10T15:29:51.903Z{"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-07-10T15:29:51.254138794Z","hostname":"w-01J2EKZEVPA6452PKBGH6J05BH","pid":1220,"client":"0","":"downstairs","session_id":"409adfbc-b612-4139-a33e-13a64ab56962"}
3732024-07-10T15:29:51.903Z{"msg":"ds_transition from WaitActive to WaitQuorum","v":0,"name":"crucible","level":30,"time":"2024-07-10T15:29:51.254504741Z","hostname":"w-01J2EKZEVPA6452PKBGH6J05BH","pid":1220,"client":"1","":"downstairs","session_id":"409adfbc-b612-4139-a33e-13a64ab56962"}
3742024-07-10T15:29:51.903Z{"msg":"[1] Transition from WaitActive to WaitQuorum","v":0,"name":"crucible","level":30,"time":"2024-07-10T15:29:51.25457546Z","hostname":"w-01J2EKZEVPA6452PKBGH6J05BH","pid":1220,"client":"1","":"downstairs","session_id":"409adfbc-b612-4139-a33e-13a64ab56962"}
3752024-07-10T15:29:51.903Z{"msg":"Waiting for more clients to be ready","v":0,"name":"crucible","level":30,"time":"2024-07-10T15:29:51.25461012Z","hostname":"w-01J2EKZEVPA6452PKBGH6J05BH","pid":1220,"session_id":"409adfbc-b612-4139-a33e-13a64ab56962"}
3762024-07-10T15:29:51.903Z{"msg":"ds_transition from WaitActive to WaitQuorum","v":0,"name":"crucible","level":30,"time":"2024-07-10T15:29:51.25462493Z","hostname":"w-01J2EKZEVPA6452PKBGH6J05BH","pid":1220,"client":"0","":"downstairs","session_id":"409adfbc-b612-4139-a33e-13a64ab56962"}
3772024-07-10T15:29:51.903Z{"msg":"[0] Transition from WaitActive to WaitQuorum","v":0,"name":"crucible","level":30,"time":"2024-07-10T15:29:51.25464552Z","hostname":"w-01J2EKZEVPA6452PKBGH6J05BH","pid":1220,"client":"0","":"downstairs","session_id":"409adfbc-b612-4139-a33e-13a64ab56962"}
3782024-07-10T15:29:51.903Z{"msg":"Waiting for more clients to be ready","v":0,"name":"crucible","level":30,"time":"2024-07-10T15:29:51.254659329Z","hostname":"w-01J2EKZEVPA6452PKBGH6J05BH","pid":1220,"session_id":"409adfbc-b612-4139-a33e-13a64ab56962"}
3792024-07-10T15:30:01.873Z{"msg":"connecting to 127.0.0.1:8830","v":0,"name":"crucible","level":30,"time":"2024-07-10T15:30:01.253328593Z","hostname":"w-01J2EKZEVPA6452PKBGH6J05BH","pid":1220,"":"io task","client":"2","":"downstairs","session_id":"409adfbc-b612-4139-a33e-13a64ab56962"}
3802024-07-10T15:30:01.873Z{"msg":"ds_connection connected from Ok(127.0.0.1:60731)","v":0,"name":"crucible","level":30,"time":"2024-07-10T15:30:01.253481502Z","hostname":"w-01J2EKZEVPA6452PKBGH6J05BH","pid":1220,"":"io task","client":"2","":"downstairs","session_id":"409adfbc-b612-4139-a33e-13a64ab56962"}
3812024-07-10T15:30:01.876Z{"msg":"ds_transition from New to WaitActive","v":0,"name":"crucible","level":30,"time":"2024-07-10T15:30:01.254643153Z","hostname":"w-01J2EKZEVPA6452PKBGH6J05BH","pid":1220,"client":"2","":"downstairs","session_id":"409adfbc-b612-4139-a33e-13a64ab56962"}
3822024-07-10T15:30:01.876Z{"msg":"[2] Transition from New to WaitActive","v":0,"name":"crucible","level":30,"time":"2024-07-10T15:30:01.254699742Z","hostname":"w-01J2EKZEVPA6452PKBGH6J05BH","pid":1220,"client":"2","":"downstairs","session_id":"409adfbc-b612-4139-a33e-13a64ab56962"}
3832024-07-10T15:30:01.876Z{"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-07-10T15:30:01.255195138Z","hostname":"w-01J2EKZEVPA6452PKBGH6J05BH","pid":1220,"client":"2","":"downstairs","session_id":"409adfbc-b612-4139-a33e-13a64ab56962"}
3842024-07-10T15:30:01.876Z{"msg":"ds_transition from WaitActive to WaitQuorum","v":0,"name":"crucible","level":30,"time":"2024-07-10T15:30:01.255564855Z","hostname":"w-01J2EKZEVPA6452PKBGH6J05BH","pid":1220,"client":"2","":"downstairs","session_id":"409adfbc-b612-4139-a33e-13a64ab56962"}
3852024-07-10T15:30:01.876Z{"msg":"[2] Transition from WaitActive to WaitQuorum","v":0,"name":"crucible","level":30,"time":"2024-07-10T15:30:01.255611305Z","hostname":"w-01J2EKZEVPA6452PKBGH6J05BH","pid":1220,"client":"2","":"downstairs","session_id":"409adfbc-b612-4139-a33e-13a64ab56962"}
3862024-07-10T15:30:01.876Z{"msg":"[0]R flush_numbers: [1657, 1657, 1657, 1657, 1657]","v":0,"name":"crucible","level":30,"time":"2024-07-10T15:30:01.255637814Z","hostname":"w-01J2EKZEVPA6452PKBGH6J05BH","pid":1220,"":"downstairs","":"downstairs","session_id":"409adfbc-b612-4139-a33e-13a64ab56962"}
3872024-07-10T15:30:01.876Z{"msg":"[0]R generation: [31, 31, 31, 31, 31]","v":0,"name":"crucible","level":30,"time":"2024-07-10T15:30:01.255672764Z","hostname":"w-01J2EKZEVPA6452PKBGH6J05BH","pid":1220,"":"downstairs","":"downstairs","session_id":"409adfbc-b612-4139-a33e-13a64ab56962"}
3882024-07-10T15:30:01.876Z{"msg":"[0]R dirty: [true, false, false, true, true]","v":0,"name":"crucible","level":30,"time":"2024-07-10T15:30:01.255707254Z","hostname":"w-01J2EKZEVPA6452PKBGH6J05BH","pid":1220,"":"downstairs","":"downstairs","session_id":"409adfbc-b612-4139-a33e-13a64ab56962"}
3892024-07-10T15:30:01.876Z{"msg":"[1]R flush_numbers: [1657, 1657, 1657, 1657, 1657]","v":0,"name":"crucible","level":30,"time":"2024-07-10T15:30:01.255740553Z","hostname":"w-01J2EKZEVPA6452PKBGH6J05BH","pid":1220,"":"downstairs","":"downstairs","session_id":"409adfbc-b612-4139-a33e-13a64ab56962"}
3902024-07-10T15:30:01.876Z{"msg":"[1]R generation: [31, 31, 31, 31, 31]","v":0,"name":"crucible","level":30,"time":"2024-07-10T15:30:01.255778193Z","hostname":"w-01J2EKZEVPA6452PKBGH6J05BH","pid":1220,"":"downstairs","":"downstairs","session_id":"409adfbc-b612-4139-a33e-13a64ab56962"}
3912024-07-10T15:30:01.876Z{"msg":"[1]R dirty: [true, false, false, true, true]","v":0,"name":"crucible","level":30,"time":"2024-07-10T15:30:01.255813123Z","hostname":"w-01J2EKZEVPA6452PKBGH6J05BH","pid":1220,"":"downstairs","":"downstairs","session_id":"409adfbc-b612-4139-a33e-13a64ab56962"}
3922024-07-10T15:30:01.876Z{"msg":"[2]R flush_numbers: [1657, 1657, 1657, 1657, 1657]","v":0,"name":"crucible","level":30,"time":"2024-07-10T15:30:01.255848152Z","hostname":"w-01J2EKZEVPA6452PKBGH6J05BH","pid":1220,"":"downstairs","":"downstairs","session_id":"409adfbc-b612-4139-a33e-13a64ab56962"}
3932024-07-10T15:30:01.876Z{"msg":"[2]R generation: [31, 31, 31, 31, 31]","v":0,"name":"crucible","level":30,"time":"2024-07-10T15:30:01.255872272Z","hostname":"w-01J2EKZEVPA6452PKBGH6J05BH","pid":1220,"":"downstairs","":"downstairs","session_id":"409adfbc-b612-4139-a33e-13a64ab56962"}
3942024-07-10T15:30:01.876Z{"msg":"[2]R dirty: [false, false, false, false, false]","v":0,"name":"crucible","level":30,"time":"2024-07-10T15:30:01.255905412Z","hostname":"w-01J2EKZEVPA6452PKBGH6J05BH","pid":1220,"":"downstairs","":"downstairs","session_id":"409adfbc-b612-4139-a33e-13a64ab56962"}
3952024-07-10T15:30:01.876Z{"msg":"Max found gen is 32","v":0,"name":"crucible","level":30,"time":"2024-07-10T15:30:01.255939372Z","hostname":"w-01J2EKZEVPA6452PKBGH6J05BH","pid":1220,"":"downstairs","":"downstairs","session_id":"409adfbc-b612-4139-a33e-13a64ab56962"}
3962024-07-10T15:30:01.876Z{"msg":"Generation requested: 33 >= found:32","v":0,"name":"crucible","level":30,"time":"2024-07-10T15:30:01.255971391Z","hostname":"w-01J2EKZEVPA6452PKBGH6J05BH","pid":1220,"":"downstairs","":"downstairs","session_id":"409adfbc-b612-4139-a33e-13a64ab56962"}
3972024-07-10T15:30:01.876Z{"msg":"Next flush: 1658","v":0,"name":"crucible","level":30,"time":"2024-07-10T15:30:01.255994861Z","hostname":"w-01J2EKZEVPA6452PKBGH6J05BH","pid":1220,"":"downstairs","":"downstairs","session_id":"409adfbc-b612-4139-a33e-13a64ab56962"}
3982024-07-10T15:30:01.876Z{"msg":"Extents 0 dirty","v":0,"name":"crucible","level":30,"time":"2024-07-10T15:30:01.256031021Z","hostname":"w-01J2EKZEVPA6452PKBGH6J05BH","pid":1220,"":"mend","":"downstairs","":"downstairs","session_id":"409adfbc-b612-4139-a33e-13a64ab56962"}
3992024-07-10T15:30:01.876Z{"msg":"First source client ID for extent 0","v":0,"name":"crucible","level":30,"time":"2024-07-10T15:30:01.256071881Z","hostname":"w-01J2EKZEVPA6452PKBGH6J05BH","pid":1220,"mrl":"dirty","":"mend","":"downstairs","":"downstairs","session_id":"409adfbc-b612-4139-a33e-13a64ab56962"}
4002024-07-10T15:30:01.876Z{"msg":"extent:0 gens: 31 31 31","v":0,"name":"crucible","level":30,"time":"2024-07-10T15:30:01.25611278Z","hostname":"w-01J2EKZEVPA6452PKBGH6J05BH","pid":1220,"mrl":"dirty","":"mend","":"downstairs","":"downstairs","session_id":"409adfbc-b612-4139-a33e-13a64ab56962"}
4012024-07-10T15:30:01.876Z{"msg":"extent:0 flush: 1657 1657 1657 scs: [ClientId(0), ClientId(1), ClientId(2)]","v":0,"name":"crucible","level":30,"time":"2024-07-10T15:30:01.25615072Z","hostname":"w-01J2EKZEVPA6452PKBGH6J05BH","pid":1220,"mrl":"dirty","":"mend","":"downstairs","":"downstairs","session_id":"409adfbc-b612-4139-a33e-13a64ab56962"}
4022024-07-10T15:30:01.880Z{"msg":"max_flush now has: [ClientId(0), ClientId(1), ClientId(2)]","v":0,"name":"crucible","level":30,"time":"2024-07-10T15:30:01.25616874Z","hostname":"w-01J2EKZEVPA6452PKBGH6J05BH","pid":1220,"mrl":"dirty","":"mend","":"downstairs","":"downstairs","session_id":"409adfbc-b612-4139-a33e-13a64ab56962"}
4032024-07-10T15:30:01.880Z{"msg":"extent:0 dirty: true true false","v":0,"name":"crucible","level":30,"time":"2024-07-10T15:30:01.25618447Z","hostname":"w-01J2EKZEVPA6452PKBGH6J05BH","pid":1220,"mrl":"dirty","":"mend","":"downstairs","":"downstairs","session_id":"409adfbc-b612-4139-a33e-13a64ab56962"}
4042024-07-10T15:30:01.880Z{"msg":"find dest for source 0 for extent at index 0","v":0,"name":"crucible","level":30,"time":"2024-07-10T15:30:01.25619906Z","hostname":"w-01J2EKZEVPA6452PKBGH6J05BH","pid":1220,"mrl":"dirty","":"mend","":"downstairs","":"downstairs","session_id":"409adfbc-b612-4139-a33e-13a64ab56962"}
4052024-07-10T15:30:01.880Z{"msg":"source 0, add dest 1 source flush","v":0,"name":"crucible","level":30,"time":"2024-07-10T15:30:01.25621332Z","hostname":"w-01J2EKZEVPA6452PKBGH6J05BH","pid":1220,"mrl":"dirty","":"mend","":"downstairs","":"downstairs","session_id":"409adfbc-b612-4139-a33e-13a64ab56962"}
4062024-07-10T15:30:01.880Z{"msg":"source 0, add dest 2 source flush","v":0,"name":"crucible","level":30,"time":"2024-07-10T15:30:01.256228149Z","hostname":"w-01J2EKZEVPA6452PKBGH6J05BH","pid":1220,"mrl":"dirty","":"mend","":"downstairs","":"downstairs","session_id":"409adfbc-b612-4139-a33e-13a64ab56962"}
4072024-07-10T15:30:01.880Z{"msg":"Extents 3 dirty","v":0,"name":"crucible","level":30,"time":"2024-07-10T15:30:01.256243519Z","hostname":"w-01J2EKZEVPA6452PKBGH6J05BH","pid":1220,"":"mend","":"downstairs","":"downstairs","session_id":"409adfbc-b612-4139-a33e-13a64ab56962"}
4082024-07-10T15:30:01.880Z{"msg":"First source client ID for extent 3","v":0,"name":"crucible","level":30,"time":"2024-07-10T15:30:01.256258259Z","hostname":"w-01J2EKZEVPA6452PKBGH6J05BH","pid":1220,"mrl":"dirty","":"mend","":"downstairs","":"downstairs","session_id":"409adfbc-b612-4139-a33e-13a64ab56962"}
4092024-07-10T15:30:01.880Z{"msg":"extent:3 gens: 31 31 31","v":0,"name":"crucible","level":30,"time":"2024-07-10T15:30:01.256272509Z","hostname":"w-01J2EKZEVPA6452PKBGH6J05BH","pid":1220,"mrl":"dirty","":"mend","":"downstairs","":"downstairs","session_id":"409adfbc-b612-4139-a33e-13a64ab56962"}
4102024-07-10T15:30:01.880Z{"msg":"extent:3 flush: 1657 1657 1657 scs: [ClientId(0), ClientId(1), ClientId(2)]","v":0,"name":"crucible","level":30,"time":"2024-07-10T15:30:01.256287349Z","hostname":"w-01J2EKZEVPA6452PKBGH6J05BH","pid":1220,"mrl":"dirty","":"mend","":"downstairs","":"downstairs","session_id":"409adfbc-b612-4139-a33e-13a64ab56962"}
4112024-07-10T15:30:01.880Z{"msg":"max_flush now has: [ClientId(0), ClientId(1), ClientId(2)]","v":0,"name":"crucible","level":30,"time":"2024-07-10T15:30:01.256302409Z","hostname":"w-01J2EKZEVPA6452PKBGH6J05BH","pid":1220,"mrl":"dirty","":"mend","":"downstairs","":"downstairs","session_id":"409adfbc-b612-4139-a33e-13a64ab56962"}
4122024-07-10T15:30:01.880Z{"msg":"extent:3 dirty: true true false","v":0,"name":"crucible","level":30,"time":"2024-07-10T15:30:01.256316679Z","hostname":"w-01J2EKZEVPA6452PKBGH6J05BH","pid":1220,"mrl":"dirty","":"mend","":"downstairs","":"downstairs","session_id":"409adfbc-b612-4139-a33e-13a64ab56962"}
4132024-07-10T15:30:01.880Z{"msg":"find dest for source 0 for extent at index 3","v":0,"name":"crucible","level":30,"time":"2024-07-10T15:30:01.256339568Z","hostname":"w-01J2EKZEVPA6452PKBGH6J05BH","pid":1220,"mrl":"dirty","":"mend","":"downstairs","":"downstairs","session_id":"409adfbc-b612-4139-a33e-13a64ab56962"}
4142024-07-10T15:30:01.880Z{"msg":"source 0, add dest 1 source flush","v":0,"name":"crucible","level":30,"time":"2024-07-10T15:30:01.256354468Z","hostname":"w-01J2EKZEVPA6452PKBGH6J05BH","pid":1220,"mrl":"dirty","":"mend","":"downstairs","":"downstairs","session_id":"409adfbc-b612-4139-a33e-13a64ab56962"}
4152024-07-10T15:30:01.880Z{"msg":"source 0, add dest 2 source flush","v":0,"name":"crucible","level":30,"time":"2024-07-10T15:30:01.256369248Z","hostname":"w-01J2EKZEVPA6452PKBGH6J05BH","pid":1220,"mrl":"dirty","":"mend","":"downstairs","":"downstairs","session_id":"409adfbc-b612-4139-a33e-13a64ab56962"}
4162024-07-10T15:30:01.880Z{"msg":"Extents 4 dirty","v":0,"name":"crucible","level":30,"time":"2024-07-10T15:30:01.256383598Z","hostname":"w-01J2EKZEVPA6452PKBGH6J05BH","pid":1220,"":"mend","":"downstairs","":"downstairs","session_id":"409adfbc-b612-4139-a33e-13a64ab56962"}
4172024-07-10T15:30:01.880Z{"msg":"First source client ID for extent 4","v":0,"name":"crucible","level":30,"time":"2024-07-10T15:30:01.256404158Z","hostname":"w-01J2EKZEVPA6452PKBGH6J05BH","pid":1220,"mrl":"dirty","":"mend","":"downstairs","":"downstairs","session_id":"409adfbc-b612-4139-a33e-13a64ab56962"}
4182024-07-10T15:30:01.880Z{"msg":"extent:4 gens: 31 31 31","v":0,"name":"crucible","level":30,"time":"2024-07-10T15:30:01.256418588Z","hostname":"w-01J2EKZEVPA6452PKBGH6J05BH","pid":1220,"mrl":"dirty","":"mend","":"downstairs","":"downstairs","session_id":"409adfbc-b612-4139-a33e-13a64ab56962"}
4192024-07-10T15:30:01.880Z{"msg":"extent:4 flush: 1657 1657 1657 scs: [ClientId(0), ClientId(1), ClientId(2)]","v":0,"name":"crucible","level":30,"time":"2024-07-10T15:30:01.256439968Z","hostname":"w-01J2EKZEVPA6452PKBGH6J05BH","pid":1220,"mrl":"dirty","":"mend","":"downstairs","":"downstairs","session_id":"409adfbc-b612-4139-a33e-13a64ab56962"}
4202024-07-10T15:30:01.880Z{"msg":"max_flush now has: [ClientId(0), ClientId(1), ClientId(2)]","v":0,"name":"crucible","level":30,"time":"2024-07-10T15:30:01.256455118Z","hostname":"w-01J2EKZEVPA6452PKBGH6J05BH","pid":1220,"mrl":"dirty","":"mend","":"downstairs","":"downstairs","session_id":"409adfbc-b612-4139-a33e-13a64ab56962"}
4212024-07-10T15:30:01.880Z{"msg":"extent:4 dirty: true true false","v":0,"name":"crucible","level":30,"time":"2024-07-10T15:30:01.256475677Z","hostname":"w-01J2EKZEVPA6452PKBGH6J05BH","pid":1220,"mrl":"dirty","":"mend","":"downstairs","":"downstairs","session_id":"409adfbc-b612-4139-a33e-13a64ab56962"}
4222024-07-10T15:30:01.880Z{"msg":"find dest for source 0 for extent at index 4","v":0,"name":"crucible","level":30,"time":"2024-07-10T15:30:01.256490337Z","hostname":"w-01J2EKZEVPA6452PKBGH6J05BH","pid":1220,"mrl":"dirty","":"mend","":"downstairs","":"downstairs","session_id":"409adfbc-b612-4139-a33e-13a64ab56962"}
4232024-07-10T15:30:01.880Z{"msg":"source 0, add dest 1 source flush","v":0,"name":"crucible","level":30,"time":"2024-07-10T15:30:01.256511297Z","hostname":"w-01J2EKZEVPA6452PKBGH6J05BH","pid":1220,"mrl":"dirty","":"mend","":"downstairs","":"downstairs","session_id":"409adfbc-b612-4139-a33e-13a64ab56962"}
4242024-07-10T15:30:01.880Z{"msg":"source 0, add dest 2 source flush","v":0,"name":"crucible","level":30,"time":"2024-07-10T15:30:01.256525947Z","hostname":"w-01J2EKZEVPA6452PKBGH6J05BH","pid":1220,"mrl":"dirty","":"mend","":"downstairs","":"downstairs","session_id":"409adfbc-b612-4139-a33e-13a64ab56962"}
4252024-07-10T15:30:01.881Z{"msg":"Transition from WaitQuorum to Reconcile","v":0,"name":"crucible","level":30,"time":"2024-07-10T15:30:01.256547087Z","hostname":"w-01J2EKZEVPA6452PKBGH6J05BH","pid":1220,"client":"0","":"downstairs","session_id":"409adfbc-b612-4139-a33e-13a64ab56962"}
4262024-07-10T15:30:01.881Z{"msg":"Transition from WaitQuorum to Reconcile","v":0,"name":"crucible","level":30,"time":"2024-07-10T15:30:01.256561147Z","hostname":"w-01J2EKZEVPA6452PKBGH6J05BH","pid":1220,"client":"1","":"downstairs","session_id":"409adfbc-b612-4139-a33e-13a64ab56962"}
4272024-07-10T15:30:01.881Z{"msg":"Transition from WaitQuorum to Reconcile","v":0,"name":"crucible","level":30,"time":"2024-07-10T15:30:01.256580946Z","hostname":"w-01J2EKZEVPA6452PKBGH6J05BH","pid":1220,"client":"2","":"downstairs","session_id":"409adfbc-b612-4139-a33e-13a64ab56962"}
4282024-07-10T15:30:01.881Z{"msg":"starting reconciliation c2595893-54ef-4e85-9ba0-f51d093ba1dc: found 3 extents that need repair","v":0,"name":"crucible","level":30,"time":"2024-07-10T15:30:01.256595316Z","hostname":"w-01J2EKZEVPA6452PKBGH6J05BH","pid":1220,"":"downstairs","":"downstairs","session_id":"409adfbc-b612-4139-a33e-13a64ab56962"}
4292024-07-10T15:30:01.881Z{"msg":"Full repair list: {ExtentId(3): ExtentFix { source: ClientId(0), dest: [ClientId(1), ClientId(2)] }, ExtentId(4): ExtentFix { source: ClientId(0), dest: [ClientId(1), ClientId(2)] }, ExtentId(0): ExtentFix { source: ClientId(0), dest: [ClientId(1), ClientId(2)] }}","v":0,"name":"crucible","level":30,"time":"2024-07-10T15:30:01.256618106Z","hostname":"w-01J2EKZEVPA6452PKBGH6J05BH","pid":1220,"":"downstairs","":"downstairs","session_id":"409adfbc-b612-4139-a33e-13a64ab56962"}
4302024-07-10T15:30:01.881Z{"msg":"Task list: [ReconcileIO { id: ReconciliationId(0), op: ExtentFlush { repair_id: ReconciliationId(0), extent_id: ExtentId(3), client_id: ClientId(0), flush_number: 1658, gen_number: 32 }, state: ClientData([New, New, New]) }, ReconcileIO { id: ReconciliationId(1), op: ExtentClose { repair_id: ReconciliationId(1), extent_id: ExtentId(3) }, state: ClientData([New, New, New]) }, ReconcileIO { id: ReconciliationId(2), op: ExtentRepair { repair_id: ReconciliationId(2), extent_id: ExtentId(3), source_client_id: ClientId(0), source_repair_address: 0.0.0.0:12810, dest_clients: [ClientId(1), ClientId(2)] }, state: ClientData([New, New, New]) }, ReconcileIO { id: ReconciliationId(3), op: ExtentReopen { repair_id: ReconciliationId(3), extent_id: ExtentId(3) }, state: ClientData([New, New, New]) }, ReconcileIO { id: ReconciliationId(4), op: ExtentFlush { repair_id: ReconciliationId(4), extent_id: ExtentId(4), client_id: ClientId(0), flush_number: 1658, gen_number: 32 }, state: ClientData([New, New, New]) }, ReconcileIO { id: ReconciliationId(5), op: ExtentClose { repair_id: ReconciliationId(5), extent_id: ExtentId(4) }, state: ClientData([New, New, New]) }, ReconcileIO { id: ReconciliationId(6), op: ExtentRepair { repair_id: ReconciliationId(6), extent_id: ExtentId(4), source_client_id: ClientId(0), source_repair_address: 0.0.0.0:12810, dest_clients: [ClientId(1), ClientId(2)] }, state: ClientData([New, New, New]) }, ReconcileIO { id: ReconciliationId(7), op: ExtentReopen { repair_id: ReconciliationId(7), extent_id: ExtentId(4) }, state: ClientData([New, New, New]) }, ReconcileIO { id: ReconciliationId(8), op: ExtentFlush { repair_id: ReconciliationId(8), extent_id: ExtentId(0), client_id: ClientId(0), flush_number: 1658, gen_number: 32 }, state: ClientData([New, New, New]) }, ReconcileIO { id: ReconciliationId(9), op: ExtentClose { repair_id: ReconciliationId(9), extent_id: ExtentId(0) }, state: ClientData([New, New, New]) }, ReconcileIO { id: ReconciliationId(10), op: ExtentRepair { repair_id: ReconciliationId(10), extent_id: ExtentId(0), source_client_id: ClientId(0), source_repair_address: 0.0.0.0:12810, dest_clients: [ClientId(1), ClientId(2)] }, state: ClientData([New, New, New]) }, ReconcileIO { id: ReconciliationId(11), op: ExtentReopen { repair_id: ReconciliationId(11), extent_id: ExtentId(0) }, state: ClientData([New, New, New]) }]","v":0,"name":"crucible","level":30,"time":"2024-07-10T15:30:01.256672766Z","hostname":"w-01J2EKZEVPA6452PKBGH6J05BH","pid":1220,"":"downstairs","":"downstairs","session_id":"409adfbc-b612-4139-a33e-13a64ab56962"}
4312024-07-10T15:30:01.881Z{"msg":"sending reconcile request ReconciliationId(2)","v":0,"name":"crucible","level":30,"time":"2024-07-10T15:30:01.257826106Z","hostname":"w-01J2EKZEVPA6452PKBGH6J05BH","pid":1220,"client":"1","":"downstairs","session_id":"409adfbc-b612-4139-a33e-13a64ab56962"}
4322024-07-10T15:30:01.881Z{"msg":"sending reconcile request ReconciliationId(2)","v":0,"name":"crucible","level":30,"time":"2024-07-10T15:30:01.257873016Z","hostname":"w-01J2EKZEVPA6452PKBGH6J05BH","pid":1220,"client":"2","":"downstairs","session_id":"409adfbc-b612-4139-a33e-13a64ab56962"}
4332024-07-10T15:30:01.893Z{"msg":"sending reconcile request ReconciliationId(6)","v":0,"name":"crucible","level":30,"time":"2024-07-10T15:30:01.273925954Z","hostname":"w-01J2EKZEVPA6452PKBGH6J05BH","pid":1220,"client":"1","":"downstairs","session_id":"409adfbc-b612-4139-a33e-13a64ab56962"}
4342024-07-10T15:30:01.893Z{"msg":"sending reconcile request ReconciliationId(6)","v":0,"name":"crucible","level":30,"time":"2024-07-10T15:30:01.273968523Z","hostname":"w-01J2EKZEVPA6452PKBGH6J05BH","pid":1220,"client":"2","":"downstairs","session_id":"409adfbc-b612-4139-a33e-13a64ab56962"}
4352024-07-10T15:30:01.904Z{"msg":"sending reconcile request ReconciliationId(10)","v":0,"name":"crucible","level":30,"time":"2024-07-10T15:30:01.284541836Z","hostname":"w-01J2EKZEVPA6452PKBGH6J05BH","pid":1220,"client":"1","":"downstairs","session_id":"409adfbc-b612-4139-a33e-13a64ab56962"}
4362024-07-10T15:30:01.904Z{"msg":"sending reconcile request ReconciliationId(10)","v":0,"name":"crucible","level":30,"time":"2024-07-10T15:30:01.284592856Z","hostname":"w-01J2EKZEVPA6452PKBGH6J05BH","pid":1220,"client":"2","":"downstairs","session_id":"409adfbc-b612-4139-a33e-13a64ab56962"}
4372024-07-10T15:30:01.914Z{"msg":"done with reconciliation","v":0,"name":"crucible","level":30,"time":"2024-07-10T15:30:01.294604483Z","hostname":"w-01J2EKZEVPA6452PKBGH6J05BH","pid":1220,"":"downstairs","":"downstairs","session_id":"409adfbc-b612-4139-a33e-13a64ab56962"}
4382024-07-10T15:30:01.914Z{"msg":"Transition from Reconcile to Active","v":0,"name":"crucible","level":30,"time":"2024-07-10T15:30:01.294645193Z","hostname":"Wait for a query_work_queue command to finish before sending IO
4392024-07-10T15:30:01.914Zw-01J2EKZEVPA6452PKBGH6J05BH","pid":1220,"client":"0","":"downstairs","session_id":"409adfbc-b612-4139-a33e-13a64ab56962"}
4402024-07-10T15:30:01.914Z{"msg":"Transition from Reconcile to Active","v":0,"name":"crucible","level":30,"time":"2024-07-10T15:30:01.294664823Z","hostname":"w-01J2EKZEVPA6452PKBGH6J05BH","pid":1220,"client":"1","":"downstairs","session_id":"409adfbc-b612-4139-a33e-13a64ab56962"}
4412024-07-10T15:30:01.914Z{"msg":"Transition from Reconcile to Active","v":0,"name":"crucible","level":30,"time":"2024-07-10T15:30:01.294680203Z","hostname":"w-01J2EKZEVPA6452PKBGH6J05BH","pid":1220,"client":"2","":"downstairs","session_id":"409adfbc-b612-4139-a33e-13a64ab56962"}
4422024-07-10T15:30:01.914Z{"msg":"All required reconciliation work is completed","v":0,"name":"crucible","level":30,"time":"2024-07-10T15:30:01.294694183Z","hostname":"w-01J2EKZEVPA6452PKBGH6J05BH","pid":1220,"session_id":"409adfbc-b612-4139-a33e-13a64ab56962"}
4432024-07-10T15:30:01.914Z{"msg":"Set Downstairs and Upstairs active after reconciliation","v":0,"name":"crucible","level":30,"time":"2024-07-10T15:30:01.294717272Z","hostname":"w-01J2EKZEVPA6452PKBGH6J05BH","pid":1220,"session_id":"409adfbc-b612-4139-a33e-13a64ab56962"}
4442024-07-10T15:30:01.917Z{"msg":"5009db20-421b-48e6-8ffa-36117ff0b3a4 is now active with session: 409adfbc-b612-4139-a33e-13a64ab56962","v":0,"name":"crucible","level":30,"time":"2024-07-10T15:30:01.294732122Z","hostname":"w-01J2EKZEVPA6452PKBGH6J05BH","pid":1220,"session_id":"409adfbc-b612-4139-a33e-13a64ab56962"}
4452024-07-10T15:30:01.917Z{"msg":"The guest has finished waiting for activation with:33","v":0,"name":"crucible","level":30,"time":"2024-07-10T15:30:01.294766652Z","hostname":"w-01J2EKZEVPA6452PKBGH6J05BH","pid":1220}
4462024-07-10T15:30:01.917ZRegion: es:10 ec:5 bs:4096 ts:204800 tb:50 max_io:50 or 204800
4472024-07-10T15:30:01.917ZLoading write count information from file "/var/tmp/test_up/verify_file"
4482024-07-10T15:30:01.917ZRead and Verify all blocks (0..50 range:true)
4492024-07-10T15:30:01.950ZWrote out file "/var/tmp/test_up/verify_file"
4502024-07-10T15:30:01.950ZVerify test completed
4512024-07-10T15:30:01.952ZWrote out file "/var/tmp/test_up/verify_file"
4522024-07-10T15:30:01.952ZCLIENT: Tests done. All submitted work has been ACK'd
4532024-07-10T15:30:01.952Z----------------------------------------------------------------
4542024-07-10T15:30:01.952Z Crucible gen:33 GIO:true work queues: Upstairs:0 downstairs:1
4552024-07-10T15:30:01.952ZStates: Active Active Active
4562024-07-10T15:30:01.952ZGW_ID ACK DSID TYPE BKS/EXT DS:0 DS:1 DS:2 REPLAY
4572024-07-10T15:30:01.952Z 1 Acked 1000 Read 50 Done Done Done false
4582024-07-10T15:30:01.953Z STATES DS:0 DS:1 DS:2 TOTAL
4592024-07-10T15:30:01.953Z New 0 0 0 0
4602024-07-10T15:30:01.953Z Sent 0 0 0 0
4612024-07-10T15:30:01.953Z Done 1 1 1 3
4622024-07-10T15:30:01.953Z Skipped 0 0 0 0
4632024-07-10T15:30:01.953Z Error 0 0 0 0
4642024-07-10T15:30:01.953ZLast Flush: 0 0 0
4652024-07-10T15:30:01.953ZDownstairs last five completed:
4662024-07-10T15:30:01.953ZUpstairs last five completed: 1
4672024-07-10T15:30:01.953ZCLIENT: Up:0 ds:1 act:3
4682024-07-10T15:30:05.952Z----------------------------------------------------------------
4692024-07-10T15:30:05.952Z Crucible gen:33 GIO:true work queues: Upstairs:0 downstairs:0
4702024-07-10T15:30:05.952ZDownstairs last five completed: 1001 1000
4712024-07-10T15:30:05.952ZUpstairs last five completed: 2 1
4722024-07-10T15:30:05.952ZCLIENT: Up:0 ds:0 act:3
4732024-07-10T15:30:05.953ZCLIENT: All crucible jobs finished, exiting program
4742024-07-10T15:30:05.956ZRepair part 2 passed
4752024-07-10T15:30:05.959Z/var/tmp/bins/crucible-downstairs dump --no-color -d /var/tmp/test_up/8810 -d /var/tmp/test_up/8820 -d /var/tmp/test_up/8830
4762024-07-10T15:30:05.973ZEXT BLOCKS GEN0 GEN1 GEN2 FL0 FL1 FL2 D0 D1 D2 DIFF
4772024-07-10T15:30:05.973Z 0 000-009 32 32 32 1658 1658 1658 F F F
4782024-07-10T15:30:05.976Z 1 010-019 31 31 31 1657 1657 1657 F F F
4792024-07-10T15:30:05.976Z 2 020-029 31 31 31 1657 1657 1657 F F F
4802024-07-10T15:30:05.976Z 3 030-039 32 32 32 1658 1658 1658 F F F
4812024-07-10T15:30:05.977Z 4 040-049 32 32 32 1658 1658 1658 F F F
4822024-07-10T15:30:05.977ZMax gen: 32, Max flush: 1658
4832024-07-10T15:30:05.977Zdump test passed
4842024-07-10T15:30:05.977Z/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
4852024-07-10T15:30:05.988Z Extent 1
4862024-07-10T15:30:05.991ZGEN 31 31 31
4872024-07-10T15:30:05.991ZFLUSH_ID 1657 1657 1657
4882024-07-10T15:30:05.991ZDIRTY
4892024-07-10T15:30:05.991Z
4902024-07-10T15:30:05.992ZBLOCK D0 D1 D2 C0 C1 C2 DIFF
4912024-07-10T15:30:05.992Z010 A A A A A A
4922024-07-10T15:30:05.992Z011 A A A A A A
4932024-07-10T15:30:05.995Z012 A A A A A A
4942024-07-10T15:30:05.995Z013 A A A A A A
4952024-07-10T15:30:05.995Z014 A A A A A A
4962024-07-10T15:30:05.998Z015 A A A A A A
4972024-07-10T15:30:05.998Z016 A A A A A A
4982024-07-10T15:30:06.001Z017 A A A A A A
4992024-07-10T15:30:06.002Z018 A A A A A A
5002024-07-10T15:30:06.002Z019 A A A A A A
5012024-07-10T15:30:06.005Zdump extent test passed
5022024-07-10T15:30:06.008Z/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
5032024-07-10T15:30:06.018ZExtent 2 Block in extent 0 Actual block 20
5042024-07-10T15:30:06.022Z
5052024-07-10T15:30:06.022Z DATA SHA256 VER
5062024-07-10T15:30:06.022Z------ ---------------------------------------------------------------- ---
5072024-07-10T15:30:06.022Z 0 3bdac3c0ec895b7496870c91e75b22078ae3641445e2fdd58253701d3e4fabda A
5082024-07-10T15:30:06.022Z 1 3bdac3c0ec895b7496870c91e75b22078ae3641445e2fdd58253701d3e4fabda A
5092024-07-10T15:30:06.022Z 2 3bdac3c0ec895b7496870c91e75b22078ae3641445e2fdd58253701d3e4fabda A
5102024-07-10T15:30:06.022Z
5112024-07-10T15:30:06.023ZNONCES 0 1 2 DIFF
5122024-07-10T15:30:06.023Z------ ------------------------ ------------------------ ------------------------ -----
5132024-07-10T15:30:06.023Z 0 660eb46c70cbf8f0b919a511 660eb46c70cbf8f0b919a511 660eb46c70cbf8f0b919a511
5142024-07-10T15:30:06.023Z
5152024-07-10T15:30:06.023Z TAGS 0 1 2 DIFF
5162024-07-10T15:30:06.023Z------ -------------------------------- -------------------------------- -------------------------------- -----
5172024-07-10T15:30:06.023Z 0 10698ce61e0e6ec7f1ed85c79b25b801 10698ce61e0e6ec7f1ed85c79b25b801 10698ce61e0e6ec7f1ed85c79b25b801
5182024-07-10T15:30:06.023Z
5192024-07-10T15:30:06.023ZHASHES 0 1 2 DIFF
5202024-07-10T15:30:06.023Z------ ---------------- ---------------- ---------------- -----
5212024-07-10T15:30:06.023Z 0 27c345fd73434c2d 27c345fd73434c2d 27c345fd73434c2d
5222024-07-10T15:30:06.024Z
5232024-07-10T15:30:06.030Zdump block test passed
5242024-07-10T15:30:06.030ZUpstairs tests have completed, stopping all downstairs
5252024-07-10T15:30:06.078Z
5262024-07-10T15:30:06.078ZAll Tests have passed
5272024-07-10T15:30:06.081Z3:28 Test duration
5282024-07-10T15:30:06.081Z
5292024-07-10T15:30:06.081Zreal 3:27.940164893
5302024-07-10T15:30:06.081Zuser 2:08.194526289
5312024-07-10T15:30:06.081Zsys 7.107003001
5322024-07-10T15:30:06.081Ztrap 0.100715718
5332024-07-10T15:30:06.082Ztflt 0.008634051
5342024-07-10T15:30:06.082Zdflt 0.005959021
5352024-07-10T15:30:06.082Zkflt 0.002816914
5362024-07-10T15:30:06.082Zlock 57:11.497368785
5372024-07-10T15:30:06.082Zslp 6:44.563669680
5382024-07-10T15:30:06.082Zlat 6.215582785
5392024-07-10T15:30:06.082Zstop 0.031256225
5402024-07-10T15:30:06.082Zprocess exited: duration 215344 ms, exit code 0
 
5412024-07-10T15:30:06.093Zfound 5 output files
5422024-07-10T15:30:06.093Zuploading: /tmp/test_up/dsc-out.txt (4483 bytes)
5432024-07-10T15:30:07.107Zuploaded: /tmp/test_up/dsc-out.txt
5442024-07-10T15:30:07.107Zuploading: /tmp/test_up/test_up_out.txt (3920985 bytes)
5452024-07-10T15:30:08.179Zuploaded: /tmp/test_up/test_up_out.txt
5462024-07-10T15:30:08.179Zuploading: /tmp/test_up/dsc/downstairs-8810.txt (57509 bytes)
5472024-07-10T15:30:09.193Zuploaded: /tmp/test_up/dsc/downstairs-8810.txt
5482024-07-10T15:30:09.194Zuploading: /tmp/test_up/dsc/downstairs-8820.txt (54413 bytes)
5492024-07-10T15:30:10.217Zuploaded: /tmp/test_up/dsc/downstairs-8820.txt
5502024-07-10T15:30:10.218Zuploading: /tmp/test_up/dsc/downstairs-8830.txt (8964 bytes)
5512024-07-10T15:30:11.235Zuploaded: /tmp/test_up/dsc/downstairs-8830.txt