01J8T6EDZQ7R231EZVAG4Q62XD: test-up-encrypted

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

Buildomat Job: 01J8T6EX9Y84BJ3ZNCP5KDSH9R

Tags:

Artefacts:

Output:

SEQ GLOBAL TIME DETAILS
12024-09-27T17:08:43.889Zjob dependencies complete; ready to run (waiting for 14 m 35 s)
22024-09-27T17:09:41.815Zjob assigned to worker 01J8T79TZ98ARZXF9AJ1D7W0D7 (queued for 57 s)
32024-09-27T17:09:49.684Zdownloading input: /input/build/work/bins/crucible-downstairs.gz
42024-09-27T17:09:50.808Zdownloaded input: /input/build/work/bins/crucible-downstairs.gz
52024-09-27T17:09:50.808Zdownloading input: /input/build/work/bins/crucible-hammer.gz
62024-09-27T17:09:51.893Zdownloaded input: /input/build/work/bins/crucible-hammer.gz
72024-09-27T17:09:51.893Zdownloading input: /input/build/work/bins/crutest.gz
82024-09-27T17:09:53.019Zdownloaded input: /input/build/work/bins/crutest.gz
92024-09-27T17:09:53.019Zdownloading input: /input/build/work/bins/dsc.gz
102024-09-27T17:09:53.722Zdownloaded input: /input/build/work/bins/dsc.gz
112024-09-27T17:09:53.725Zdownloading input: /input/build/work/scripts/perf-downstairs-tick.d
122024-09-27T17:09:53.740Zdownloaded input: /input/build/work/scripts/perf-downstairs-tick.d
132024-09-27T17:09:53.740Zdownloading input: /input/build/work/scripts/test_ds.sh
142024-09-27T17:09:53.755Zdownloaded input: /input/build/work/scripts/test_ds.sh
152024-09-27T17:09:53.755Zdownloading input: /input/build/work/scripts/test_live_repair.sh
162024-09-27T17:09:53.773Zdownloaded input: /input/build/work/scripts/test_live_repair.sh
172024-09-27T17:09:53.773Zdownloading input: /input/build/work/scripts/test_repair.sh
182024-09-27T17:09:53.791Zdownloaded input: /input/build/work/scripts/test_repair.sh
192024-09-27T17:09:53.791Zdownloading input: /input/build/work/scripts/test_replay.sh
202024-09-27T17:09:53.810Zdownloaded input: /input/build/work/scripts/test_replay.sh
212024-09-27T17:09:53.811Zdownloading input: /input/build/work/scripts/test_up.sh
222024-09-27T17:09:53.828Zdownloaded input: /input/build/work/scripts/test_up.sh
232024-09-27T17:09:53.829Zdownloading input: /input/build/work/scripts/upstairs_info.d
242024-09-27T17:09:53.843Zdownloaded input: /input/build/work/scripts/upstairs_info.d
252024-09-27T17:09:53.845Zdownloading input: /input/build/tmp/cargo-test-out.log
262024-09-27T17:09:54.612Zdownloaded input: /input/build/tmp/cargo-test-out.log
 
272024-09-27T17:09:54.612Zstarting task 0: "setup"
282024-09-27T17:09:54.617Z++ uname -s
292024-09-27T17:09:54.620Z+ kern=SunOS
302024-09-27T17:09:54.620Z+ case "$kern" in
312024-09-27T17:09:54.620Z+ groupadd -g 12345 build
322024-09-27T17:09:54.622Z+ useradd -u 12345 -g build -d /home/build -s /bin/bash -c build -P 'Primary Administrator' build
332024-09-27T17:09:56.632Z+ zfs create -o mountpoint=/work rpool/work
342024-09-27T17:09:56.904Z++ awk '$2 == "/home" { print $3 }' /etc/mnttab
352024-09-27T17:09:56.906Z+ home_fs=zfs
362024-09-27T17:09:56.906Z+ [[ zfs == autofs ]]
372024-09-27T17:09:56.906Z+ mkdir -p /home/build
382024-09-27T17:09:56.909Z+ chown build:build /home/build /work
392024-09-27T17:09:58.911Z+ chmod 0700 /home/build /work
402024-09-27T17:09:58.915Zprocess exited: duration 4304 ms, exit code 0
 
412024-09-27T17:09:58.924Zstarting task 1: "authentication"
422024-09-27T17:09:58.939Zprocess exited: duration 17 ms, exit code 0
 
432024-09-27T17:09:58.945Zstarting task 2: "build"
442024-09-27T17:09:58.951Z+ banner cores
452024-09-27T17:09:58.969Z
462024-09-27T17:09:58.969Z #### #### ##### ###### ####
472024-09-27T17:09:58.969Z # # # # # # # #
482024-09-27T17:09:58.969Z # # # # # ##### ####
492024-09-27T17:09:58.969Z # # # ##### # #
502024-09-27T17:09:58.969Z # # # # # # # # #
512024-09-27T17:09:58.969Z #### #### # # ###### ####
522024-09-27T17:09:58.969Z
532024-09-27T17:09:58.973Z+ pfexec coreadm -i /tmp/core.%f.%p -g /tmp/core.%f.%p -e global -e log -e proc-setid -e global-setid
542024-09-27T17:09:58.979Z+ echo 'input bins dir contains:'
552024-09-27T17:09:58.982Zinput bins dir contains:
562024-09-27T17:09:58.982Z+ ls -ltr /input/build/work/bins
572024-09-27T17:09:58.982Ztotal 771528
582024-09-27T17:09:58.982Z-rw-r--r-- 1 root root 110734592 Sep 27 17:09 crucible-downstairs.gz
592024-09-27T17:09:58.982Z-rw-r--r-- 1 root root 105905316 Sep 27 17:09 crucible-hammer.gz
602024-09-27T17:09:58.982Z-rw-r--r-- 1 root root 111383517 Sep 27 17:09 crutest.gz
612024-09-27T17:09:58.982Z-rw-r--r-- 1 root root 66745083 Sep 27 17:09 dsc.gz
622024-09-27T17:09:58.983Z+ banner unpack
632024-09-27T17:09:58.986Z
642024-09-27T17:09:58.986Z # # # # ##### ## #### # #
652024-09-27T17:09:58.986Z # # ## # # # # # # # # #
662024-09-27T17:09:58.986Z # # # # # # # # # # ####
672024-09-27T17:09:58.986Z # # # # # ##### ###### # # #
682024-09-27T17:09:58.986Z # # # ## # # # # # # #
692024-09-27T17:09:58.986Z #### # # # # # #### # #
702024-09-27T17:09:58.986Z
712024-09-27T17:09:58.986Z+ mkdir -p /var/tmp/bins
722024-09-27T17:09:58.986Z+ for t in "$input/bins/"*.gz
732024-09-27T17:09:58.989Z++ basename /input/build/work/bins/crucible-downstairs.gz
742024-09-27T17:09:58.989Z+ b=crucible-downstairs.gz
752024-09-27T17:09:58.989Z+ b=crucible-downstairs
762024-09-27T17:09:58.989Z+ gunzip
772024-09-27T17:10:01.278Z+ chmod +x /var/tmp/bins/crucible-downstairs
782024-09-27T17:10:01.281Z+ for t in "$input/bins/"*.gz
792024-09-27T17:10:01.285Z++ basename /input/build/work/bins/crucible-hammer.gz
802024-09-27T17:10:01.285Z+ b=crucible-hammer.gz
812024-09-27T17:10:01.285Z+ b=crucible-hammer
822024-09-27T17:10:01.285Z+ gunzip
832024-09-27T17:10:03.462Z+ chmod +x /var/tmp/bins/crucible-hammer
842024-09-27T17:10:03.465Z+ for t in "$input/bins/"*.gz
852024-09-27T17:10:03.465Z++ basename /input/build/work/bins/crutest.gz
862024-09-27T17:10:03.468Z+ b=crutest.gz
872024-09-27T17:10:03.468Z+ b=crutest
882024-09-27T17:10:03.468Z+ gunzip
892024-09-27T17:10:05.854Z+ chmod +x /var/tmp/bins/crutest
902024-09-27T17:10:05.857Z+ for t in "$input/bins/"*.gz
912024-09-27T17:10:05.860Z++ basename /input/build/work/bins/dsc.gz
922024-09-27T17:10:05.860Z+ b=dsc.gz
932024-09-27T17:10:05.860Z+ b=dsc
942024-09-27T17:10:05.860Z+ gunzip
952024-09-27T17:10:07.230Z+ chmod +x /var/tmp/bins/dsc
962024-09-27T17:10:07.234Z+ export BINDIR=/var/tmp/bins
972024-09-27T17:10:07.234Z+ BINDIR=/var/tmp/bins
982024-09-27T17:10:07.234Z+ jobpid=1137
992024-09-27T17:10:07.234Z+ echo 'Setup debug logging'
1002024-09-27T17:10:07.234ZSetup debug logging
1012024-09-27T17:10:07.234Z+ mkdir /tmp/debug
1022024-09-27T17:10:07.234Z+ sleep 7200
1032024-09-27T17:10:07.239Z+ psrinfo -v
1042024-09-27T17:10:07.242Z+ df -h
1052024-09-27T17:10:07.276Z+ prstat -d d -mLc 1
1062024-09-27T17:10:07.281Z+ iostat -T d -xn 1
1072024-09-27T17:10:07.281Z+ mpstat -T d 1
1082024-09-27T17:10:07.281Z+ vmstat -T d -p 1
1092024-09-27T17:10:07.281Z+ pfexec dtrace -Z -s /input/build/work/scripts/perf-downstairs-tick.d
1102024-09-27T17:10:07.281Z+ banner test_up_encrypted
1112024-09-27T17:10:07.281Z+ pfexec dtrace -Z -s /input/build/work/scripts/upstairs_info.d
1122024-09-27T17:10:07.285Z
1132024-09-27T17:10:07.285Z ##### ###### #### ##### # # ##### ###### # #
1142024-09-27T17:10:07.285Z # # # # # # # # # ## #
1152024-09-27T17:10:07.285Z # ##### #### # # # # # ##### # # #
1162024-09-27T17:10:07.285Z # # # # # # ##### # # # #
1172024-09-27T17:10:07.285Z # # # # # # # # # # ##
1182024-09-27T17:10:07.285Z # ###### #### # ####### #### # ####### ###### # #
1192024-09-27T17:10:07.285Z
1202024-09-27T17:10:07.285Z+ ptime -m bash /input/build/work/scripts/test_up.sh -N encrypted
1212024-09-27T17:10:07.292Z/input/build/work
1222024-09-27T17:10:07.321ZTurn off color for downstairs dump
1232024-09-27T17:10:07.347ZUpstairs using key: rWzZG8E/8XgqIm3XrvGn0g0nYOJ/sNiEzEskSoS4E9U=
1242024-09-27T17:10:07.350Zdsc output goes to /tmp/test_up-build/dsc-out.txt
1252024-09-27T17:10:07.350ZCreating three downstairs regions
1262024-09-27T17:10:07.731ZStarting three downstairs
1272024-09-27T17:10:12.739ZDisable automatic restart on all downstairs
1282024-09-27T17:10:12.799Z
1292024-09-27T17:10:12.799ZBegin tests, output goes to /tmp/test_up-build/test_up_out.txt
1302024-09-27T17:10:12.804ZRunning test: span
1312024-09-27T17:10:16.987ZCompleted test: span
1322024-09-27T17:10:21.994ZRunning test: big
1332024-09-27T17:10:26.424ZCompleted test: big
1342024-09-27T17:10:31.410ZRunning test: dep
1352024-09-27T17:11:25.664ZCompleted test: dep
1362024-09-27T17:11:30.671ZRunning test: balloon
1372024-09-27T17:12:17.096ZCompleted test: balloon
1382024-09-27T17:12:22.102ZRunning test: deactivate
1392024-09-27T17:13:12.853ZCompleted test: deactivate
1402024-09-27T17:13:17.860ZRunning hammer
1412024-09-27T17:13:31.603ZRun repair tests
1422024-09-27T17:13:31.607Z/var/tmp/bins/crutest fill -g 31 -q --key rWzZG8E/8XgqIm3XrvGn0g0nYOJ/sNiEzEskSoS4E9U= -t 127.0.0.1:8810 -t 127.0.0.1:8820 -t 127.0.0.1:8830 --verify-out /var/tmp/test_up-build/verify_file
1432024-09-27T17:13:31.623Z{"msg":"look at: http://127.0.0.1:12810 ","v":0,"name":"crucible","level":30,"time":"2024-09-27T17:13:30.097518319Z","hostname":"w-01J8T79TZ98ARZXF9AJ1D7W0D7","pid":1217,"task":"crutest"}
1442024-09-27T17:13:31.666Z{"msg":"RI is: RegionDefinition { block_size: 4096, extent_size: Block { value: 10, shift: 12 }, extent_count: 5, uuid: 12345678-0000-0000-0000-000000008810, encrypted: true, database_read_version: 1, database_write_version: 1 }","v":0,"name":"crucible","level":30,"time":"2024-09-27T17:13:30.14084703Z","hostname":"w-01J8T79TZ98ARZXF9AJ1D7W0D7","pid":1217,"task":"crutest"}
1452024-09-27T17:13:31.669Z{"msg":"Upstairs starts","v":0,"name":"crucible","level":30,"time":"2024-09-27T17:13:30.14149239Z","hostname":"w-01J8T79TZ98ARZXF9AJ1D7W0D7","pid":1217}
1462024-09-27T17:13:31.669Z{"msg":"Crucible Version: BuildInfo {\n version: \"0.0.1\",\n git_sha: \"93b12f70ee7c1993c73ac4256d99ff80ccbe4bac\",\n git_commit_timestamp: \"2024-09-27T16:52:31.000000000Z\",\n git_branch: \"update-omicron-common\",\n rustc_semver: \"1.80.0\",\n rustc_channel: \"stable\",\n rustc_host_triple: \"x86_64-unknown-illumos\",\n rustc_commit_sha: \"051478957371ee0084a7c0913941d2a8c4757bb9\",\n cargo_triple: \"x86_64-unknown-illumos\",\n debug: true,\n opt_level: 0,\n}","v":0,"name":"crucible","level":30,"time":"2024-09-27T17:13:30.141549587Z","hostname":"w-01J8T79TZ98ARZXF9AJ1D7W0D7","pid":1217}
1472024-09-27T17:13:31.669Z{"msg":"Upstairs <-> Downstairs Message Version: 11","v":0,"name":"crucible","level":30,"time":"2024-09-27T17:13:30.141580466Z","hostname":"w-01J8T79TZ98ARZXF9AJ1D7W0D7","pid":1217}
1482024-09-27T17:13:31.669Z{"msg":"Using region definition RegionDefinition { block_size: 4096, extent_size: Block { value: 10, shift: 12 }, extent_count: 5, uuid: 00000000-0000-0000-0000-000000000000, encrypted: true, database_read_version: 1, database_write_version: 1 }","v":0,"name":"crucible","level":30,"time":"2024-09-27T17:13:30.141599825Z","hostname":"w-01J8T79TZ98ARZXF9AJ1D7W0D7","pid":1217}
1492024-09-27T17:13:31.669Z{"msg":"Crucible 2e5b70dc-6477-4a01-8338-42160bb5f582 has session id: de096f19-2c59-4e9a-b1d5-aec09578d4a9","v":0,"name":"crucible","level":30,"time":"2024-09-27T17:13:30.142024254Z","hostname":"w-01J8T79TZ98ARZXF9AJ1D7W0D7","pid":1217,"session_id":"de096f19-2c59-4e9a-b1d5-aec09578d4a9"}
1502024-09-27T17:13:31.669Z{"msg":"Upstairs opts: Upstairs UUID: 2e5b70dc-6477-4a01-8338-42160bb5f582, 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-09-27T17:13:30.142079082Z","hostname":"w-01J8T79TZ98ARZXF9AJ1D7W0D7","pid":1217,"session_id":"de096f19-2c59-4e9a-b1d5-aec09578d4a9"}
1512024-09-27T17:13:31.669Z{"msg":"Crucible stats registered with UUID: 2e5b70dc-6477-4a01-8338-42160bb5f582","v":0,"name":"crucible","level":30,"time":"2024-09-27T17:13:30.142097571Z","hostname":"w-01J8T79TZ98ARZXF9AJ1D7W0D7","pid":1217,"session_id":"de096f19-2c59-4e9a-b1d5-aec09578d4a9"}
1522024-09-27T17:13:31.699Z{"msg":"The guest has requested activation with gen:31","v":0,"name":"crucible","level":30,"time":"2024-09-27T17:13:30.173507159Z","hostname":"w-01J8T79TZ98ARZXF9AJ1D7W0D7","pid":1217}
1532024-09-27T17:13:31.699Z{"msg":"2e5b70dc-6477-4a01-8338-42160bb5f582 active request set","v":0,"name":"crucible","level":30,"time":"2024-09-27T17:13:30.173568586Z","hostname":"w-01J8T79TZ98ARZXF9AJ1D7W0D7","pid":1217,"session_id":"de096f19-2c59-4e9a-b1d5-aec09578d4a9"}
1542024-09-27T17:13:31.699Z{"msg":"sending connect oneshot to client","v":0,"name":"crucible","level":30,"time":"2024-09-27T17:13:30.173591075Z","hostname":"w-01J8T79TZ98ARZXF9AJ1D7W0D7","pid":1217,"client":"0","":"downstairs","session_id":"de096f19-2c59-4e9a-b1d5-aec09578d4a9"}
1552024-09-27T17:13:31.699Z{"msg":"client set_active_request while in New; waiting...","v":0,"name":"crucible","level":30,"time":"2024-09-27T17:13:30.173620733Z","hostname":"w-01J8T79TZ98ARZXF9AJ1D7W0D7","pid":1217,"client":"0","":"downstairs","session_id":"de096f19-2c59-4e9a-b1d5-aec09578d4a9"}
1562024-09-27T17:13:31.701Z{"msg":"sending connect oneshot to client","v":0,"name":"crucible","level":30,"time":"2024-09-27T17:13:30.173640362Z","hostname":"w-01J8T79TZ98ARZXF9AJ1D7W0D7","pid":1217,"client":"1","":"downstairs","session_id":"de096f19-2c59-4e9a-b1d5-aec09578d4a9"}
1572024-09-27T17:13:31.702Z{"msg":"client set_active_request while in New; waiting...","v":0,"name":"crucible","level":30,"time":"2024-09-27T17:13:30.17368Z","hostname":"w-01J8T79TZ98ARZXF9AJ1D7W0D7","pid":1217,"client":"1","":"downstairs","session_id":"de096f19-2c59-4e9a-b1d5-aec09578d4a9"}
1582024-09-27T17:13:31.702Z{"msg":"sending connect oneshot to client","v":0,"name":"crucible","level":30,"time":"2024-09-27T17:13:30.173712099Z","hostname":"w-01J8T79TZ98ARZXF9AJ1D7W0D7","pid":1217,"client":"2","":"downstairs","session_id":"de096f19-2c59-4e9a-b1d5-aec09578d4a9"}
1592024-09-27T17:13:31.702Z{"msg":"client set_active_request while in New; waiting...","v":0,"name":"crucible","level":30,"time":"2024-09-27T17:13:30.173760737Z","hostname":"w-01J8T79TZ98ARZXF9AJ1D7W0D7","pid":1217,"client":"2","":"downstairs","session_id":"de096f19-2c59-4e9a-b1d5-aec09578d4a9"}
1602024-09-27T17:13:31.702Z{"msg":"connecting to 127.0.0.1:8830","v":0,"name":"crucible","level":30,"time":"2024-09-27T17:13:30.173791405Z","hostname":"w-01J8T79TZ98ARZXF9AJ1D7W0D7","pid":1217,"":"io task","client":"2","":"downstairs","session_id":"de096f19-2c59-4e9a-b1d5-aec09578d4a9"}
1612024-09-27T17:13:31.702Z{"msg":"connecting to 127.0.0.1:8810","v":0,"name":"crucible","level":30,"time":"2024-09-27T17:13:30.173831643Z","hostname":"w-01J8T79TZ98ARZXF9AJ1D7W0D7","pid":1217,"":"io task","client":"0","":"downstairs","session_id":"de096f19-2c59-4e9a-b1d5-aec09578d4a9"}
1622024-09-27T17:13:31.702Z{"msg":"connecting to 127.0.0.1:8820","v":0,"name":"crucible","level":30,"time":"2024-09-27T17:13:30.173863552Z","hostname":"w-01J8T79TZ98ARZXF9AJ1D7W0D7","pid":1217,"":"io task","client":"1","":"downstairs","session_id":"de096f19-2c59-4e9a-b1d5-aec09578d4a9"}
1632024-09-27T17:13:31.702Z{"msg":"ds_connection connected from Ok(127.0.0.1:34209)","v":0,"name":"crucible","level":30,"time":"2024-09-27T17:13:30.174182757Z","hostname":"w-01J8T79TZ98ARZXF9AJ1D7W0D7","pid":1217,"":"io task","client":"1","":"downstairs","session_id":"de096f19-2c59-4e9a-b1d5-aec09578d4a9"}
1642024-09-27T17:13:31.702Z{"msg":"ds_connection connected from Ok(127.0.0.1:51283)","v":0,"name":"crucible","level":30,"time":"2024-09-27T17:13:30.174206275Z","hostname":"w-01J8T79TZ98ARZXF9AJ1D7W0D7","pid":1217,"":"io task","client":"2","":"downstairs","session_id":"de096f19-2c59-4e9a-b1d5-aec09578d4a9"}
1652024-09-27T17:13:31.702Z{"msg":"ds_connection connected from Ok(127.0.0.1:37184)","v":0,"name":"crucible","level":30,"time":"2024-09-27T17:13:30.174231404Z","hostname":"w-01J8T79TZ98ARZXF9AJ1D7W0D7","pid":1217,"":"io task","client":"0","":"downstairs","session_id":"de096f19-2c59-4e9a-b1d5-aec09578d4a9"}
1662024-09-27T17:13:31.702Z{"msg":"ds_transition from New to WaitActive","v":0,"name":"crucible","level":30,"time":"2024-09-27T17:13:30.174862194Z","hostname":"w-01J8T79TZ98ARZXF9AJ1D7W0D7","pid":1217,"client":"1","":"downstairs","session_id":"de096f19-2c59-4e9a-b1d5-aec09578d4a9"}
1672024-09-27T17:13:31.702Z{"msg":"[1] Transition from New to WaitActive","v":0,"name":"crucible","level":30,"time":"2024-09-27T17:13:30.174900052Z","hostname":"w-01J8T79TZ98ARZXF9AJ1D7W0D7","pid":1217,"client":"1","":"downstairs","session_id":"de096f19-2c59-4e9a-b1d5-aec09578d4a9"}
1682024-09-27T17:13:31.702Z{"msg":"ds_transition from New to WaitActive","v":0,"name":"crucible","level":30,"time":"2024-09-27T17:13:30.174915522Z","hostname":"w-01J8T79TZ98ARZXF9AJ1D7W0D7","pid":1217,"client":"2","":"downstairs","session_id":"de096f19-2c59-4e9a-b1d5-aec09578d4a9"}
1692024-09-27T17:13:31.702Z{"msg":"[2] Transition from New to WaitActive","v":0,"name":"crucible","level":30,"time":"2024-09-27T17:13:30.174929571Z","hostname":"w-01J8T79TZ98ARZXF9AJ1D7W0D7","pid":1217,"client":"2","":"downstairs","session_id":"de096f19-2c59-4e9a-b1d5-aec09578d4a9"}
1702024-09-27T17:13:31.702Z{"msg":"ds_transition from New to WaitActive","v":0,"name":"crucible","level":30,"time":"2024-09-27T17:13:30.174998478Z","hostname":"w-01J8T79TZ98ARZXF9AJ1D7W0D7","pid":1217,"client":"0","":"downstairs","session_id":"de096f19-2c59-4e9a-b1d5-aec09578d4a9"}
1712024-09-27T17:13:31.702Z{"msg":"[0] Transition from New to WaitActive","v":0,"name":"crucible","level":30,"time":"2024-09-27T17:13:30.175029346Z","hostname":"w-01J8T79TZ98ARZXF9AJ1D7W0D7","pid":1217,"client":"0","":"downstairs","session_id":"de096f19-2c59-4e9a-b1d5-aec09578d4a9"}
1722024-09-27T17:13:31.702Z{"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-09-27T17:13:30.175599539Z","hostname":"w-01J8T79TZ98ARZXF9AJ1D7W0D7","pid":1217,"client":"1","":"downstairs","session_id":"de096f19-2c59-4e9a-b1d5-aec09578d4a9"}
1732024-09-27T17:13:31.702Z{"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-09-27T17:13:30.175670936Z","hostname":"w-01J8T79TZ98ARZXF9AJ1D7W0D7","pid":1217,"client":"0","":"downstairs","session_id":"de096f19-2c59-4e9a-b1d5-aec09578d4a9"}
1742024-09-27T17:13:31.702Z{"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-09-27T17:13:30.175707674Z","hostname":"w-01J8T79TZ98ARZXF9AJ1D7W0D7","pid":1217,"client":"2","":"downstairs","session_id":"de096f19-2c59-4e9a-b1d5-aec09578d4a9"}
1752024-09-27T17:13:31.702Z{"msg":"ds_transition from WaitActive to WaitQuorum","v":0,"name":"crucible","level":30,"time":"2024-09-27T17:13:30.176097755Z","hostname":"w-01J8T79TZ98ARZXF9AJ1D7W0D7","pid":1217,"client":"0","":"downstairs","session_id":"de096f19-2c59-4e9a-b1d5-aec09578d4a9"}
1762024-09-27T17:13:31.702Z{"msg":"[0] Transition from WaitActive to WaitQuorum","v":0,"name":"crucible","level":30,"time":"2024-09-27T17:13:30.176135634Z","hostname":"w-01J8T79TZ98ARZXF9AJ1D7W0D7","pid":1217,"client":"0","":"downstairs","session_id":"de096f19-2c59-4e9a-b1d5-aec09578d4a9"}
1772024-09-27T17:13:31.702Z{"msg":"Waiting for more clients to be ready","v":0,"name":"crucible","level":30,"time":"2024-09-27T17:13:30.176151223Z","hostname":"w-01J8T79TZ98ARZXF9AJ1D7W0D7","pid":1217,"session_id":"de096f19-2c59-4e9a-b1d5-aec09578d4a9"}
1782024-09-27T17:13:31.702Z{"msg":"ds_transition from WaitActive to WaitQuorum","v":0,"name":"crucible","level":30,"time":"2024-09-27T17:13:30.176183522Z","hostname":"w-01J8T79TZ98ARZXF9AJ1D7W0D7","pid":1217,"client":"2","":"downstairs","session_id":"de096f19-2c59-4e9a-b1d5-aec09578d4a9"}
1792024-09-27T17:13:31.702Z{"msg":"[2] Transition from WaitActive to WaitQuorum","v":0,"name":"crucible","level":30,"time":"2024-09-27T17:13:30.176200951Z","hostname":"w-01J8T79TZ98ARZXF9AJ1D7W0D7","pid":1217,"client":"2","":"downstairs","session_id":"de096f19-2c59-4e9a-b1d5-aec09578d4a9"}
1802024-09-27T17:13:31.702Z{"msg":"Waiting for more clients to be ready","v":0,"name":"crucible","level":30,"time":"2024-09-27T17:13:30.176231979Z","hostname":"w-01J8T79TZ98ARZXF9AJ1D7W0D7","pid":1217,"session_id":"de096f19-2c59-4e9a-b1d5-aec09578d4a9"}
1812024-09-27T17:13:31.702Z{"msg":"ds_transition from WaitActive to WaitQuorum","v":0,"name":"crucible","level":30,"time":"2024-09-27T17:13:30.176249388Z","hostname":"w-01J8T79TZ98ARZXF9AJ1D7W0D7","pid":1217,"client":"1","":"downstairs","session_id":"de096f19-2c59-4e9a-b1d5-aec09578d4a9"}
1822024-09-27T17:13:31.702Z{"msg":"[1] Transition from WaitActive to WaitQuorum","v":0,"name":"crucible","level":30,"time":"2024-09-27T17:13:30.176279207Z","hostname":"w-01J8T79TZ98ARZXF9AJ1D7W0D7","pid":1217,"client":"1","":"downstairs","session_id":"de096f19-2c59-4e9a-b1d5-aec09578d4a9"}
1832024-09-27T17:13:31.702Z{"msg":"[0]R flush_numbers: [1688, 1688, 1688, 1688, 1688]","v":0,"name":"crucible","level":30,"time":"2024-09-27T17:13:30.176299896Z","hostname":"w-01J8T79TZ98ARZXF9AJ1D7W0D7","pid":1217,"":"downstairs","":"downstairs","session_id":"de096f19-2c59-4e9a-b1d5-aec09578d4a9"}
1842024-09-27T17:13:31.702Z{"msg":"[0]R generation: [25, 25, 25, 25, 25]","v":0,"name":"crucible","level":30,"time":"2024-09-27T17:13:30.176329544Z","hostname":"w-01J8T79TZ98ARZXF9AJ1D7W0D7","pid":1217,"":"downstairs","":"downstairs","session_id":"de096f19-2c59-4e9a-b1d5-aec09578d4a9"}
1852024-09-27T17:13:31.702Z{"msg":"[0]R dirty: [false, false, false, false, false]","v":0,"name":"crucible","level":30,"time":"2024-09-27T17:13:30.176344604Z","hostname":"w-01J8T79TZ98ARZXF9AJ1D7W0D7","pid":1217,"":"downstairs","":"downstairs","session_id":"de096f19-2c59-4e9a-b1d5-aec09578d4a9"}
1862024-09-27T17:13:31.702Z{"msg":"[1]R flush_numbers: [1688, 1688, 1688, 1688, 1688]","v":0,"name":"crucible","level":30,"time":"2024-09-27T17:13:30.176357993Z","hostname":"w-01J8T79TZ98ARZXF9AJ1D7W0D7","pid":1217,"":"downstairs","":"downstairs","session_id":"de096f19-2c59-4e9a-b1d5-aec09578d4a9"}
1872024-09-27T17:13:31.702Z{"msg":"Wait for a query_work_queue command to finish before sending IO
1882024-09-27T17:13:31.705Z[1]R generation: [25, 25, 25, 25, 25]","v":0,"name":"crucible","level":30,"time":"2024-09-27T17:13:30.176385582Z","hostname":"w-01J8T79TZ98ARZXF9AJ1D7W0D7","pid":1217,"":"downstairs","":"downstairs","session_id":"de096f19-2c59-4e9a-b1d5-aec09578d4a9"}
1892024-09-27T17:13:31.705Z{"msg":"[1]R dirty: [false, false, false, false, false]","v":0,"name":"crucible","level":30,"time":"2024-09-27T17:13:30.17642531Z","hostname":"w-01J8T79TZ98ARZXF9AJ1D7W0D7","pid":1217,"":"downstairs","":"downstairs","session_id":"de096f19-2c59-4e9a-b1d5-aec09578d4a9"}
1902024-09-27T17:13:31.705Z{"msg":"[2]R flush_numbers: [1688, 1688, 1688, 1688, 1688]","v":0,"name":"crucible","level":30,"time":"2024-09-27T17:13:30.176449179Z","hostname":"w-01J8T79TZ98ARZXF9AJ1D7W0D7","pid":1217,"":"downstairs","":"downstairs","session_id":"de096f19-2c59-4e9a-b1d5-aec09578d4a9"}
1912024-09-27T17:13:31.705Z{"msg":"[2]R generation: [25, 25, 25, 25, 25]","v":0,"name":"crucible","level":30,"time":"2024-09-27T17:13:30.176477548Z","hostname":"w-01J8T79TZ98ARZXF9AJ1D7W0D7","pid":1217,"":"downstairs","":"downstairs","session_id":"de096f19-2c59-4e9a-b1d5-aec09578d4a9"}
1922024-09-27T17:13:31.705Z{"msg":"[2]R dirty: [false, false, false, false, false]","v":0,"name":"crucible","level":30,"time":"2024-09-27T17:13:30.176492417Z","hostname":"w-01J8T79TZ98ARZXF9AJ1D7W0D7","pid":1217,"":"downstairs","":"downstairs","session_id":"de096f19-2c59-4e9a-b1d5-aec09578d4a9"}
1932024-09-27T17:13:31.705Z{"msg":"Max found gen is 26","v":0,"name":"crucible","level":30,"time":"2024-09-27T17:13:30.176523285Z","hostname":"w-01J8T79TZ98ARZXF9AJ1D7W0D7","pid":1217,"":"downstairs","":"downstairs","session_id":"de096f19-2c59-4e9a-b1d5-aec09578d4a9"}
1942024-09-27T17:13:31.705Z{"msg":"Generation requested: 31 >= found:26","v":0,"name":"crucible","level":30,"time":"2024-09-27T17:13:30.176542504Z","hostname":"w-01J8T79TZ98ARZXF9AJ1D7W0D7","pid":1217,"":"downstairs","":"downstairs","session_id":"de096f19-2c59-4e9a-b1d5-aec09578d4a9"}
1952024-09-27T17:13:31.705Z{"msg":"Next flush: 1689","v":0,"name":"crucible","level":30,"time":"2024-09-27T17:13:30.176565123Z","hostname":"w-01J8T79TZ98ARZXF9AJ1D7W0D7","pid":1217,"":"downstairs","":"downstairs","session_id":"de096f19-2c59-4e9a-b1d5-aec09578d4a9"}
1962024-09-27T17:13:31.705Z{"msg":"All extents match","v":0,"name":"crucible","level":30,"time":"2024-09-27T17:13:30.176588802Z","hostname":"w-01J8T79TZ98ARZXF9AJ1D7W0D7","pid":1217,"":"downstairs","":"downstairs","session_id":"de096f19-2c59-4e9a-b1d5-aec09578d4a9"}
1972024-09-27T17:13:31.705Z{"msg":"No downstairs reconciliation required","v":0,"name":"crucible","level":30Region: es:10 ec:5 bs:4096 ts:204800 tb:50 max_io:50 or 204800
1982024-09-27T17:13:31.705Z,"time":"2024-09-27T17:13:30.176614241Z","hostname":"w-01J8T79TZ98ARZXF9AJ1D7W0D7","pid":1217,"session_id":"de096f19-2c59-4e9a-b1d5-aec09578d4a9"}
1992024-09-27T17:13:31.705Z{"msg":"Transition from WaitQuorum to Active","v":0,"name":"crucible","level":30,"time":"2024-09-27T17:13:30.17662741Z","hostname":"w-01J8T79TZ98ARZXF9AJ1D7W0D7","pid":1217,"client":"0","":"downstairs","session_id":"de096f19-2c59-4e9a-b1d5-aec09578d4a9"}
2002024-09-27T17:13:31.705Z{"msg":"Transition from WaitQuorum to Active","v":0,"name":"crucible","level":30,"time":"2024-09-27T17:13:30.17664082Z","hostname":"w-01J8T79TZ98ARZXF9AJ1D7W0D7","pid":1217,"client":"1","":"downstairs","session_id":"de096f19-2c59-4e9a-b1d5-aec09578d4a9"}
2012024-09-27T17:13:31.706ZFill test
2022024-09-27T17:13:31.706Z{"msg":"Transition from WaitQuorum to Active","v":0,"name":"crucible","level":30,"time":"2024-09-27T17:13:30.176663959Z","hostname":"w-01J8T79TZ98ARZXF9AJ1D7W0D7","pid":1217,"client":"2","":"downstairs","session_id":"de096f19-2c59-4e9a-b1d5-aec09578d4a9"}
2032024-09-27T17:13:31.706Z{"msg":"All required reconciliation work is completed","v":0,"name":"crucible","level":30,"time":"2024-09-27T17:13:30.176678268Z","hostname":"w-01J8T79TZ98ARZXF9AJ1D7W0D7","pid":1217,"session_id":"de096f19-2c59-4e9a-b1d5-aec09578d4a9"}
2042024-09-27T17:13:31.706Z{"msg":"Set Downstairs and Upstairs active after reconciliation","v":0,"name":"crucible","level":30,"time":"2024-09-27T17:13:30.176697447Z","hostname":"w-01J8T79TZ98ARZXF9AJ1D7W0D7","pid":1217,"session_id":"de096f19-2c59-4e9a-b1d5-aec09578d4a9"}
2052024-09-27T17:13:31.706Z{"msg":"2e5b70dc-6477-4a01-8338-42160bb5f582 is now active with session: de096f19-2c59-4e9a-b1d5-aec09578d4a9","v":0,"name":"crucible","level":30,"time":"2024-09-27T17:13:30.176710616Z","hostname":"w-01J8T79TZ98ARZXF9AJ1D7W0D7","pid":1217,"session_id":"de096f19-2c59-4e9a-b1d5-aec09578d4a9"}
2062024-09-27T17:13:31.706Z{"msg":"Set Active after no reconciliation","v":0,"name":"crucible","level":30,"time":"2024-09-27T17:13:30.176729676Z","hostname":"w-01J8T79TZ98ARZXF9AJ1D7W0D7","pid":1217,"session_id":"de096f19-2c59-4e9a-b1d5-aec09578d4a9"}
2072024-09-27T17:13:31.706Z{"msg":"The guest has finished waiting for activation with:31","v":0,"name":"crucible","level":30,"time":"2024-09-27T17:13:30.176742245Z","hostname":"w-01J8T79TZ98ARZXF9AJ1D7W0D7","pid":1217}
2082024-09-27T17:13:31.782ZRead and Verify all blocks (0..50 range:false)
2092024-09-27T17:13:31.824ZWrote out file "/var/tmp/test_up-build/verify_file"
2102024-09-27T17:13:31.824ZCLIENT: Tests done. All submitted work has been ACK'd
2112024-09-27T17:13:31.826Z----------------------------------------------------------------
2122024-09-27T17:13:31.826Z Crucible gen:31 GIO:true work queues: Upstairs:0 downstairs:1
2132024-09-27T17:13:31.827ZStates: Active Active Active
2142024-09-27T17:13:31.827ZGW_ID ACK DSID TYPE BKS/EXT DS:0 DS:1 DS:2 REPLAY
2152024-09-27T17:13:31.827Z 3 Acked 1002 Read 50 Done Done Done false
2162024-09-27T17:13:31.827Z STATES DS:0 DS:1 DS:2 TOTAL
2172024-09-27T17:13:31.827Z Sent 0 0 0 0
2182024-09-27T17:13:31.827Z Done 1 1 1 3
2192024-09-27T17:13:31.827Z Skipped 0 0 0 0
2202024-09-27T17:13:31.827Z Error 0 0 0 0
2212024-09-27T17:13:31.827ZLast Flush: 1001 1001 1001
2222024-09-27T17:13:31.827ZDownstairs last five completed: 1001 1000
2232024-09-27T17:13:31.827ZUpstairs last five completed: 3 2 1
2242024-09-27T17:13:31.827ZCLIENT: Up:0 ds:1 act:3
2252024-09-27T17:13:35.825Z----------------------------------------------------------------
2262024-09-27T17:13:35.825Z Crucible gen:31 GIO:true work queues: Upstairs:0 downstairs:0
2272024-09-27T17:13:35.825ZDownstairs last five completed: 1003 1002 1001 1000
2282024-09-27T17:13:35.825ZUpstairs last five completed: 4 3 2 1
2292024-09-27T17:13:35.825ZCLIENT: Up:0 ds:0 act:3
2302024-09-27T17:13:35.825ZCLIENT: All crucible jobs finished, exiting program
2312024-09-27T17:13:35.828Z{"msg":"Guest handle has been dropped","v":0,"name":"crucible","level":40,"time":"2024-09-27T17:13:34.299117434Z","hostname":"w-01J8T79TZ98ARZXF9AJ1D7W0D7","pid":1217}
2322024-09-27T17:13:35.835ZRepair setup passed
2332024-09-27T17:13:35.839ZCopy the 8830 file
2342024-09-27T17:13:35.842Zcp -r /var/tmp/test_up-build/8830 /var/tmp/test_up-build/previous
2352024-09-27T17:13:35.844Z/var/tmp/bins/crutest repair -g 32 -q --key rWzZG8E/8XgqIm3XrvGn0g0nYOJ/sNiEzEskSoS4E9U= -t 127.0.0.1:8810 -t 127.0.0.1:8820 -t 127.0.0.1:8830 --verify-out /var/tmp/test_up-build/verify_file --verify-in /var/tmp/test_up-build/verify_file
2362024-09-27T17:13:35.860Z{"msg":"look at: http://127.0.0.1:12810 ","v":0,"name":"crucible","level":30,"time":"2024-09-27T17:13:34.332754656Z","hostname":"w-01J8T79TZ98ARZXF9AJ1D7W0D7","pid":1223,"task":"crutest"}
2372024-09-27T17:13:35.902Z{"msg":"RI is: RegionDefinition { block_size: 4096, extent_size: Block { value: 10, shift: 12 }, extent_count: 5, uuid: 12345678-0000-0000-0000-000000008810, encrypted: true, database_read_version: 1, database_write_version: 1 }","v":0,"name":"crucible","level":30,"time":"2024-09-27T17:13:34.376188832Z","hostname":"w-01J8T79TZ98ARZXF9AJ1D7W0D7","pid":1223,"task":"crutest"}
2382024-09-27T17:13:35.906Z{"msg":"Upstairs starts","v":0,"name":"crucible","level":30,"time":"2024-09-27T17:13:34.376767565Z","hostname":"w-01J8T79TZ98ARZXF9AJ1D7W0D7","pid":1223}
2392024-09-27T17:13:35.906Z{"msg":"Crucible Version: BuildInfo {\n version: \"0.0.1\",\n git_sha: \"93b12f70ee7c1993c73ac4256d99ff80ccbe4bac\",\n git_commit_timestamp: \"2024-09-27T16:52:31.000000000Z\",\n git_branch: \"update-omicron-common\",\n rustc_semver: \"1.80.0\",\n rustc_channel: \"stable\",\n rustc_host_triple: \"x86_64-unknown-illumos\",\n rustc_commit_sha: \"051478957371ee0084a7c0913941d2a8c4757bb9\",\n cargo_triple: \"x86_64-unknown-illumos\",\n debug: true,\n opt_level: 0,\n}","v":0,"name":"crucible","level":30,"time":"2024-09-27T17:13:34.376821942Z","hostname":"w-01J8T79TZ98ARZXF9AJ1D7W0D7","pid":1223}
2402024-09-27T17:13:35.906Z{"msg":"Upstairs <-> Downstairs Message Version: 11","v":0,"name":"crucible","level":30,"time":"2024-09-27T17:13:34.37685997Z","hostname":"w-01J8T79TZ98ARZXF9AJ1D7W0D7","pid":1223}
2412024-09-27T17:13:35.906Z{"msg":"Using region definition RegionDefinition { block_size: 4096, extent_size: Block { value: 10, shift: 12 }, extent_count: 5, uuid: 00000000-0000-0000-0000-000000000000, encrypted: true, database_read_version: 1, database_write_version: 1 }","v":0,"name":"crucible","level":30,"time":"2024-09-27T17:13:34.376905298Z","hostname":"w-01J8T79TZ98ARZXF9AJ1D7W0D7","pid":1223}
2422024-09-27T17:13:35.906Z{"msg":"Crucible 1009559a-3d73-4efc-99dc-aa83b2b3266b has session id: 81b154a5-6708-4c9c-b0d3-c5edfff6162c","v":0,"name":"crucible","level":30,"time":"2024-09-27T17:13:34.377315679Z","hostname":"w-01J8T79TZ98ARZXF9AJ1D7W0D7","pid":1223,"session_id":"81b154a5-6708-4c9c-b0d3-c5edfff6162c"}
2432024-09-27T17:13:35.906Z{"msg":"Upstairs opts: Upstairs UUID: 1009559a-3d73-4efc-99dc-aa83b2b3266b, 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-09-27T17:13:34.377360466Z","hostname":"w-01J8T79TZ98ARZXF9AJ1D7W0D7","pid":1223,"session_id":"81b154a5-6708-4c9c-b0d3-c5edfff6162c"}
2442024-09-27T17:13:35.906Z{"msg":"Crucible stats registered with UUID: 1009559a-3d73-4efc-99dc-aa83b2b3266b","v":0,"name":"crucible","level":30,"time":"2024-09-27T17:13:34.377393375Z","hostname":"w-01J8T79TZ98ARZXF9AJ1D7W0D7","pid":1223,"session_id":"81b154a5-6708-4c9c-b0d3-c5edfff6162c"}
2452024-09-27T17:13:35.935Z{"msg":"The guest has requested activation with gen:32","v":0,"name":"crucible","level":30,"time":"2024-09-27T17:13:34.408419221Z","hostname":"w-01J8T79TZ98ARZXF9AJ1D7W0D7","pid":1223}
2462024-09-27T17:13:35.935Z{"msg":"1009559a-3d73-4efc-99dc-aa83b2b3266b active request set","v":0,"name":"crucible","level":30,"time":"2024-09-27T17:13:34.408461049Z","hostname":"w-01J8T79TZ98ARZXF9AJ1D7W0D7","pid":1223,"session_id":"81b154a5-6708-4c9c-b0d3-c5edfff6162c"}
2472024-09-27T17:13:35.935Z{"msg":"sending connect oneshot to client","v":0,"name":"crucible","level":30,"time":"2024-09-27T17:13:34.408479298Z","hostname":"w-01J8T79TZ98ARZXF9AJ1D7W0D7","pid":1223,"client":"0","":"downstairs","session_id":"81b154a5-6708-4c9c-b0d3-c5edfff6162c"}
2482024-09-27T17:13:35.940Z{"msg":"client set_active_request while in New; waiting...","v":0,"name":"crucible","level":30,"time":"2024-09-27T17:13:34.408512696Z","hostname":"w-01J8T79TZ98ARZXF9AJ1D7W0D7","pid":1223,"client":"0","":"downstairs","session_id":"81b154a5-6708-4c9c-b0d3-c5edfff6162c"}
2492024-09-27T17:13:35.941Z{"msg":"sending connect oneshot to client","v":0,"name":"crucible","level":30,"time":"2024-09-27T17:13:34.408553015Z","hostname":"w-01J8T79TZ98ARZXF9AJ1D7W0D7","pid":1223,"client":"1","":"downstairs","session_id":"81b154a5-6708-4c9c-b0d3-c5edfff6162c"}
2502024-09-27T17:13:35.941Z{"msg":"client set_active_request while in New; waiting...","v":0,"name":"crucible","level":30,"time":"2024-09-27T17:13:34.408584653Z","hostname":"w-01J8T79TZ98ARZXF9AJ1D7W0D7","pid":1223,"client":"1","":"downstairs","session_id":"81b154a5-6708-4c9c-b0d3-c5edfff6162c"}
2512024-09-27T17:13:35.941Z{"msg":"sending connect oneshot to client","v":0,"name":"crucible","level":30,"time":"2024-09-27T17:13:34.408617141Z","hostname":"w-01J8T79TZ98ARZXF9AJ1D7W0D7","pid":1223,"client":"2","":"downstairs","session_id":"81b154a5-6708-4c9c-b0d3-c5edfff6162c"}
2522024-09-27T17:13:35.941Z{"msg":"client set_active_request while in New; waiting...","v":0,"name":"crucible","level":30,"time":"2024-09-27T17:13:34.40865158Z","hostname":"w-01J8T79TZ98ARZXF9AJ1D7W0D7","pid":1223,"client":"2","":"downstairs","session_id":"81b154a5-6708-4c9c-b0d3-c5edfff6162c"}
2532024-09-27T17:13:35.941Z{"msg":"connecting to 127.0.0.1:8830","v":0,"name":"crucible","level":30,"time":"2024-09-27T17:13:34.408694228Z","hostname":"w-01J8T79TZ98ARZXF9AJ1D7W0D7","pid":1223,"":"io task","client":"2","":"downstairs","session_id":"81b154a5-6708-4c9c-b0d3-c5edfff6162c"}
2542024-09-27T17:13:35.941Z{"msg":"connecting to 127.0.0.1:8810","v":0,"name":"crucible","level":30,"time":"2024-09-27T17:13:34.408725716Z","hostname":"w-01J8T79TZ98ARZXF9AJ1D7W0D7","pid":1223,"":"io task","client":"0","":"downstairs","session_id":"81b154a5-6708-4c9c-b0d3-c5edfff6162c"}
2552024-09-27T17:13:35.941Z{"msg":"connecting to 127.0.0.1:8820","v":0,"name":"crucible","level":30,"time":"2024-09-27T17:13:34.408977794Z","hostname":"w-01J8T79TZ98ARZXF9AJ1D7W0D7","pid":1223,"":"io task","client":"1","":"downstairs","session_id":"81b154a5-6708-4c9c-b0d3-c5edfff6162c"}
2562024-09-27T17:13:35.942Z{"msg":"ds_connection connected from Ok(127.0.0.1:61343)","v":0,"name":"crucible","level":30,"time":"2024-09-27T17:13:34.409026942Z","hostname":"w-01J8T79TZ98ARZXF9AJ1D7W0D7","pid":1223,"":"io task","client":"0","":"downstairs","session_id":"81b154a5-6708-4c9c-b0d3-c5edfff6162c"}
2572024-09-27T17:13:35.942Z{"msg":"ds_connection connected from Ok(127.0.0.1:41168)","v":0,"name":"crucible","level":30,"time":"2024-09-27T17:13:34.40906894Z","hostname":"w-01J8T79TZ98ARZXF9AJ1D7W0D7","pid":1223,"":"io task","client":"1","":"downstairs","session_id":"81b154a5-6708-4c9c-b0d3-c5edfff6162c"}
2582024-09-27T17:13:35.942Z{"msg":"ds_connection connected from Ok(127.0.0.1:45558)","v":0,"name":"crucible","level":30,"time":"2024-09-27T17:13:34.409093489Z","hostname":"w-01J8T79TZ98ARZXF9AJ1D7W0D7","pid":1223,"":"io task","client":"2","":"downstairs","session_id":"81b154a5-6708-4c9c-b0d3-c5edfff6162c"}
2592024-09-27T17:13:35.942Z{"msg":"ds_transition from New to WaitActive","v":0,"name":"crucible","level":30,"time":"2024-09-27T17:13:34.409618004Z","hostname":"w-01J8T79TZ98ARZXF9AJ1D7W0D7","pid":1223,"client":"1","":"downstairs","session_id":"81b154a5-6708-4c9c-b0d3-c5edfff6162c"}
2602024-09-27T17:13:35.942Z{"msg":"[1] Transition from New to WaitActive","v":0,"name":"crucible","level":30,"time":"2024-09-27T17:13:34.409655422Z","hostname":"w-01J8T79TZ98ARZXF9AJ1D7W0D7","pid":1223,"client":"1","":"downstairs","session_id":"81b154a5-6708-4c9c-b0d3-c5edfff6162c"}
2612024-09-27T17:13:35.942Z{"msg":"ds_transition from New to WaitActive","v":0,"name":"crucible","level":30,"time":"2024-09-27T17:13:34.409670731Z","hostname":"w-01J8T79TZ98ARZXF9AJ1D7W0D7","pid":1223,"client":"2","":"downstairs","session_id":"81b154a5-6708-4c9c-b0d3-c5edfff6162c"}
2622024-09-27T17:13:35.942Z{"msg":"[2] Transition from New to WaitActive","v":0,"name":"crucible","level":30,"time":"2024-09-27T17:13:34.4097035Z","hostname":"w-01J8T79TZ98ARZXF9AJ1D7W0D7","pid":1223,"client":"2","":"downstairs","session_id":"81b154a5-6708-4c9c-b0d3-c5edfff6162c"}
2632024-09-27T17:13:35.942Z{"msg":"ds_transition from New to WaitActive","v":0,"name":"crucible","level":30,"time":"2024-09-27T17:13:34.409749618Z","hostname":"w-01J8T79TZ98ARZXF9AJ1D7W0D7","pid":1223,"client":"0","":"downstairs","session_id":"81b154a5-6708-4c9c-b0d3-c5edfff6162c"}
2642024-09-27T17:13:35.942Z{"msg":"[0] Transition from New to WaitActive","v":0,"name":"crucible","level":30,"time":"2024-09-27T17:13:34.409783686Z","hostname":"w-01J8T79TZ98ARZXF9AJ1D7W0D7","pid":1223,"client":"0","":"downstairs","session_id":"81b154a5-6708-4c9c-b0d3-c5edfff6162c"}
2652024-09-27T17:13:35.943Z{"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-09-27T17:13:34.410236224Z","hostname":"w-01J8T79TZ98ARZXF9AJ1D7W0D7","pid":1223,"client":"0","":"downstairs","session_id":"81b154a5-6708-4c9c-b0d3-c5edfff6162c"}
2662024-09-27T17:13:35.943Z{"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-09-27T17:13:34.410358469Z","hostname":"w-01J8T79TZ98ARZXF9AJ1D7W0D7","pid":1223,"client":"1","":"downstairs","session_id":"81b154a5-6708-4c9c-b0d3-c5edfff6162c"}
2672024-09-27T17:13:35.943Z{"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-09-27T17:13:34.410568179Z","hostname":"w-01J8T79TZ98ARZXF9AJ1D7W0D7","pid":1223,"client":"2","":"downstairs","session_id":"81b154a5-6708-4c9c-b0d3-c5edfff6162c"}
2682024-09-27T17:13:35.943Z{"msg":"ds_transition from WaitActive to WaitQuorum","v":0,"name":"crucible","level":30,"time":"2024-09-27T17:13:34.410774309Z","hostname":"w-01J8T79TZ98ARZXF9AJ1D7W0D7","pid":1223,"client":"1","":"downstairs","session_id":"81b154a5-6708-4c9c-b0d3-c5edfff6162c"}
2692024-09-27T17:13:35.943Z{"msg":"[1] Transition from WaitActive to WaitQuorum","v":0,"name":"crucible","level":30,"time":"2024-09-27T17:13:34.410827456Z","hostname":"w-01J8T79TZ98ARZXF9AJ1D7W0D7","pid":1223,"client":"1","":"downstairs","session_id":"81b154a5-6708-4c9c-b0d3-c5edfff6162c"}
2702024-09-27T17:13:35.943Z{"msg":"Waiting for more clients to be ready","v":0,"name":"crucible","level":30,"time":"2024-09-27T17:13:34.410865075Z","hostname":"w-01J8T79TZ98ARZXF9AJ1D7W0D7","pid":1223,"session_id":"81b154a5-6708-4c9c-b0d3-c5edfff6162c"}
2712024-09-27T17:13:35.944Z{"msg":"ds_transition from WaitActive to WaitQuorum","v":0,"name":"crucible","level":30,"time":"2024-09-27T17:13:34.410885974Z","hostname":"w-01J8T79TZ98ARZXF9AJ1D7W0D7","pid":1223,"client":"0","":"downstairs","session_id":"81b154a5-6708-4c9c-b0d3-c5edfff6162c"}
2722024-09-27T17:13:35.944Z{"msg":"[0] Transition from WaitActive to WaitQuorum","v":0,"name":"crucible","level":30,"time":"2024-09-27T17:13:34.410899853Z","hostname":"w-01J8T79TZ98ARZXF9AJ1D7W0D7","pid":1223,"client":"0","":"downstairs","session_id":"81b154a5-6708-4c9c-b0d3-c5edfff6162c"}
2732024-09-27T17:13:35.944Z{"msg":"Waiting for more clients to be ready","v":0,"name":"crucible","level":30,"time":"2024-09-27T17:13:34.410926932Z","hostname":"w-01J8T79TZ98ARZXF9AJ1D7W0D7","pid":1223,"session_id":"81b154a5-6708-4c9c-b0d3-c5edfff6162c"}
2742024-09-27T17:13:35.944Z{"msg":"ds_transition from WaitActive to WaitQuorum","v":0,"name":"crucible","level":30,"time":"2024-09-27T17:13:34.410943261Z","hostname":"w-01J8T79TZ98ARZXF9AJ1D7W0D7","pid":1223,"client":"2","":"downstairs","session_id":"81b154a5-6708-4c9c-b0d3-c5edfff6162c"}
2752024-09-27T17:13:35.944Z{"msg":"[2] Transition from WaitActive to WaitQuorum","v":0,"name":"crucible","level":30,"time":"2024-09-27T17:13:34.41096735Z","hostname":"w-01J8T79TZ98ARZXF9AJ1D7W0D7","pid":1223,"client":"2","":"downstairs","session_id":"81b154a5-6708-4c9c-b0d3-c5edfff6162c"}
2762024-09-27T17:13:35.944Z{"msg":"[0]R flush_numbers: [1689, 1689, 1689, 1689, 1689]","v":0,"name":"crucible","level":30,"time":"2024-09-27T17:13:34.410981329Z","hostname":"w-01J8T79TZ98ARZXF9AJ1D7W0D7","pid":1223,"":"downstairs","":"downstairs","session_id":"81b154a5-6708-4c9c-b0d3-c5edfff6162c"}
2772024-09-27T17:13:35.944Z{"msg":"[0]R generation: [31, 31, 31, 31, 31]","v":0,"name":"crucible","level":30,"time":"2024-09-27T17:13:34.411001588Z","hostname":"w-01J8T79TZ98ARZXF9AJ1D7W0D7","pid":1223,"":"downstairs","":"downstairs","session_id":"81b154a5-6708-4c9c-b0d3-c5edfff6162c"}
2782024-09-27T17:13:35.944Z{"msg":"[0]R dirty: [false, false, false, false, false]","v":0,"name":"crucible","level":30,"time":"2024-09-27T17:13:34.411015407Z","hostname":"w-01J8T79TZ98ARZXF9AJ1D7W0D7","pid":1223,"":"downstairs","":"downstairs","session_id":"81b154a5-6708-4c9c-b0d3-c5edfff6162c"}
2792024-09-27T17:13:35.945Z{"msg":"[1]R flush_numbers: [1689, 1689, 1689, 1689, 1689]","v":0,"name":"crucible","level":30,"time":"2024-09-27T17:13:34.411029357Z","hostname":"w-01J8T79TZ98ARZXF9AJ1D7W0D7","pid":1223,"":"downstairs","":"downstairs","session_id":"81b154a5-6708-4c9c-b0d3-c5edfff6162c"}
2802024-09-27T17:13:35.945Z{"msg":"[1]R generation: [31, 31, 31, 31, 31]","v":0,"name":"crucible","level":30,"time":"2024-09-27T17:13:34.411042596Z","hostname":"w-01J8T79TZ98ARZXF9AJ1D7W0D7","pid":1223,"":"downstairs","":"downstairs","session_id":"81b154a5-6708-4c9c-b0d3-c5edfff6162c"}
2812024-09-27T17:13:35.945Z{"msg":"[1]R dirty: [false, false, false, false, false]","v":0,"name":"crucible","level":30,"time":"2024-09-27T17:13:34.411062435Z","hostname":"w-01J8T79TZ98ARZXF9AJ1D7W0D7","pid":1223,"":"downstairs","":"downstairs","session_id":"81b154a5-6708-4c9c-b0d3-c5edfff6162c"}
2822024-09-27T17:13:35.945Z{"msg":"[2]R flush_numbers: [1689, 1689, 1689, 1689, 1689]","v":0,"name":"crucible","level":30,"time":"2024-09-27T17:13:34.411086634Z","hostname":"w-01J8T79TZ98ARZXF9AJ1D7W0D7","pid":1223,"":"downstairs","":"downstairs","session_id":"81b154a5-6708-4c9c-b0d3-c5edfff6162c"}
2832024-09-27T17:13:35.945Z{"msg":"[2]R generation: [31, 31, 31, 31, 31]","v":0,"name":"crucible","level":30,"time":"2024-09-27T17:13:34.411111333Z","hostname":"w-01J8T79TZ98ARZXF9AJ1D7W0D7","pid":1223,"":"downstairs","":"downstairs","session_id":"81b154a5-6708-4c9c-b0d3-c5edfff6162c"}
2842024-09-27T17:13:35.945Z{"msg":"[2]R dirty: [false, false, false, false, false]","v":0,"name":"crucible","level":30,"time":"2024-09-27T17:13:34.411133862Z","hostname":"w-01J8T79TZ98ARZXF9AJ1D7W0D7","pid":1223,"":"downstairs","":"downstairs","session_id":"81b154a5-6708-4c9c-b0d3-c5edfff6162c"}
2852024-09-27T17:13:35.945Z{"msg":"Max found gen is 32","v":0,"name":"crucible","level":30,"time":"2024-09-27T17:13:34.411154181Z","hostname":"w-01J8T79TZ98ARZXF9AJ1D7W0D7","pid":1223,"":"downstairs","":"downstairs","session_id":"81b154a5-6708-4c9c-b0d3-c5edfff6162c"}
2862024-09-27T17:13:35.945Z{"msg":"Generation requested: 32 >= found:32","v":0,"name":"crucible","level":30,"time":"2024-09-27T17:13:34.41116775Z","hostname":"w-01J8T79TZ98ARZXF9AJ1D7W0D7","pid":1223,"":"downstairs","":"downstairs","session_id":"81b154a5-6708-4c9c-b0d3-c5edfff6162c"}
2872024-09-27T17:13:35.945ZWait for a query_work_queue command to finish before sending IO
2882024-09-27T17:13:35.945Z{"msg":"Next flush: 1690","v":0,"name":"crucible","level":30,"time":"2024-09-27T17:13:34.411201389Z","hostname":"w-01J8T79TZ98ARZXF9AJ1D7W0D7","pid":1223,"":"downstairs","":"downstairs","session_id":"81b154a5-6708-4c9c-b0d3-c5edfff6162c"}
2892024-09-27T17:13:35.945Z{"msg":"All extents match","v":0,"name":"crucible","level":30,"time":"2024-09-27T17:13:34.411221148Z","hostname":"w-01J8T79TZ98ARZXF9AJ1D7W0D7","pid":1223,"":"downstairs","":"downstairs","session_id":"81b154a5-6708-4c9c-b0d3-c5edfff6162c"}
2902024-09-27T17:13:35.946Z{"msg":"No downstairs reconciliation required","v":0,"name":"crucible","level":30,"time":"2024-09-27T17:13:34.411234587Z","hostname":"w-01J8T79TZ98ARZXF9AJ1D7W0D7","pid":1223,"session_id":"81b154a5-6708-4c9c-b0d3-c5edfff6162c"}
2912024-09-27T17:13:35.946Z{"msg":"Transition from WaitQuorum to Active","v":0,"name":"crucible","level":30,"time":"2024-09-27T17:13:34.411253546Z","hostname":"w-01J8T79TZ98ARZXF9AJ1D7W0D7","pid":1223,"client":"0","":"downstairs","session_id":"81b154a5-6708-4c9c-b0d3-c5edfff6162c"}
2922024-09-27T17:13:35.946Z{"msg":"Transition from WaitQuorum to Active","v":0,"name":"crucible","level":30,"time":"2024-09-27T17:13:34.411267786Z","hostname":"w-01J8T79TZ98ARZXF9AJ1D7W0D7","pid":1223,"client":"1","":"downstairs","session_id":"81b154a5-6708-4c9c-b0d3-c5edfff6162c"}
2932024-09-27T17:13:35.946Z{"msg":"Transition from WaitQuorum to Active","v":0,"name":"crucible","level":30,"time":"2024-09-27T17:13:34.411288134Z","hostname":"w-01J8T79TZ98ARZXF9AJ1D7W0D7","pid":1223,"client":"2","":"downstairs","session_id":"81b154a5-6708-4c9c-b0d3-c5edfff6162c"}
2942024-09-27T17:13:35.946Z{"msg":"All required reconciliation work is completed","v":0,"name":"crucible","level":30,"time":"2024-09-27T17:13:34.411301474Z","hostname":"w-01J8T79TZ98ARZXF9AJ1D7W0D7","pid":1223,"session_id":"81b154a5-6708-4c9c-b0d3-c5edfff6162c"}
2952024-09-27T17:13:35.946Z{"msg":"Set Downstairs and Upstairs active after reconciliation","v":0,"name":"crucible","level":30,"time":"2024-09-27T17:13:34.411320633Z","hostname":"w-01J8T79TZ98ARZXF9AJ1D7W0D7","pid":1223,"session_id":"81b154a5-6708-4c9c-b0d3-c5edfff6162c"}
2962024-09-27T17:13:35.946Z{"msg":"1009559a-3d73-4efc-99dc-aa83b2b3266b is now active with session: 81b154a5-6708-4c9c-b0d3-c5edfff6162c","v":0,"name":"crucible","level":30,"time":"2024-09-27T17:13:34.411333572Z","hostname":"w-01J8T79TZ98ARZXF9AJ1D7W0D7","pid":1223,"session_id":"81b154a5-6708-4c9c-b0d3-c5edfff6162c"}
2972024-09-27T17:13:35.946Z{"msg":"Set Active after no reconciliation","v":0,"name":"crucible","level":30,"time":"2024-09-27T17:13:34.411345452Z","hostname":"w-01J8T79TZ98ARZXF9AJ1D7W0D7","pid":1223,"session_id":"81b154a5-6708-4c9c-b0d3-c5edfff6162c"}
2982024-09-27T17:13:35.946Z{"msg":"The guest has finished waiting for activation with:32","v":0,"name":"crucible","level":30,"time":"2024-09-27T17:13:34.411357451Z","hostname":"w-01J8T79TZ98ARZXF9AJ1D7W0D7","pid":1223}
2992024-09-27T17:13:35.946ZRegion: es:10 ec:5 bs:4096 ts:204800 tb:50 max_io:50 or 204800
3002024-09-27T17:13:35.946ZLoading write count information from file "/var/tmp/test_up-build/verify_file"
3012024-09-27T17:13:35.947ZRun Repair workload
3022024-09-27T17:13:35.947Z01/10 Write block 6 len 40960 data: 2 2 2 2 2 2 2 2 2 2
3032024-09-27T17:13:35.947Z02/10 Read block 45 len 16384
3042024-09-27T17:13:35.954Z03/10 Read block 4 len 24576
3052024-09-27T17:13:35.958Z04/10 Write block 41 len 28672 data: 2 2 2 2 2 2 2
3062024-09-27T17:13:35.958Z05/10 Write block 10 len 4096 data: 3
3072024-09-27T17:13:35.958Z06/10 Write block 16 len 32768 data: 2 2 2 2 2 2 2 2
3082024-09-27T17:13:35.958Z07/10 Write block 43 len 16384 data: 3 3 3 3
3092024-09-27T17:13:35.958Z08/10 Read block 15 len 40960
3102024-09-27T17:13:35.973Z09/10 Write block 15 len 32768 data: 3 3 3 3 3 3 3 3
3112024-09-27T17:13:35.976Z10/10 Read block 19 len 36864
3122024-09-27T17:13:35.987Z----------------------------------------------------------------
3132024-09-27T17:13:35.987Z Crucible gen:32 GIO:true work queues: Upstairs:0 downstairs:10
3142024-09-27T17:13:35.987ZStates: Active Active Active
3152024-09-27T17:13:35.987ZGW_ID ACK DSID TYPE BKS/EXT DS:0 DS:1 DS:2 REPLAY
3162024-09-27T17:13:35.987Z 1 Acked 1000 Write 10 Done Done Done false
3172024-09-27T17:13:35.987Z 2 Acked 1001 Read 4 Done Done Done false
3182024-09-27T17:13:35.987Z 3 Acked 1002 Read 6 Done Done Done false
3192024-09-27T17:13:35.988Z 4 Acked 1003 Write 7 Done Done Done false
3202024-09-27T17:13:35.988Z 5 Acked 1004 Write 1 Done Done Done false
3212024-09-27T17:13:35.988Z 6 Acked 1005 Write 8 Done Done Done false
3222024-09-27T17:13:35.988Z 7 Acked 1006 Write 4 Done Done Done false
3232024-09-27T17:13:35.988Z 8 Acked 1007 Read 10 Done Done Done false
3242024-09-27T17:13:35.988Z 9 Acked 1008 Write 8 Done Done Done false
3252024-09-27T17:13:35.988Z 10 Acked 1009 Read 9 Done Sent Sent false
3262024-09-27T17:13:35.988Z STATES DS:0 DS:1 DS:2 TOTAL
3272024-09-27T17:13:35.988Z Sent 0 1 1 2
3282024-09-27T17:13:35.988Z Done 10 9 9 28
3292024-09-27T17:13:35.988Z Skipped 0 0 0 0
3302024-09-27T17:13:35.988Z Error 0 0 0 0
3312024-09-27T17:13:35.988ZLast Flush: 0 0 0
3322024-09-27T17:13:35.988ZDownstairs last five completed:
3332024-09-27T17:13:35.988ZUpstairs last five completed: 10 9 8 7 6
3342024-09-27T17:13:35.991Z{"msg":"Guest handle has been dropped","v":0,"name":"crucible","level":40,"time":"2024-09-27T17:13:34.46146669Z","hostname":"w-01J8T79TZ98ARZXF9AJ1D7W0D7","pid":1223}
3352024-09-27T17:13:35.991ZWrote out file "/var/tmp/test_up-build/verify_file"
3362024-09-27T17:13:35.994ZRepair part 1 passed
3372024-09-27T17:13:35.994Z
3382024-09-27T17:13:35.994ZKill the current downstairs
3392024-09-27T17:13:36.103Zrm -rf /var/tmp/test_up-build/8830
3402024-09-27T17:13:36.104ZNow put back the original so we have a mismatch
3412024-09-27T17:13:36.104Zmv /var/tmp/test_up-build/previous /var/tmp/test_up-build/8830
3422024-09-27T17:13:36.107ZRestart downstairs with old directory
3432024-09-27T17:13:36.163Z/var/tmp/bins/crucible-downstairs dump --no-color -d /var/tmp/test_up-build/8810 -d /var/tmp/test_up-build/8820 -d /var/tmp/test_up-build/8830
3442024-09-27T17:13:36.180ZEXT BLOCKS GEN0 GEN1 GEN2 FL0 FL1 FL2 D0 D1 D2 DIFF
3452024-09-27T17:13:36.182Z 0 000-009 31 31 31 1689 1689 1689 T T F <---
3462024-09-27T17:13:36.182Z 1 010-019 31 31 31 1689 1689 1689 T T F <---
3472024-09-27T17:13:36.182Z 2 020-029 31 31 31 1689 1689 1689 T T F <---
3482024-09-27T17:13:36.183Z 3 030-039 31 31 31 1689 1689 1689 F F F
3492024-09-27T17:13:36.183Z 4 040-049 31 31 31 1689 1689 1689 T T F <---
3502024-09-27T17:13:36.183ZMax gen: 31, Max flush: 1689
3512024-09-27T17:13:36.183ZError: Difference in extent metadata found!
3522024-09-27T17:13:36.186Zdump test found error as expected
3532024-09-27T17:13:36.186Z
3542024-09-27T17:13:36.186Z
3552024-09-27T17:13:36.186Z/var/tmp/bins/crutest verify --range -g 33 -q --key rWzZG8E/8XgqIm3XrvGn0g0nYOJ/sNiEzEskSoS4E9U= -t 127.0.0.1:8810 -t 127.0.0.1:8820 -t 127.0.0.1:8830 --verify-out /var/tmp/test_up-build/verify_file --verify-in /var/tmp/test_up-build/verify_file
3562024-09-27T17:13:36.198Z{"msg":"look at: http://127.0.0.1:12810 ","v":0,"name":"crucible","level":30,"time":"2024-09-27T17:13:34.672050115Z","hostname":"w-01J8T79TZ98ARZXF9AJ1D7W0D7","pid":1230,"task":"crutest"}
3572024-09-27T17:13:36.241Z{"msg":"RI is: RegionDefinition { block_size: 4096, extent_size: Block { value: 10, shift: 12 }, extent_count: 5, uuid: 12345678-0000-0000-0000-000000008810, encrypted: true, database_read_version: 1, database_write_version: 1 }","v":0,"name":"crucible","level":30,"time":"2024-09-27T17:13:34.71551621Z","hostname":"w-01J8T79TZ98ARZXF9AJ1D7W0D7","pid":1230,"task":"crutest"}
3582024-09-27T17:13:36.243Z{"msg":"Upstairs starts","v":0,"name":"crucible","level":30,"time":"2024-09-27T17:13:34.716288554Z","hostname":"w-01J8T79TZ98ARZXF9AJ1D7W0D7","pid":1230}
3592024-09-27T17:13:36.243Z{"msg":"Crucible Version: BuildInfo {\n version: \"0.0.1\",\n git_sha: \"93b12f70ee7c1993c73ac4256d99ff80ccbe4bac\",\n git_commit_timestamp: \"2024-09-27T16:52:31.000000000Z\",\n git_branch: \"update-omicron-common\",\n rustc_semver: \"1.80.0\",\n rustc_channel: \"stable\",\n rustc_host_triple: \"x86_64-unknown-illumos\",\n rustc_commit_sha: \"051478957371ee0084a7c0913941d2a8c4757bb9\",\n cargo_triple: \"x86_64-unknown-illumos\",\n debug: true,\n opt_level: 0,\n}","v":0,"name":"crucible","level":30,"time":"2024-09-27T17:13:34.716330712Z","hostname":"w-01J8T79TZ98ARZXF9AJ1D7W0D7","pid":1230}
3602024-09-27T17:13:36.244Z{"msg":"Upstairs <-> Downstairs Message Version: 11","v":0,"name":"crucible","level":30,"time":"2024-09-27T17:13:34.716347831Z","hostname":"w-01J8T79TZ98ARZXF9AJ1D7W0D7","pid":1230}
3612024-09-27T17:13:36.244Z{"msg":"Using region definition RegionDefinition { block_size: 4096, extent_size: Block { value: 10, shift: 12 }, extent_count: 5, uuid: 00000000-0000-0000-0000-000000000000, encrypted: true, database_read_version: 1, database_write_version: 1 }","v":0,"name":"crucible","level":30,"time":"2024-09-27T17:13:34.7163704Z","hostname":"w-01J8T79TZ98ARZXF9AJ1D7W0D7","pid":1230}
3622024-09-27T17:13:36.244Z{"msg":"Crucible c7d40530-c950-4128-a645-c384a86d62f2 has session id: 7e4dc9d6-72a4-443b-80a5-97e066c91131","v":0,"name":"crucible","level":30,"time":"2024-09-27T17:13:34.716822138Z","hostname":"w-01J8T79TZ98ARZXF9AJ1D7W0D7","pid":1230,"session_id":"7e4dc9d6-72a4-443b-80a5-97e066c91131"}
3632024-09-27T17:13:36.244Z{"msg":"Upstairs opts: Upstairs UUID: c7d40530-c950-4128-a645-c384a86d62f2, 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-09-27T17:13:34.716885155Z","hostname":"w-01J8T79TZ98ARZXF9AJ1D7W0D7","pid":1230,"session_id":"7e4dc9d6-72a4-443b-80a5-97e066c91131"}
3642024-09-27T17:13:36.244Z{"msg":"Crucible stats registered with UUID: c7d40530-c950-4128-a645-c384a86d62f2","v":0,"name":"crucible","level":30,"time":"2024-09-27T17:13:34.716905864Z","hostname":"w-01J8T79TZ98ARZXF9AJ1D7W0D7","pid":1230,"session_id":"7e4dc9d6-72a4-443b-80a5-97e066c91131"}
3652024-09-27T17:13:36.278Z{"msg":"The guest has requested activation with gen:33","v":0,"name":"crucible","level":30,"time":"2024-09-27T17:13:34.748034875Z","hostname":"w-01J8T79TZ98ARZXF9AJ1D7W0D7","pid":1230}
3662024-09-27T17:13:36.278Z{"msg":"c7d40530-c950-4128-a645-c384a86d62f2 active request set","v":0,"name":"crucible","level":30,"time":"2024-09-27T17:13:34.748077563Z","hostname":"w-01J8T79TZ98ARZXF9AJ1D7W0D7","pid":1230,"session_id":"7e4dc9d6-72a4-443b-80a5-97e066c91131"}
3672024-09-27T17:13:36.278Z{"msg":"sending connect oneshot to client","v":0,"name":"crucible","level":30,"time":"2024-09-27T17:13:34.748096272Z","hostname":"w-01J8T79TZ98ARZXF9AJ1D7W0D7","pid":1230,"client":"0","":"downstairs","session_id":"7e4dc9d6-72a4-443b-80a5-97e066c91131"}
3682024-09-27T17:13:36.281Z{"msg":"client set_active_request while in New; waiting...","v":0,"name":"crucible","level":30,"time":"2024-09-27T17:13:34.74813942Z","hostname":"w-01J8T79TZ98ARZXF9AJ1D7W0D7","pid":1230,"client":"0","":"downstairs","session_id":"7e4dc9d6-72a4-443b-80a5-97e066c91131"}
3692024-09-27T17:13:36.282Z{"msg":"sending connect oneshot to client","v":0,"name":"crucible","level":30,"time":"2024-09-27T17:13:34.748186878Z","hostname":"w-01J8T79TZ98ARZXF9AJ1D7W0D7","pid":1230,"client":"1","":"downstairs","session_id":"7e4dc9d6-72a4-443b-80a5-97e066c91131"}
3702024-09-27T17:13:36.282Z{"msg":"client set_active_request while in New; waiting...","v":0,"name":"crucible","level":30,"time":"2024-09-27T17:13:34.748223296Z","hostname":"w-01J8T79TZ98ARZXF9AJ1D7W0D7","pid":1230,"client":"1","":"downstairs","session_id":"7e4dc9d6-72a4-443b-80a5-97e066c91131"}
3712024-09-27T17:13:36.282Z{"msg":"sending connect oneshot to client","v":0,"name":"crucible","level":30,"time":"2024-09-27T17:13:34.748315272Z","hostname":"w-01J8T79TZ98ARZXF9AJ1D7W0D7","pid":1230,"client":"2","":"downstairs","session_id":"7e4dc9d6-72a4-443b-80a5-97e066c91131"}
3722024-09-27T17:13:36.282Z{"msg":"client set_active_request while in New; waiting...","v":0,"name":"crucible","level":30,"time":"2024-09-27T17:13:34.748380379Z","hostname":"w-01J8T79TZ98ARZXF9AJ1D7W0D7","pid":1230,"client":"2","":"downstairs","session_id":"7e4dc9d6-72a4-443b-80a5-97e066c91131"}
3732024-09-27T17:13:36.282Z{"msg":"connecting to 127.0.0.1:8830","v":0,"name":"crucible","level":30,"time":"2024-09-27T17:13:34.748431907Z","hostname":"w-01J8T79TZ98ARZXF9AJ1D7W0D7","pid":1230,"":"io task","client":"2","":"downstairs","session_id":"7e4dc9d6-72a4-443b-80a5-97e066c91131"}
3742024-09-27T17:13:36.282Z{"msg":"connecting to 127.0.0.1:8810","v":0,"name":"crucible","level":30,"time":"2024-09-27T17:13:34.748525632Z","hostname":"w-01J8T79TZ98ARZXF9AJ1D7W0D7","pid":1230,"":"io task","client":"0","":"downstairs","session_id":"7e4dc9d6-72a4-443b-80a5-97e066c91131"}
3752024-09-27T17:13:36.282Z{"msg":"connecting to 127.0.0.1:8820","v":0,"name":"crucible","level":30,"time":"2024-09-27T17:13:34.748615808Z","hostname":"w-01J8T79TZ98ARZXF9AJ1D7W0D7","pid":1230,"":"io task","client":"1","":"downstairs","session_id":"7e4dc9d6-72a4-443b-80a5-97e066c91131"}
3762024-09-27T17:13:36.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-09-27T17:13:34.748685844Z","hostname":"w-01J8T79TZ98ARZXF9AJ1D7W0D7","pid":1230,"":"io task","client":"2","":"downstairs","session_id":"7e4dc9d6-72a4-443b-80a5-97e066c91131"}
3772024-09-27T17:13:36.282Z{"msg":"client task is sending Done(ConnectionFailed(Os { code: 146, kind: ConnectionRefused, message: \"Connection refused\" }))","v":0,"name":"crucible","level":40,"time":"2024-09-27T17:13:34.748746961Z","hostname":"w-01J8T79TZ98ARZXF9AJ1D7W0D7","pid":1230,"":"io task","client":"2","":"downstairs","session_id":"7e4dc9d6-72a4-443b-80a5-97e066c91131"}
3782024-09-27T17:13:36.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-09-27T17:13:34.748796559Z","hostname":"w-01J8T79TZ98ARZXF9AJ1D7W0D7","pid":1230,"session_id":"7e4dc9d6-72a4-443b-80a5-97e066c91131"}
3792024-09-27T17:13:36.282Z{"msg":"Gone missing, transition from New to Disconnected","v":0,"name":"crucible","level":30,"time":"2024-09-27T17:13:34.748817618Z","hostname":"w-01J8T79TZ98ARZXF9AJ1D7W0D7","pid":1230,"client":"2","":"downstairs","session_id":"7e4dc9d6-72a4-443b-80a5-97e066c91131"}
3802024-09-27T17:13:36.282Z{"msg":"Disconnected -> New","v":0,"name":"crucible","level":30,"time":"2024-09-27T17:13:34.748843737Z","hostname":"w-01J8T79TZ98ARZXF9AJ1D7W0D7","pid":1230,"client":"2","":"downstairs","session_id":"7e4dc9d6-72a4-443b-80a5-97e066c91131"}
3812024-09-27T17:13:36.282Z{"msg":"ds_connection connected from Ok(127.0.0.1:50479)","v":0,"name":"crucible","level":30,"time":"2024-09-27T17:13:34.748862126Z","hostname":"w-01J8T79TZ98ARZXF9AJ1D7W0D7","pid":1230,"":"io task","client":"0","":"downstairs","session_id":"7e4dc9d6-72a4-443b-80a5-97e066c91131"}
3822024-09-27T17:13:36.282Z{"msg":"client task is exiting","v":0,"name":"crucible","level":30,"time":"2024-09-27T17:13:34.748933363Z","hostname":"w-01J8T79TZ98ARZXF9AJ1D7W0D7","pid":1230,"":"io task","client":"2","":"downstairs","session_id":"7e4dc9d6-72a4-443b-80a5-97e066c91131"}
3832024-09-27T17:13:36.282Z{"msg":"ds_connection connected from Ok(127.0.0.1:35432)","v":0,"name":"crucible","level":30,"time":"2024-09-27T17:13:34.74898549Z","hostname":"w-01J8T79TZ98ARZXF9AJ1D7W0D7","pid":1230,"":"io task","client":"1","":"downstairs","session_id":"7e4dc9d6-72a4-443b-80a5-97e066c91131"}
3842024-09-27T17:13:36.282Z{"msg":"ds_transition from New to WaitActive","v":0,"name":"crucible","level":30,"time":"2024-09-27T17:13:34.74919486Z","hostname":"w-01J8T79TZ98ARZXF9AJ1D7W0D7","pid":1230,"client":"0","":"downstairs","session_id":"7e4dc9d6-72a4-443b-80a5-97e066c91131"}
3852024-09-27T17:13:36.282Z{"msg":"[0] Transition from New to WaitActive","v":0,"name":"crucible","level":30,"time":"2024-09-27T17:13:34.749225589Z","hostname":"w-01J8T79TZ98ARZXF9AJ1D7W0D7","pid":1230,"client":"0","":"downstairs","session_id":"7e4dc9d6-72a4-443b-80a5-97e066c91131"}
3862024-09-27T17:13:36.282Z{"msg":"ds_transition from New to WaitActive","v":0,"name":"crucible","level":30,"time":"2024-09-27T17:13:34.749241378Z","hostname":"w-01J8T79TZ98ARZXF9AJ1D7W0D7","pid":1230,"client":"1","":"downstairs","session_id":"7e4dc9d6-72a4-443b-80a5-97e066c91131"}
3872024-09-27T17:13:36.282Z{"msg":"[1] Transition from New to WaitActive","v":0,"name":"crucible","level":30,"time":"2024-09-27T17:13:34.749299355Z","hostname":"w-01J8T79TZ98ARZXF9AJ1D7W0D7","pid":1230,"client":"1","":"downstairs","session_id":"7e4dc9d6-72a4-443b-80a5-97e066c91131"}
3882024-09-27T17:13:36.282Z{"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-09-27T17:13:34.749785052Z","hostname":"w-01J8T79TZ98ARZXF9AJ1D7W0D7","pid":1230,"client":"1","":"downstairs","session_id":"7e4dc9d6-72a4-443b-80a5-97e066c91131"}
3892024-09-27T17:13:36.282Z{"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-09-27T17:13:34.749908036Z","hostname":"w-01J8T79TZ98ARZXF9AJ1D7W0D7","pid":1230,"client":"0","":"downstairs","session_id":"7e4dc9d6-72a4-443b-80a5-97e066c91131"}
3902024-09-27T17:13:36.282Z{"msg":"ds_transition from WaitActive to WaitQuorum","v":0,"name":"crucible","level":30,"time":"2024-09-27T17:13:34.750127966Z","hostname":"w-01J8T79TZ98ARZXF9AJ1D7W0D7","pid":1230,"client":"1","":"downstairs","session_id":"7e4dc9d6-72a4-443b-80a5-97e066c91131"}
3912024-09-27T17:13:36.282Z{"msg":"[1] Transition from WaitActive to WaitQuorum","v":0,"name":"crucible","level":30,"time":"2024-09-27T17:13:34.750180533Z","hostname":"w-01J8T79TZ98ARZXF9AJ1D7W0D7","pid":1230,"client":"1","":"downstairs","session_id":"7e4dc9d6-72a4-443b-80a5-97e066c91131"}
3922024-09-27T17:13:36.282Z{"msg":"Waiting for more clients to be ready","v":0,"name":"crucible","level":30,"time":"2024-09-27T17:13:34.750216472Z","hostname":"w-01J8T79TZ98ARZXF9AJ1D7W0D7","pid":1230,"session_id":"7e4dc9d6-72a4-443b-80a5-97e066c91131"}
3932024-09-27T17:13:36.282Z{"msg":"ds_transition from WaitActive to WaitQuorum","v":0,"name":"crucible","level":30,"time":"2024-09-27T17:13:34.75025803Z","hostname":"w-01J8T79TZ98ARZXF9AJ1D7W0D7","pid":1230,"client":"0","":"downstairs","session_id":"7e4dc9d6-72a4-443b-80a5-97e066c91131"}
3942024-09-27T17:13:36.282Z{"msg":"[0] Transition from WaitActive to WaitQuorum","v":0,"name":"crucible","level":30,"time":"2024-09-27T17:13:34.750286908Z","hostname":"w-01J8T79TZ98ARZXF9AJ1D7W0D7","pid":1230,"client":"0","":"downstairs","session_id":"7e4dc9d6-72a4-443b-80a5-97e066c91131"}
3952024-09-27T17:13:36.282Z{"msg":"Waiting for more clients to be ready","v":0,"name":"crucible","level":30,"time":"2024-09-27T17:13:34.750317487Z","hostname":"w-01J8T79TZ98ARZXF9AJ1D7W0D7","pid":1230,"session_id":"7e4dc9d6-72a4-443b-80a5-97e066c91131"}
3962024-09-27T17:13:46.278Z{"msg":"connecting to 127.0.0.1:8830","v":0,"name":"crucible","level":30,"time":"2024-09-27T17:13:44.750432883Z","hostname":"w-01J8T79TZ98ARZXF9AJ1D7W0D7","pid":1230,"":"io task","client":"2","":"downstairs","session_id":"7e4dc9d6-72a4-443b-80a5-97e066c91131"}
3972024-09-27T17:13:46.282Z{"msg":"ds_connection connected from Ok(127.0.0.1:61645)","v":0,"name":"crucible","level":30,"time":"2024-09-27T17:13:44.750798216Z","hostname":"w-01J8T79TZ98ARZXF9AJ1D7W0D7","pid":1230,"":"io task","client":"2","":"downstairs","session_id":"7e4dc9d6-72a4-443b-80a5-97e066c91131"}
3982024-09-27T17:13:46.283Z{"msg":"ds_transition from New to WaitActive","v":0,"name":"crucible","level":30,"time":"2024-09-27T17:13:44.75175839Z","hostname":"w-01J8T79TZ98ARZXF9AJ1D7W0D7","pid":1230,"client":"2","":"downstairs","session_id":"7e4dc9d6-72a4-443b-80a5-97e066c91131"}
3992024-09-27T17:13:46.283Z{"msg":"[2] Transition from New to WaitActive","v":0,"name":"crucible","level":30,"time":"2024-09-27T17:13:44.751806738Z","hostname":"w-01J8T79TZ98ARZXF9AJ1D7W0D7","pid":1230,"client":"2","":"downstairs","session_id":"7e4dc9d6-72a4-443b-80a5-97e066c91131"}
4002024-09-27T17:13:46.283Z{"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-09-27T17:13:44.752346392Z","hostname":"w-01J8T79TZ98ARZXF9AJ1D7W0D7","pid":1230,"client":"2","":"downstairs","session_id":"7e4dc9d6-72a4-443b-80a5-97e066c91131"}
4012024-09-27T17:13:46.283Z{"msg":"ds_transition from WaitActive to WaitQuorum","v":0,"name":"crucible","level":30,"time":"2024-09-27T17:13:44.752725774Z","hostname":"w-01J8T79TZ98ARZXF9AJ1D7W0D7","pid":1230,"client":"2","":"downstairs","session_id":"7e4dc9d6-72a4-443b-80a5-97e066c91131"}
4022024-09-27T17:13:46.283Z{"msg":"[2] Transition from WaitActive to WaitQuorum","v":0,"name":"crucible","level":30,"time":"2024-09-27T17:13:44.752760293Z","hostname":"w-01J8T79TZ98ARZXF9AJ1D7W0D7","pid":1230,"client":"2","":"downstairs","session_id":"7e4dc9d6-72a4-443b-80a5-97e066c91131"}
4032024-09-27T17:13:46.283Z{"msg":"[0]R flush_numbers: [1689, 1689, 1689, 1689, 1689]","v":0,"name":"crucible","level":30,"time":"2024-09-27T17:13:44.752780032Z","hostname":"w-01J8T79TZ98ARZXF9AJ1D7W0D7","pid":1230,"":"downstairs","":"downstairs","session_id":"7e4dc9d6-72a4-443b-80a5-97e066c91131"}
4042024-09-27T17:13:46.283Z{"msg":"[0]R generation: [31, 31, 31, 31, 31]","v":0,"name":"crucible","level":30,"time":"2024-09-27T17:13:44.752806241Z","hostname":"w-01J8T79TZ98ARZXF9AJ1D7W0D7","pid":1230,"":"downstairs","":"downstairs","session_id":"7e4dc9d6-72a4-443b-80a5-97e066c91131"}
4052024-09-27T17:13:46.283Z{"msg":"[0]R dirty: [true, true, true, false, true]","v":0,"name":"crucible","level":30,"time":"2024-09-27T17:13:44.75282349Z","hostname":"w-01J8T79TZ98ARZXF9AJ1D7W0D7","pid":1230,"":"downstairs","":"downstairs","session_id":"7e4dc9d6-72a4-443b-80a5-97e066c91131"}
4062024-09-27T17:13:46.283Z{"msg":"[1]R flush_numbers: [1689, 1689, 1689, 1689, 1689]","v":0,"name":"crucible","level":30,"time":"2024-09-27T17:13:44.752841199Z","hostname":"w-01J8T79TZ98ARZXF9AJ1D7W0D7","pid":1230,"":"downstairs","":"downstairs","session_id":"7e4dc9d6-72a4-443b-80a5-97e066c91131"}
4072024-09-27T17:13:46.283Z{"msg":"[1]R generation: [31, 31, 31, 31, 31]","v":0,"name":"crucible","level":30,"time":"2024-09-27T17:13:44.752858288Z","hostname":"w-01J8T79TZ98ARZXF9AJ1D7W0D7","pid":1230,"":"downstairs","":"downstairs","session_id":"7e4dc9d6-72a4-443b-80a5-97e066c91131"}
4082024-09-27T17:13:46.283Z{"msg":"[1]R dirty: [true, true, true, false, true]","v":0,"name":"crucible","level":30,"time":"2024-09-27T17:13:44.752883367Z","hostname":"w-01J8T79TZ98ARZXF9AJ1D7W0D7","pid":1230,"":"downstairs","":"downstairs","session_id":"7e4dc9d6-72a4-443b-80a5-97e066c91131"}
4092024-09-27T17:13:46.283Z{"msg":"[2]R flush_numbers: [1689, 1689, 1689, 1689, 1689]","v":0,"name":"crucible","level":30,"time":"2024-09-27T17:13:44.752900416Z","hostname":"w-01J8T79TZ98ARZXF9AJ1D7W0D7","pid":1230,"":"downstairs","":"downstairs","session_id":"7e4dc9d6-72a4-443b-80a5-97e066c91131"}
4102024-09-27T17:13:46.283Z{"msg":"[2]R generation: [31, 31, 31, 31, 31]","v":0,"name":"crucible","level":30,"time":"2024-09-27T17:13:44.752924885Z","hostname":"w-01J8T79TZ98ARZXF9AJ1D7W0D7","pid":1230,"":"downstairs","":"downstairs","session_id":"7e4dc9d6-72a4-443b-80a5-97e066c91131"}
4112024-09-27T17:13:46.283Z{"msg":"[2]R dirty: [false, false, false, false, false]","v":0,"name":"crucible","level":30,"time":"2024-09-27T17:13:44.752942594Z","hostname":"w-01J8T79TZ98ARZXF9AJ1D7W0D7","pid":1230,"":"downstairs","":"downstairs","session_id":"7e4dc9d6-72a4-443b-80a5-97e066c91131"}
4122024-09-27T17:13:46.283Z{"msg":"Max found gen is 32","v":0,"name":"crucible","level":30,"time":"2024-09-27T17:13:44.752959073Z","hostname":"w-01J8T79TZ98ARZXF9AJ1D7W0D7","pid":1230,"":"downstairs","":"downstairs","session_id":"7e4dc9d6-72a4-443b-80a5-97e066c91131"}
4132024-09-27T17:13:46.283Z{"msg":"Generation requested: 33 >= found:32","v":0,"name":"crucible","level":30,"time":"2024-09-27T17:13:44.752983862Z","hostname":"w-01J8T79TZ98ARZXF9AJ1D7W0D7","pid":1230,"":"downstairs","":"downstairs","session_id":"7e4dc9d6-72a4-443b-80a5-97e066c91131"}
4142024-09-27T17:13:46.283Z{"msg":"Next flush: 1690","v":0,"name":"crucible","level":30,"time":"2024-09-27T17:13:44.753000701Z","hostname":"w-01J8T79TZ98ARZXF9AJ1D7W0D7","pid":1230,"":"downstairs","":"downstairs","session_id":"7e4dc9d6-72a4-443b-80a5-97e066c91131"}
4152024-09-27T17:13:46.283Z{"msg":"Extents 0 dirty","v":0,"name":"crucible","level":30,"time":"2024-09-27T17:13:44.75302565Z","hostname":"w-01J8T79TZ98ARZXF9AJ1D7W0D7","pid":1230,"":"mend","":"downstairs","":"downstairs","session_id":"7e4dc9d6-72a4-443b-80a5-97e066c91131"}
4162024-09-27T17:13:46.283Z{"msg":"First source client ID for extent 0","v":0,"name":"crucible","level":30,"time":"2024-09-27T17:13:44.753043369Z","hostname":"w-01J8T79TZ98ARZXF9AJ1D7W0D7","pid":1230,"mrl":"dirty","":"mend","":"downstairs","":"downstairs","session_id":"7e4dc9d6-72a4-443b-80a5-97e066c91131"}
4172024-09-27T17:13:46.283Z{"msg":"extent:0 gens: 31 31 31","v":0,"name":"crucible","level":30,"time":"2024-09-27T17:13:44.753069268Z","hostname":"w-01J8T79TZ98ARZXF9AJ1D7W0D7","pid":1230,"mrl":"dirty","":"mend","":"downstairs","":"downstairs","session_id":"7e4dc9d6-72a4-443b-80a5-97e066c91131"}
4182024-09-27T17:13:46.283Z{"msg":"extent:0 flush: 1689 1689 1689 scs: [ClientId(0), ClientId(1), ClientId(2)]","v":0,"name":"crucible","level":30,"time":"2024-09-27T17:13:44.753088957Z","hostname":"w-01J8T79TZ98ARZXF9AJ1D7W0D7","pid":1230,"mrl":"dirty","":"mend","":"downstairs","":"downstairs","session_id":"7e4dc9d6-72a4-443b-80a5-97e066c91131"}
4192024-09-27T17:13:46.283Z{"msg":"max_flush now has: [ClientId(0), ClientId(1), ClientId(2)]","v":0,"name":"crucible","level":30,"time":"2024-09-27T17:13:44.753107836Z","hostname":"w-01J8T79TZ98ARZXF9AJ1D7W0D7","pid":1230,"mrl":"dirty","":"mend","":"downstairs","":"downstairs","session_id":"7e4dc9d6-72a4-443b-80a5-97e066c91131"}
4202024-09-27T17:13:46.283Z{"msg":"extent:0 dirty: true true false","v":0,"name":"crucible","level":30,"time":"2024-09-27T17:13:44.753133705Z","hostname":"w-01J8T79TZ98ARZXF9AJ1D7W0D7","pid":1230,"mrl":"dirty","":"mend","":"downstairs","":"downstairs","session_id":"7e4dc9d6-72a4-443b-80a5-97e066c91131"}
4212024-09-27T17:13:46.283Z{"msg":"find dest for source 0 for extent at index 0","v":0,"name":"crucible","level":30,"time":"2024-09-27T17:13:44.753153044Z","hostname":"w-01J8T79TZ98ARZXF9AJ1D7W0D7","pid":1230,"mrl":"dirty","":"mend","":"downstairs","":"downstairs","session_id":"7e4dc9d6-72a4-443b-80a5-97e066c91131"}
4222024-09-27T17:13:46.283Z{"msg":"source 0, add dest 1 source flush","v":0,"name":"crucible","level":30,"time":"2024-09-27T17:13:44.753178943Z","hostname":"w-01J8T79TZ98ARZXF9AJ1D7W0D7","pid":1230,"mrl":"dirty","":"mend","":"downstairs","":"downstairs","session_id":"7e4dc9d6-72a4-443b-80a5-97e066c91131"}
4232024-09-27T17:13:46.283Z{"msg":"source 0, add dest 2 source flush","v":0,"name":"crucible","level":30,"time":"2024-09-27T17:13:44.753197662Z","hostname":"w-01J8T79TZ98ARZXF9AJ1D7W0D7","pid":1230,"mrl":"dirty","":"mend","":"downstairs","":"downstairs","session_id":"7e4dc9d6-72a4-443b-80a5-97e066c91131"}
4242024-09-27T17:13:46.283Z{"msg":"Extents 1 dirty","v":0,"name":"crucible","level":30,"time":"2024-09-27T17:13:44.75323171Z","hostname":"w-01J8T79TZ98ARZXF9AJ1D7W0D7","pid":1230,"":"mend","":"downstairs","":"downstairs","session_id":"7e4dc9d6-72a4-443b-80a5-97e066c91131"}
4252024-09-27T17:13:46.283Z{"msg":"First source client ID for extent 1","v":0,"name":"crucible","level":30,"time":"2024-09-27T17:13:44.753258879Z","hostname":"w-01J8T79TZ98ARZXF9AJ1D7W0D7","pid":1230,"mrl":"dirty","":"mend","":"downstairs","":"downstairs","session_id":"7e4dc9d6-72a4-443b-80a5-97e066c91131"}
4262024-09-27T17:13:46.284Z{"msg":"extent:1 gens: 31 31 31","v":0,"name":"crucible","level":30,"time":"2024-09-27T17:13:44.753277028Z","hostname":"w-01J8T79TZ98ARZXF9AJ1D7W0D7","pid":1230,"mrl":"dirty","":"mend","":"downstairs","":"downstairs","session_id":"7e4dc9d6-72a4-443b-80a5-97e066c91131"}
4272024-09-27T17:13:46.284Z{"msg":"extent:1 flush: 1689 1689 1689 scs: [ClientId(0), ClientId(1), ClientId(2)]","v":0,"name":"crucible","level":30,"time":"2024-09-27T17:13:44.753303667Z","hostname":"w-01J8T79TZ98ARZXF9AJ1D7W0D7","pid":1230,"mrl":"dirty","":"mend","":"downstairs","":"downstairs","session_id":"7e4dc9d6-72a4-443b-80a5-97e066c91131"}
4282024-09-27T17:13:46.284Z{"msg":"max_flush now has: [ClientId(0), ClientId(1), ClientId(2)]","v":0,"name":"crucible","level":30,"time":"2024-09-27T17:13:44.753322846Z","hostname":"w-01J8T79TZ98ARZXF9AJ1D7W0D7","pid":1230,"mrl":"dirty","":"mend","":"downstairs","":"downstairs","session_id":"7e4dc9d6-72a4-443b-80a5-97e066c91131"}
4292024-09-27T17:13:46.284Z{"msg":"extent:1 dirty: true true false","v":0,"name":"crucible","level":30,"time":"2024-09-27T17:13:44.753353704Z","hostname":"w-01J8T79TZ98ARZXF9AJ1D7W0D7","pid":1230,"mrl":"dirty","":"mend","":"downstairs","":"downstairs","session_id":"7e4dc9d6-72a4-443b-80a5-97e066c91131"}
4302024-09-27T17:13:46.284Z{"msg":"find dest for source 0 for extent at index 1","v":0,"name":"crucible","level":30,"time":"2024-09-27T17:13:44.753390833Z","hostname":"w-01J8T79TZ98ARZXF9AJ1D7W0D7","pid":1230,"mrl":"dirty","":"mend","":"downstairs","":"downstairs","session_id":"7e4dc9d6-72a4-443b-80a5-97e066c91131"}
4312024-09-27T17:13:46.284Z{"msg":"source 0, add dest 1 source flush","v":0,"name":"crucible","level":30,"time":"2024-09-27T17:13:44.753436461Z","hostname":"w-01J8T79TZ98ARZXF9AJ1D7W0D7","pid":1230,"mrl":"dirty","":"mend","":"downstairs","":"downstairs","session_id":"7e4dc9d6-72a4-443b-80a5-97e066c91131"}
4322024-09-27T17:13:46.284Z{"msg":"source 0, add dest 2 source flush","v":0,"name":"crucible","level":30,"time":"2024-09-27T17:13:44.753470849Z","hostname":"w-01J8T79TZ98ARZXF9AJ1D7W0D7","pid":1230,"mrl":"dirty","":"mend","":"downstairs","":"downstairs","session_id":"7e4dc9d6-72a4-443b-80a5-97e066c91131"}
4332024-09-27T17:13:46.284Z{"msg":"Extents 2 dirty","v":0,"name":"crucible","level":30,"time":"2024-09-27T17:13:44.753504587Z","hostname":"w-01J8T79TZ98ARZXF9AJ1D7W0D7","pid":1230,"":"mend","":"downstairs","":"downstairs","session_id":"7e4dc9d6-72a4-443b-80a5-97e066c91131"}
4342024-09-27T17:13:46.284Z{"msg":"First source client ID for extent 2","v":0,"name":"crucible","level":30,"time":"2024-09-27T17:13:44.753540306Z","hostname":"w-01J8T79TZ98ARZXF9AJ1D7W0D7","pid":1230,"mrl":"dirty","":"mend","":"downstairs","":"downstairs","session_id":"7e4dc9d6-72a4-443b-80a5-97e066c91131"}
4352024-09-27T17:13:46.284Z{"msg":"extent:2 gens: 31 31 31","v":0,"name":"crucible","level":30,"time":"2024-09-27T17:13:44.753572524Z","hostname":"w-01J8T79TZ98ARZXF9AJ1D7W0D7","pid":1230,"mrl":"dirty","":"mend","":"downstairs","":"downstairs","session_id":"7e4dc9d6-72a4-443b-80a5-97e066c91131"}
4362024-09-27T17:13:46.284Z{"msg":"extent:2 flush: 1689 1689 1689 scs: [ClientId(0), ClientId(1), ClientId(2)]","v":0,"name":"crucible","level":30,"time":"2024-09-27T17:13:44.753608792Z","hostname":"w-01J8T79TZ98ARZXF9AJ1D7W0D7","pid":1230,"mrl":"dirty","":"mend","":"downstairs","":"downstairs","session_id":"7e4dc9d6-72a4-443b-80a5-97e066c91131"}
4372024-09-27T17:13:46.284Z{"msg":"max_flush now has: [ClientId(0), ClientId(1), ClientId(2)]","v":0,"name":"crucible","level":30,"time":"2024-09-27T17:13:44.753642631Z","hostname":"w-01J8T79TZ98ARZXF9AJ1D7W0D7","pid":1230,"mrl":"dirty","":"mend","":"downstairs","":"downstairs","session_id":"7e4dc9d6-72a4-443b-80a5-97e066c91131"}
4382024-09-27T17:13:46.284Z{"msg":"extent:2 dirty: true true false","v":0,"name":"crucible","level":30,"time":"2024-09-27T17:13:44.753708778Z","hostname":"w-01J8T79TZ98ARZXF9AJ1D7W0D7","pid":1230,"mrl":"dirty","":"mend","":"downstairs","":"downstairs","session_id":"7e4dc9d6-72a4-443b-80a5-97e066c91131"}
4392024-09-27T17:13:46.284Z{"msg":"find dest for source 0 for extent at index 2","v":0,"name":"crucible","level":30,"time":"2024-09-27T17:13:44.753743436Z","hostname":"w-01J8T79TZ98ARZXF9AJ1D7W0D7","pid":1230,"mrl":"dirty","":"mend","":"downstairs","":"downstairs","session_id":"7e4dc9d6-72a4-443b-80a5-97e066c91131"}
4402024-09-27T17:13:46.284Z{"msg":"source 0, add dest 1 source flush","v":0,"name":"crucible","level":30,"time":"2024-09-27T17:13:44.753778714Z","hostname":"w-01J8T79TZ98ARZXF9AJ1D7W0D7","pid":1230,"mrl":"dirty","":"mend","":"downstairs","":"downstairs","session_id":"7e4dc9d6-72a4-443b-80a5-97e066c91131"}
4412024-09-27T17:13:46.284Z{"msg":"source 0, add dest 2 source flush","v":0,"name":"crucible","level":30,"time":"2024-09-27T17:13:44.753806113Z","hostname":"w-01J8T79TZ98ARZXF9AJ1D7W0D7","pid":1230,"mrl":"dirty","":"mend","":"downstairs","":"downstairs","session_id":"7e4dc9d6-72a4-443b-80a5-97e066c91131"}
4422024-09-27T17:13:46.284Z{"msg":"Extents 4 dirty","v":0,"name":"crucible","level":30,"time":"2024-09-27T17:13:44.753822332Z","hostname":"w-01J8T79TZ98ARZXF9AJ1D7W0D7","pid":1230,"":"mend","":"downstairs","":"downstairs","session_id":"7e4dc9d6-72a4-443b-80a5-97e066c91131"}
4432024-09-27T17:13:46.284Z{"msg":"First source client ID for extent 4","v":0,"name":"crucible","level":30,"time":"2024-09-27T17:13:44.753842591Z","hostname":"w-01J8T79TZ98ARZXF9AJ1D7W0D7","pid":1230,"mrl":"dirty","":"mend","":"downstairs","":"downstairs","session_id":"7e4dc9d6-72a4-443b-80a5-97e066c91131"}
4442024-09-27T17:13:46.284Z{"msg":"extent:4 gens: 31 31 31","v":0,"name":"crucible","level":30,"time":"2024-09-27T17:13:44.753856921Z","hostname":"w-01J8T79TZ98ARZXF9AJ1D7W0D7","pid":1230,"mrl":"dirty","":"mend","":"downstairs","":"downstairs","session_id":"7e4dc9d6-72a4-443b-80a5-97e066c91131"}
4452024-09-27T17:13:46.284Z{"msg":"extent:4 flush: 1689 1689 1689 scs: [ClientId(0), ClientId(1), ClientId(2)]","v":0,"name":"crucible","level":30,"time":"2024-09-27T17:13:44.75387829Z","hostname":"w-01J8T79TZ98ARZXF9AJ1D7W0D7","pid":1230,"mrl":"dirty","":"mend","":"downstairs","":"downstairs","session_id":"7e4dc9d6-72a4-443b-80a5-97e066c91131"}
4462024-09-27T17:13:46.284Z{"msg":"max_flush now has: [ClientId(0), ClientId(1), ClientId(2)]","v":0,"name":"crucible","level":30,"time":"2024-09-27T17:13:44.753893129Z","hostname":"w-01J8T79TZ98ARZXF9AJ1D7W0D7","pid":1230,"mrl":"dirty","":"mend","":"downstairs","":"downstairs","session_id":"7e4dc9d6-72a4-443b-80a5-97e066c91131"}
4472024-09-27T17:13:46.284Z{"msg":"extent:4 dirty: true true false","v":0,"name":"crucible","level":30,"time":"2024-09-27T17:13:44.753913868Z","hostname":"w-01J8T79TZ98ARZXF9AJ1D7W0D7","pid":1230,"mrl":"dirty","":"mend","":"downstairs","":"downstairs","session_id":"7e4dc9d6-72a4-443b-80a5-97e066c91131"}
4482024-09-27T17:13:46.284Z{"msg":"find dest for source 0 for extent at index 4","v":0,"name":"crucible","level":30,"time":"2024-09-27T17:13:44.753928387Z","hostname":"w-01J8T79TZ98ARZXF9AJ1D7W0D7","pid":1230,"mrl":"dirty","":"mend","":"downstairs","":"downstairs","session_id":"7e4dc9d6-72a4-443b-80a5-97e066c91131"}
4492024-09-27T17:13:46.284Z{"msg":"source 0, add dest 1 source flush","v":0,"name":"crucible","level":30,"time":"2024-09-27T17:13:44.753949226Z","hostname":"w-01J8T79TZ98ARZXF9AJ1D7W0D7","pid":1230,"mrl":"dirty","":"mend","":"downstairs","":"downstairs","session_id":"7e4dc9d6-72a4-443b-80a5-97e066c91131"}
4502024-09-27T17:13:46.284Z{"msg":"source 0, add dest 2 source flush","v":0,"name":"crucible","level":30,"time":"2024-09-27T17:13:44.753963626Z","hostname":"w-01J8T79TZ98ARZXF9AJ1D7W0D7","pid":1230,"mrl":"dirty","":"mend","":"downstairs","":"downstairs","session_id":"7e4dc9d6-72a4-443b-80a5-97e066c91131"}
4512024-09-27T17:13:46.284Z{"msg":"Transition from WaitQuorum to Reconcile","v":0,"name":"crucible","level":30,"time":"2024-09-27T17:13:44.753984574Z","hostname":"w-01J8T79TZ98ARZXF9AJ1D7W0D7","pid":1230,"client":"0","":"downstairs","session_id":"7e4dc9d6-72a4-443b-80a5-97e066c91131"}
4522024-09-27T17:13:46.285Z{"msg":"Transition from WaitQuorum to Reconcile","v":0,"name":"crucible","level":30,"time":"2024-09-27T17:13:44.753998224Z","hostname":"w-01J8T79TZ98ARZXF9AJ1D7W0D7","pid":1230,"client":"1","":"downstairs","session_id":"7e4dc9d6-72a4-443b-80a5-97e066c91131"}
4532024-09-27T17:13:46.285Z{"msg":"Transition from WaitQuorum to Reconcile","v":0,"name":"crucible","level":30,"time":"2024-09-27T17:13:44.754011423Z","hostname":"w-01J8T79TZ98ARZXF9AJ1D7W0D7","pid":1230,"client":"2","":"downstairs","session_id":"7e4dc9d6-72a4-443b-80a5-97e066c91131"}
4542024-09-27T17:13:46.285Z{"msg":"starting reconciliation 555c472f-4e08-494f-9fc2-8ab755cde469: found 4 extents that need repair","v":0,"name":"crucible","level":30,"time":"2024-09-27T17:13:44.754031812Z","hostname":"w-01J8T79TZ98ARZXF9AJ1D7W0D7","pid":1230,"":"downstairs","":"downstairs","session_id":"7e4dc9d6-72a4-443b-80a5-97e066c91131"}
4552024-09-27T17:13:46.285Z{"msg":"Full repair list: {ExtentId(4): ExtentFix { source: ClientId(0), dest: [ClientId(1), ClientId(2)] }, ExtentId(2): ExtentFix { source: ClientId(0), dest: [ClientId(1), ClientId(2)] }, ExtentId(0): ExtentFix { source: ClientId(0), dest: [ClientId(1), ClientId(2)] }, ExtentId(1): ExtentFix { source: ClientId(0), dest: [ClientId(1), ClientId(2)] }}","v":0,"name":"crucible","level":30,"time":"2024-09-27T17:13:44.754049942Z","hostname":"w-01J8T79TZ98ARZXF9AJ1D7W0D7","pid":1230,"":"downstairs","":"downstairs","session_id":"7e4dc9d6-72a4-443b-80a5-97e066c91131"}
4562024-09-27T17:13:46.288Z{"msg":"Task list: [ReconcileIO { id: ReconciliationId(0), op: ExtentFlush { repair_id: ReconciliationId(0), extent_id: ExtentId(4), client_id: ClientId(0), flush_number: 1690, gen_number: 32 }, state: ClientData([New, New, New]) }, ReconcileIO { id: ReconciliationId(1), op: ExtentClose { repair_id: ReconciliationId(1), extent_id: ExtentId(4) }, state: ClientData([New, New, New]) }, ReconcileIO { id: ReconciliationId(2), op: ExtentRepair { repair_id: ReconciliationId(2), 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(3), op: ExtentReopen { repair_id: ReconciliationId(3), extent_id: ExtentId(4) }, state: ClientData([New, New, New]) }, ReconcileIO { id: ReconciliationId(4), op: ExtentFlush { repair_id: ReconciliationId(4), extent_id: ExtentId(2), client_id: ClientId(0), flush_number: 1690, gen_number: 32 }, state: ClientData([New, New, New]) }, ReconcileIO { id: ReconciliationId(5), op: ExtentClose { repair_id: ReconciliationId(5), extent_id: ExtentId(2) }, state: ClientData([New, New, New]) }, ReconcileIO { id: ReconciliationId(6), op: ExtentRepair { repair_id: ReconciliationId(6), extent_id: ExtentId(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(7), op: ExtentReopen { repair_id: ReconciliationId(7), extent_id: ExtentId(2) }, 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: 1690, 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]) }, ReconcileIO { id: ReconciliationId(12), op: ExtentFlush { repair_id: ReconciliationId(12), extent_id: ExtentId(1), client_id: ClientId(0), flush_number: 1690, gen_number: 32 }, state: ClientData([New, New, New]) }, ReconcileIO { id: ReconciliationId(13), op: ExtentClose { repair_id: ReconciliationId(13), extent_id: ExtentId(1) }, state: ClientData([New, New, New]) }, ReconcileIO { id: ReconciliationId(14), op: ExtentRepair { repair_id: ReconciliationId(14), extent_id: ExtentId(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(15), op: ExtentReopen { repair_id: ReconciliationId(15), extent_id: ExtentId(1) }, state: ClientData([New, New, New]) }]","v":0,"name":"crucible","level":30,"time":"2024-09-27T17:13:44.754141067Z","hostname":"w-01J8T79TZ98ARZXF9AJ1D7W0D7","pid":1230,"":"downstairs","":"downstairs","session_id":"7e4dc9d6-72a4-443b-80a5-97e066c91131"}
4572024-09-27T17:13:46.288Z{"msg":"no Nexus client from DNS, aborting start notification","v":0,"name":"crucible","level":50,"time":"2024-09-27T17:13:44.754168056Z","hostname":"w-01J8T79TZ98ARZXF9AJ1D7W0D7","pid":1230,"reconcile":"555c472f-4e08-494f-9fc2-8ab755cde469","":"downstairs","":"downstairs","session_id":"7e4dc9d6-72a4-443b-80a5-97e066c91131"}
4582024-09-27T17:13:46.288Z{"msg":"no Nexus client from DNS, aborting progress notification","v":0,"name":"crucible","level":50,"time":"2024-09-27T17:13:44.754184755Z","hostname":"w-01J8T79TZ98ARZXF9AJ1D7W0D7","pid":1230,"reconcile":"555c472f-4e08-494f-9fc2-8ab755cde469","":"downstairs","":"downstairs","session_id":"7e4dc9d6-72a4-443b-80a5-97e066c91131"}
4592024-09-27T17:13:46.288Z{"msg":"no Nexus client from DNS, aborting progress notification","v":0,"name":"crucible","level":50,"time":"2024-09-27T17:13:44.754771117Z","hostname":"w-01J8T79TZ98ARZXF9AJ1D7W0D7","pid":1230,"reconcile":"555c472f-4e08-494f-9fc2-8ab755cde469","":"downstairs","":"downstairs","session_id":"7e4dc9d6-72a4-443b-80a5-97e066c91131"}
4602024-09-27T17:13:46.288Z{"msg":"sending reconcile request ReconciliationId(2)","v":0,"name":"crucible","level":30,"time":"2024-09-27T17:13:44.755107041Z","hostname":"w-01J8T79TZ98ARZXF9AJ1D7W0D7","pid":1230,"client":"1","":"downstairs","session_id":"7e4dc9d6-72a4-443b-80a5-97e066c91131"}
4612024-09-27T17:13:46.288Z{"msg":"sending reconcile request ReconciliationId(2)","v":0,"name":"crucible","level":30,"time":"2024-09-27T17:13:44.755153649Z","hostname":"w-01J8T79TZ98ARZXF9AJ1D7W0D7","pid":1230,"client":"2","":"downstairs","session_id":"7e4dc9d6-72a4-443b-80a5-97e066c91131"}
4622024-09-27T17:13:46.288Z{"msg":"no Nexus client from DNS, aborting progress notification","v":0,"name":"crucible","level":50,"time":"2024-09-27T17:13:44.755185808Z","hostname":"w-01J8T79TZ98ARZXF9AJ1D7W0D7","pid":1230,"reconcile":"555c472f-4e08-494f-9fc2-8ab755cde469","":"downstairs","":"downstairs","session_id":"7e4dc9d6-72a4-443b-80a5-97e066c91131"}
4632024-09-27T17:13:46.294Z{"msg":"no Nexus client from DNS, aborting progress notification","v":0,"name":"crucible","level":50,"time":"2024-09-27T17:13:44.768076395Z","hostname":"w-01J8T79TZ98ARZXF9AJ1D7W0D7","pid":1230,"reconcile":"555c472f-4e08-494f-9fc2-8ab755cde469","":"downstairs","":"downstairs","session_id":"7e4dc9d6-72a4-443b-80a5-97e066c91131"}
4642024-09-27T17:13:46.297Z{"msg":"no Nexus client from DNS, aborting progress notification","v":0,"name":"crucible","level":50,"time":"2024-09-27T17:13:44.768451987Z","hostname":"w-01J8T79TZ98ARZXF9AJ1D7W0D7","pid":1230,"reconcile":"555c472f-4e08-494f-9fc2-8ab755cde469","":"downstairs","":"downstairs","session_id":"7e4dc9d6-72a4-443b-80a5-97e066c91131"}
4652024-09-27T17:13:46.297Z{"msg":"no Nexus client from DNS, aborting progress notification","v":0,"name":"crucible","level":50,"time":"2024-09-27T17:13:44.769603192Z","hostname":"w-01J8T79TZ98ARZXF9AJ1D7W0D7","pid":1230,"reconcile":"555c472f-4e08-494f-9fc2-8ab755cde469","":"downstairs","":"downstairs","session_id":"7e4dc9d6-72a4-443b-80a5-97e066c91131"}
4662024-09-27T17:13:46.297Z{"msg":"sending reconcile request ReconciliationId(6)","v":0,"name":"crucible","level":30,"time":"2024-09-27T17:13:44.769891009Z","hostname":"w-01J8T79TZ98ARZXF9AJ1D7W0D7","pid":1230,"client":"1","":"downstairs","session_id":"7e4dc9d6-72a4-443b-80a5-97e066c91131"}
4672024-09-27T17:13:46.297Z{"msg":"sending reconcile request ReconciliationId(6)","v":0,"name":"crucible","level":30,"time":"2024-09-27T17:13:44.769939127Z","hostname":"w-01J8T79TZ98ARZXF9AJ1D7W0D7","pid":1230,"client":"2","":"downstairs","session_id":"7e4dc9d6-72a4-443b-80a5-97e066c91131"}
4682024-09-27T17:13:46.297Z{"msg":"no Nexus client from DNS, aborting progress notification","v":0,"name":"crucible","level":50,"time":"2024-09-27T17:13:44.769978945Z","hostname":"w-01J8T79TZ98ARZXF9AJ1D7W0D7","pid":1230,"reconcile":"555c472f-4e08-494f-9fc2-8ab755cde469","":"downstairs","":"downstairs","session_id":"7e4dc9d6-72a4-443b-80a5-97e066c91131"}
4692024-09-27T17:13:46.306Z{"msg":"no Nexus client from DNS, aborting progress notification","v":0,"name":"crucible","level":50,"time":"2024-09-27T17:13:44.779848665Z","hostname":"w-01J8T79TZ98ARZXF9AJ1D7W0D7","pid":1230,"reconcile":"555c472f-4e08-494f-9fc2-8ab755cde469","":"downstairs","":"downstairs","session_id":"7e4dc9d6-72a4-443b-80a5-97e066c91131"}
4702024-09-27T17:13:46.309Z{"msg":"no Nexus client from DNS, aborting progress notification","v":0,"name":"crucible","level":50,"time":"2024-09-27T17:13:44.780253856Z","hostname":"w-01J8T79TZ98ARZXF9AJ1D7W0D7","pid":1230,"reconcile":"555c472f-4e08-494f-9fc2-8ab755cde469","":"downstairs","":"downstairs","session_id":"7e4dc9d6-72a4-443b-80a5-97e066c91131"}
4712024-09-27T17:13:46.309Z{"msg":"no Nexus client from DNS, aborting progress notification","v":0,"name":"crucible","level":50,"time":"2024-09-27T17:13:44.78122702Z","hostname":"w-01J8T79TZ98ARZXF9AJ1D7W0D7","pid":1230,"reconcile":"555c472f-4e08-494f-9fc2-8ab755cde469","":"downstairs","":"downstairs","session_id":"7e4dc9d6-72a4-443b-80a5-97e066c91131"}
4722024-09-27T17:13:46.309Z{"msg":"sending reconcile request ReconciliationId(10)","v":0,"name":"crucible","level":30,"time":"2024-09-27T17:13:44.781528596Z","hostname":"w-01J8T79TZ98ARZXF9AJ1D7W0D7","pid":1230,"client":"1","":"downstairs","session_id":"7e4dc9d6-72a4-443b-80a5-97e066c91131"}
4732024-09-27T17:13:46.309Z{"msg":"sending reconcile request ReconciliationId(10)","v":0,"name":"crucible","level":30,"time":"2024-09-27T17:13:44.781565754Z","hostname":"w-01J8T79TZ98ARZXF9AJ1D7W0D7","pid":1230,"client":"2","":"downstairs","session_id":"7e4dc9d6-72a4-443b-80a5-97e066c91131"}
4742024-09-27T17:13:46.309Z{"msg":"no Nexus client from DNS, aborting progress notification","v":0,"name":"crucible","level":50,"time":"2024-09-27T17:13:44.781603962Z","hostname":"w-01J8T79TZ98ARZXF9AJ1D7W0D7","pid":1230,"reconcile":"555c472f-4e08-494f-9fc2-8ab755cde469","":"downstairs","":"downstairs","session_id":"7e4dc9d6-72a4-443b-80a5-97e066c91131"}
4752024-09-27T17:13:46.318Z{"msg":"no Nexus client from DNS, aborting progress notification","v":0,"name":"crucible","level":50,"time":"2024-09-27T17:13:44.791733651Z","hostname":"w-01J8T79TZ98ARZXF9AJ1D7W0D7","pid":1230,"reconcile":"555c472f-4e08-494f-9fc2-8ab755cde469","":"downstairs","":"downstairs","session_id":"7e4dc9d6-72a4-443b-80a5-97e066c91131"}
4762024-09-27T17:13:46.321Z{"msg":"no Nexus client from DNS, aborting progress notification","v":0,"name":"crucible","level":50,"time":"2024-09-27T17:13:44.792158091Z","hostname":"w-01J8T79TZ98ARZXF9AJ1D7W0D7","pid":1230,"reconcile":"555c472f-4e08-494f-9fc2-8ab755cde469","":"downstairs","":"downstairs","session_id":"7e4dc9d6-72a4-443b-80a5-97e066c91131"}
4772024-09-27T17:13:46.321Z{"msg":"no Nexus client from DNS, aborting progress notification","v":0,"name":"crucible","level":50,"time":"2024-09-27T17:13:44.793316476Z","hostname":"w-01J8T79TZ98ARZXF9AJ1D7W0D7","pid":1230,"reconcile":"555c472f-4e08-494f-9fc2-8ab755cde469","":"downstairs","":"downstairs","session_id":"7e4dc9d6-72a4-443b-80a5-97e066c91131"}
4782024-09-27T17:13:46.321Z{"msg":"sending reconcile request ReconciliationId(14)","v":0,"name":"crucible","level":30,"time":"2024-09-27T17:13:44.793623401Z","hostname":"w-01J8T79TZ98ARZXF9AJ1D7W0D7","pid":1230,"client":"1","":"downstairs","session_id":"7e4dc9d6-72a4-443b-80a5-97e066c91131"}
4792024-09-27T17:13:46.321Z{"msg":"sending reconcile request ReconciliationId(14)","v":0,"name":"crucible","level":30,"time":"2024-09-27T17:13:44.793674869Z","hostname":"w-01J8T79TZ98ARZXF9AJ1D7W0D7","pid":1230,"client":"2","":"downstairs","session_id":"7e4dc9d6-72a4-443b-80a5-97e066c91131"}
4802024-09-27T17:13:46.321Z{"msg":"no Nexus client from DNS, aborting progress notification","v":0,"name":"crucible","level":50,"time":"2024-09-27T17:13:44.793706237Z","hostname":"w-01J8T79TZ98ARZXF9AJ1D7W0D7","pid":1230,"reconcile":"555c472f-4e08-494f-9fc2-8ab755cde469","":"downstairs","":"downstairs","session_id":"7e4dc9d6-72a4-443b-80a5-97e066c91131"}
4812024-09-27T17:13:46.330Z{"msg":"no Nexus client from DNS, aborting progress notification","v":0,"name":"crucible","level":50,"time":"2024-09-27T17:13:44.803726221Z","hostname":"w-01J8T79TZ98ARZXF9AJ1D7W0D7","pid":1230,"reconcile":"555c472f-4e08-494f-9fc2-8ab755cde469","":"downstairs","":"downstairs","session_id":"7e4dc9d6-72a4-443b-80a5-97e066c91131"}
4822024-09-27T17:13:46.333Z{"msg":"done with reconciliation","v":0,"name":"crucible","level":30,"time":"2024-09-27T17:13:44.804046506Z","hostname":"w-01J8T79TZ98ARZXF9AJ1D7W0D7","pid":1230,"":"downstairs","":"downstairs","session_id":"7e4dc9d6-72a4-443b-80a5-97e066c91131"}
4832024-09-27T17:13:46.333Z{"msg":"Transition from Reconcile to Active","v":0,"name":"crucible","level":30,"time":"2024-09-27T17:13:44.804091084Z","hostname":"w-01J8T79TZ98ARZXF9AJ1D7W0D7","pid":1230,"client":"0","":"downstairs","session_id":"7e4dc9d6-72a4-443b-80a5-97e066c91131"}
4842024-09-27T17:13:46.333Z{"msg":"Transition from Reconcile to Active","v":0,"name":"crucible","level":30,"time":"2024-09-27T17:13:44.804111583Z","hostname":"w-01J8T79TZ98ARZXF9AJ1D7W0D7","pid":1230,"client":"1","":"downstairs","session_id":"7e4dc9d6-72a4-443b-80a5-97e066c91131"}
4852024-09-27T17:13:46.333Z{"msg":"Transition from Reconcile to Active","v":0,"name":"crucible","level":30,"time":"2024-09-27T17:13:44.804139142Z","hostname":"w-01J8T79TZ98ARZXF9AJ1D7W0D7","pid":1230,"client":"2","":"downstairs","session_id":"7e4dc9d6-72a4-443b-80a5-97e066c91131"}
4862024-09-27T17:13:46.333Z{"msg":"All required reconciliation work is completed","v":0,"name":"crucible","level":30,"time":"2024-09-27T17:13:44.804157601Z","hostname":"w-01J8T79TZ98ARZXF9AJ1D7W0D7","pid":1230,"session_id":"7e4dc9d6-72a4-443b-80a5-97e066c91131"}
4872024-09-27T17:13:46.333Z{"msg":"Set Downstairs and Upstairs active after reconciliation","v":0,"name":"crucible","level":30,"time":"2024-09-27T17:13:44.804184039Z","hostname":"w-01J8T79TZ98ARZXF9AJ1D7W0D7","pid":1230,"session_id":"7e4dc9d6-72a4-443b-80a5-97e066c91131"}
4882024-09-27T17:13:46.333ZWait for a query_work_queue command to finish before sending IO
4892024-09-27T17:13:46.333Z{"msg":"c7d40530-c950-4128-a645-c384a86d62f2 is now active with session: 7e4dc9d6-72a4-443b-80a5-97e066c91131","v":0,"name":"crucible","level":30,"time":"2024-09-27T17:13:44.804212798Z","hostname":"w-01J8T79TZ98ARZXF9AJ1D7W0D7","pid":1230,"session_id":"7e4dc9d6-72a4-443b-80a5-97e066c91131"}
4902024-09-27T17:13:46.333Z{"msg":"The guest has finished waiting for activation with:33","v":0,"name":"crucible","level":30,"time":"2024-09-27T17:13:44.804238087Z","hostname":"w-01J8T79TZ98ARZXF9AJ1D7W0D7","pid":1230}
4912024-09-27T17:13:46.333Z{"msg":"no Nexus client from DNS, aborting finish notification","v":0,"name":"crucible","level":50,"time":"2024-09-27T17:13:44.804253726Z","hostname":"w-01J8T79TZ98ARZXF9AJ1D7W0D7","pid":1230,"reconcile":"555c472f-4e08-494f-9fc2-8ab755cde469","":"downstairs","":"downstairs","session_id":"7e4dc9d6-72a4-443b-80a5-97e066c91131"}
4922024-09-27T17:13:46.333ZRegion: es:10 ec:5 bs:4096 ts:204800 tb:50 max_io:50 or 204800
4932024-09-27T17:13:46.333ZLoading write count information from file "/var/tmp/test_up-build/verify_file"
4942024-09-27T17:13:46.333ZRead and Verify all blocks (0..50 range:true)
4952024-09-27T17:13:46.372ZWrote out file "/var/tmp/test_up-build/verify_file"
4962024-09-27T17:13:46.372ZVerify test completed
4972024-09-27T17:13:46.375ZWrote out file "/var/tmp/test_up-build/verify_file"
4982024-09-27T17:13:46.375ZCLIENT: Tests done. All submitted work has been ACK'd
4992024-09-27T17:13:46.375Z----------------------------------------------------------------
5002024-09-27T17:13:46.375Z Crucible gen:33 GIO:true work queues: Upstairs:0 downstairs:1
5012024-09-27T17:13:46.375ZStates: Active Active Active
5022024-09-27T17:13:46.375ZGW_ID ACK DSID TYPE BKS/EXT DS:0 DS:1 DS:2 REPLAY
5032024-09-27T17:13:46.375Z 1 Acked 1000 Read 50 Done Done Done false
5042024-09-27T17:13:46.375Z STATES DS:0 DS:1 DS:2 TOTAL
5052024-09-27T17:13:46.375Z Sent 0 0 0 0
5062024-09-27T17:13:46.375Z Done 1 1 1 3
5072024-09-27T17:13:46.375Z Skipped 0 0 0 0
5082024-09-27T17:13:46.375Z Error 0 0 0 0
5092024-09-27T17:13:46.375ZLast Flush: 0 0 0
5102024-09-27T17:13:46.375ZDownstairs last five completed:
5112024-09-27T17:13:46.375ZUpstairs last five completed: 1
5122024-09-27T17:13:46.376ZCLIENT: Up:0 ds:1 act:3
5132024-09-27T17:13:50.375Z----------------------------------------------------------------
5142024-09-27T17:13:50.375Z Crucible gen:33 GIO:true work queues: Upstairs:0 downstairs:0
5152024-09-27T17:13:50.375ZDownstairs last five completed: 1001 1000
5162024-09-27T17:13:50.375ZUpstairs last five completed: 2 1
5172024-09-27T17:13:50.375ZCLIENT: Up:0 ds:0 act:3
5182024-09-27T17:13:50.375ZCLIENT: All crucible jobs finished, exiting program
5192024-09-27T17:13:50.378Z{"msg":"Guest handle has been dropped","v":0,"name":"crucible","level":40,"time":"2024-09-27T17:13:48.847491305Z","hostname":"w-01J8T79TZ98ARZXF9AJ1D7W0D7","pid":1230}
5202024-09-27T17:13:50.381ZRepair part 2 passed
5212024-09-27T17:13:50.384Z/var/tmp/bins/crucible-downstairs dump --no-color -d /var/tmp/test_up-build/8810 -d /var/tmp/test_up-build/8820 -d /var/tmp/test_up-build/8830
5222024-09-27T17:13:50.397ZEXT BLOCKS GEN0 GEN1 GEN2 FL0 FL1 FL2 D0 D1 D2 DIFF
5232024-09-27T17:13:50.397Z 0 000-009 32 32 32 1690 1690 1690 F F F
5242024-09-27T17:13:50.398Z 1 010-019 32 32 32 1690 1690 1690 F F F
5252024-09-27T17:13:50.398Z 2 020-029 32 32 32 1690 1690 1690 F F F
5262024-09-27T17:13:50.398Z 3 030-039 31 31 31 1689 1689 1689 F F F
5272024-09-27T17:13:50.398Z 4 040-049 32 32 32 1690 1690 1690 F F F
5282024-09-27T17:13:50.398ZMax gen: 32, Max flush: 1690
5292024-09-27T17:13:50.401Zdump test passed
5302024-09-27T17:13:50.403Z/var/tmp/bins/crucible-downstairs dump --no-color -d /var/tmp/test_up-build/8810 -d /var/tmp/test_up-build/8820 -d /var/tmp/test_up-build/8830 -e 1
5312024-09-27T17:13:50.416Z Extent 1
5322024-09-27T17:13:50.416ZGEN 32 32 32
5332024-09-27T17:13:50.416ZFLUSH_ID 1690 1690 1690
5342024-09-27T17:13:50.416ZDIRTY
5352024-09-27T17:13:50.418Z
5362024-09-27T17:13:50.418ZBLOCK D0 D1 D2 C0 C1 C2 DIFF
5372024-09-27T17:13:50.418Z010 A A A A A A
5382024-09-27T17:13:50.421Z011 A A A A A A
5392024-09-27T17:13:50.421Z012 A A A A A A
5402024-09-27T17:13:50.424Z013 A A A A A A
5412024-09-27T17:13:50.424Z014 A A A A A A
5422024-09-27T17:13:50.424Z015 A A A A A A
5432024-09-27T17:13:50.426Z016 A A A A A A
5442024-09-27T17:13:50.426Z017 A A A A A A
5452024-09-27T17:13:50.429Z018 A A A A A A
5462024-09-27T17:13:50.429Z019 A A A A A A
5472024-09-27T17:13:50.432Zdump extent test passed
5482024-09-27T17:13:50.432Z/var/tmp/bins/crucible-downstairs dump --no-color -d /var/tmp/test_up-build/8810 -d /var/tmp/test_up-build/8820 -d /var/tmp/test_up-build/8830 -b 20
5492024-09-27T17:13:50.447ZExtent 2 Block in extent 0 Actual block 20
5502024-09-27T17:13:50.447Z
5512024-09-27T17:13:50.450Z DATA SHA256 VER
5522024-09-27T17:13:50.450Z------ ---------------------------------------------------------------- ---
5532024-09-27T17:13:50.450Z 0 06a4be7b2fd68b115515eff7147341bceb61feb4e1a511cefbd4a2ad91095ab2 A
5542024-09-27T17:13:50.450Z 1 06a4be7b2fd68b115515eff7147341bceb61feb4e1a511cefbd4a2ad91095ab2 A
5552024-09-27T17:13:50.450Z 2 06a4be7b2fd68b115515eff7147341bceb61feb4e1a511cefbd4a2ad91095ab2 A
5562024-09-27T17:13:50.450Z
5572024-09-27T17:13:50.450ZNONCES 0 1 2 DIFF
5582024-09-27T17:13:50.450Z------ ------------------------ ------------------------ ------------------------ -----
5592024-09-27T17:13:50.450Z 0 2cc9e8bf7a710ec527c9a4e7 2cc9e8bf7a710ec527c9a4e7 2cc9e8bf7a710ec527c9a4e7
5602024-09-27T17:13:50.450Z
5612024-09-27T17:13:50.450Z TAGS 0 1 2 DIFF
5622024-09-27T17:13:50.450Z------ -------------------------------- -------------------------------- -------------------------------- -----
5632024-09-27T17:13:50.453Z 0 681e71f20eee1603c1c5d51bfae08f72 681e71f20eee1603c1c5d51bfae08f72 681e71f20eee1603c1c5d51bfae08f72
5642024-09-27T17:13:50.453Z
5652024-09-27T17:13:50.453ZHASHES 0 1 2 DIFF
5662024-09-27T17:13:50.453Z------ ---------------- ---------------- ---------------- -----
5672024-09-27T17:13:50.453Z
5682024-09-27T17:13:50.455Zdump block test passed
5692024-09-27T17:13:50.455ZUpstairs tests have completed, stopping all downstairs
5702024-09-27T17:13:55.518ZCreating four larger downstairs regions
5712024-09-27T17:13:55.957ZStarting four downstairs
5722024-09-27T17:14:00.965ZNow do the replace-reconcile test
5732024-09-27T17:17:39.238ZCompleted test: replace-reconcile
5742024-09-27T17:17:39.240ZNow do the replace-before-active test
5752024-09-27T17:20:24.732ZCompleted test: replace-before-active
5762024-09-27T17:20:24.735ZTests have completed, stopping all downstairs
5772024-09-27T17:20:24.789Z
5782024-09-27T17:20:24.789ZAll Tests have passed
5792024-09-27T17:20:24.792Z10:18 Test duration
5802024-09-27T17:20:24.792Z
5812024-09-27T17:20:24.792Zreal 10:17.444051008
5822024-09-27T17:20:24.792Zuser 3:53.341799684
5832024-09-27T17:20:24.792Zsys 13.700058410
5842024-09-27T17:20:24.792Ztrap 0.206257022
5852024-09-27T17:20:24.792Ztflt 0.016944615
5862024-09-27T17:20:24.792Zdflt 0.053885078
5872024-09-27T17:20:24.792Zkflt 0.001094626
5882024-09-27T17:20:24.792Zlock 8:40:05.696392533
5892024-09-27T17:20:24.792Zslp 34:53.162453739
5902024-09-27T17:20:24.792Zlat 12.365948291
5912024-09-27T17:20:24.792Zstop 0.137402507
5922024-09-27T17:20:24.792Z+ echo 'test-up-encrypted ends'
5932024-09-27T17:20:24.792Ztest-up-encrypted ends
5942024-09-27T17:20:29.796Zprocess exited: duration 625783 ms, exit code 0
5952024-09-27T17:20:29.796Zexec warning: : stdio descriptors remain open after task exit; waiting 60 seconds for them to close
5962024-09-27T17:21:29.844Zexec warning: : stdout descriptor may be held open by a background process; giving up!
5972024-09-27T17:21:29.844Zexec warning: : stderr descriptor may be held open by a background process; giving up!
 
5982024-09-27T17:21:29.855Zfound 8 output files
5992024-09-27T17:21:29.855Zuploading: /tmp/debug/df.txt (1270 bytes)
6002024-09-27T17:21:30.865Zuploaded: /tmp/debug/df.txt
6012024-09-27T17:21:30.865Zuploading: /tmp/debug/dtrace.txt (593345 bytes)
6022024-09-27T17:21:31.888Zuploaded: /tmp/debug/dtrace.txt
6032024-09-27T17:21:31.891Zuploading: /tmp/debug/iostat.txt (206330 bytes)
6042024-09-27T17:21:31.898Zupload warning: file "/tmp/debug/iostat.txt" changed size mid upload: 206330 -> 206934
6052024-09-27T17:21:32.904Zuploaded: /tmp/debug/iostat.txt
6062024-09-27T17:21:32.907Zuploading: /tmp/debug/mpstat.txt (499278 bytes)
6072024-09-27T17:21:32.919Zupload warning: file "/tmp/debug/mpstat.txt" changed size mid upload: 499278 -> 501471
6082024-09-27T17:21:33.926Zuploaded: /tmp/debug/mpstat.txt
6092024-09-27T17:21:33.928Zuploading: /tmp/debug/paging.txt (90813 bytes)
6102024-09-27T17:21:33.934Zupload warning: file "/tmp/debug/paging.txt" changed size mid upload: 90813 -> 91281
6112024-09-27T17:21:34.976Zuploaded: /tmp/debug/paging.txt
6122024-09-27T17:21:34.976Zuploading: /tmp/debug/prstat.txt (962976 bytes)
6132024-09-27T17:21:35.055Zupload warning: file "/tmp/debug/prstat.txt" changed size mid upload: 962976 -> 969471
6142024-09-27T17:21:36.115Zuploaded: /tmp/debug/prstat.txt
6152024-09-27T17:21:36.115Zuploading: /tmp/debug/psrinfo.txt (1528 bytes)
6162024-09-27T17:21:37.125Zuploaded: /tmp/debug/psrinfo.txt
6172024-09-27T17:21:37.129Zuploading: /tmp/debug/upstairs-info.txt (103174 bytes)
6182024-09-27T17:21:38.146Zuploaded: /tmp/debug/upstairs-info.txt