01J8QWPR4KR2CE2CWNJAAJRE0K: 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: 01J8QWQAK2EY94W0CPJWJZYSB1

Tags:

Artefacts:

Output:

SEQ GLOBAL TIME DETAILS
12024-09-26T19:39:31.701Zjob dependencies complete; ready to run (waiting for 14 m 2 s)
22024-09-26T19:40:27.171Zjob assigned to worker 01J8QXH7SYQS95RZY0ACANYM79 (queued for 55 s)
32024-09-26T19:40:34.096Zdownloading input: /input/build/work/bins/crucible-downstairs.gz
42024-09-26T19:40:35.825Zdownloaded input: /input/build/work/bins/crucible-downstairs.gz
52024-09-26T19:40:35.825Zdownloading input: /input/build/work/bins/crucible-hammer.gz
62024-09-26T19:40:37.361Zdownloaded input: /input/build/work/bins/crucible-hammer.gz
72024-09-26T19:40:37.361Zdownloading input: /input/build/work/bins/crutest.gz
82024-09-26T19:40:39.178Zdownloaded input: /input/build/work/bins/crutest.gz
92024-09-26T19:40:39.178Zdownloading input: /input/build/work/bins/dsc.gz
102024-09-26T19:40:40.109Zdownloaded input: /input/build/work/bins/dsc.gz
112024-09-26T19:40:40.116Zdownloading input: /input/build/work/scripts/perf-downstairs-tick.d
122024-09-26T19:40:40.134Zdownloaded input: /input/build/work/scripts/perf-downstairs-tick.d
132024-09-26T19:40:40.135Zdownloading input: /input/build/work/scripts/test_ds.sh
142024-09-26T19:40:40.156Zdownloaded input: /input/build/work/scripts/test_ds.sh
152024-09-26T19:40:40.156Zdownloading input: /input/build/work/scripts/test_live_repair.sh
162024-09-26T19:40:40.177Zdownloaded input: /input/build/work/scripts/test_live_repair.sh
172024-09-26T19:40:40.177Zdownloading input: /input/build/work/scripts/test_repair.sh
182024-09-26T19:40:40.199Zdownloaded input: /input/build/work/scripts/test_repair.sh
192024-09-26T19:40:40.199Zdownloading input: /input/build/work/scripts/test_replay.sh
202024-09-26T19:40:40.220Zdownloaded input: /input/build/work/scripts/test_replay.sh
212024-09-26T19:40:40.220Zdownloading input: /input/build/work/scripts/test_up.sh
222024-09-26T19:40:40.240Zdownloaded input: /input/build/work/scripts/test_up.sh
232024-09-26T19:40:40.240Zdownloading input: /input/build/work/scripts/upstairs_info.d
242024-09-26T19:40:40.261Zdownloaded input: /input/build/work/scripts/upstairs_info.d
252024-09-26T19:40:40.264Zdownloading input: /input/build/tmp/cargo-test-out.log
262024-09-26T19:40:41.314Zdownloaded input: /input/build/tmp/cargo-test-out.log
 
272024-09-26T19:40:41.314Zstarting task 0: "setup"
282024-09-26T19:40:41.322Z++ uname -s
292024-09-26T19:40:41.325Z+ kern=SunOS
302024-09-26T19:40:41.326Z+ case "$kern" in
312024-09-26T19:40:41.326Z+ groupadd -g 12345 build
322024-09-26T19:40:41.329Z+ useradd -u 12345 -g build -d /home/build -s /bin/bash -c build -P 'Primary Administrator' build
332024-09-26T19:40:43.338Z+ zfs create -o mountpoint=/work rpool/work
342024-09-26T19:40:43.539Z++ awk '$2 == "/home" { print $3 }' /etc/mnttab
352024-09-26T19:40:43.541Z+ home_fs=zfs
362024-09-26T19:40:43.541Z+ [[ zfs == autofs ]]
372024-09-26T19:40:43.541Z+ mkdir -p /home/build
382024-09-26T19:40:43.544Z+ chown build:build /home/build /work
392024-09-26T19:40:45.546Z+ chmod 0700 /home/build /work
402024-09-26T19:40:45.549Zprocess exited: duration 4239 ms, exit code 0
 
412024-09-26T19:40:45.554Zstarting task 1: "authentication"
422024-09-26T19:40:45.571Zprocess exited: duration 17 ms, exit code 0
 
432024-09-26T19:40:45.576Zstarting task 2: "build"
442024-09-26T19:40:45.581Z+ banner cores
452024-09-26T19:40:45.584Z
462024-09-26T19:40:45.584Z #### #### ##### ###### ####
472024-09-26T19:40:45.584Z # # # # # # # #
482024-09-26T19:40:45.584Z # # # # # ##### ####
492024-09-26T19:40:45.584Z # # # ##### # #
502024-09-26T19:40:45.584Z # # # # # # # # #
512024-09-26T19:40:45.584Z #### #### # # ###### ####
522024-09-26T19:40:45.584Z
532024-09-26T19:40:45.591Z+ pfexec coreadm -i /tmp/core.%f.%p -g /tmp/core.%f.%p -e global -e log -e proc-setid -e global-setid
542024-09-26T19:40:45.594Z+ echo 'input bins dir contains:'
552024-09-26T19:40:45.594Zinput bins dir contains:
562024-09-26T19:40:45.594Z+ ls -ltr /input/build/work/bins
572024-09-26T19:40:45.597Ztotal 751106
582024-09-26T19:40:45.597Z-rw-r--r-- 1 root root 108128498 Sep 26 19:40 crucible-downstairs.gz
592024-09-26T19:40:45.597Z-rw-r--r-- 1 root root 102507842 Sep 26 19:40 crucible-hammer.gz
602024-09-26T19:40:45.597Z-rw-r--r-- 1 root root 108480497 Sep 26 19:40 crutest.gz
612024-09-26T19:40:45.597Z-rw-r--r-- 1 root root 65196996 Sep 26 19:40 dsc.gz
622024-09-26T19:40:45.597Z+ banner unpack
632024-09-26T19:40:45.599Z
642024-09-26T19:40:45.599Z # # # # ##### ## #### # #
652024-09-26T19:40:45.599Z # # ## # # # # # # # # #
662024-09-26T19:40:45.599Z # # # # # # # # # # ####
672024-09-26T19:40:45.599Z # # # # # ##### ###### # # #
682024-09-26T19:40:45.599Z # # # ## # # # # # # #
692024-09-26T19:40:45.599Z #### # # # # # #### # #
702024-09-26T19:40:45.599Z
712024-09-26T19:40:45.599Z+ mkdir -p /var/tmp/bins
722024-09-26T19:40:45.602Z+ for t in "$input/bins/"*.gz
732024-09-26T19:40:45.604Z++ basename /input/build/work/bins/crucible-downstairs.gz
742024-09-26T19:40:45.605Z+ b=crucible-downstairs.gz
752024-09-26T19:40:45.605Z+ b=crucible-downstairs
762024-09-26T19:40:45.605Z+ gunzip
772024-09-26T19:40:47.847Z+ chmod +x /var/tmp/bins/crucible-downstairs
782024-09-26T19:40:47.850Z+ for t in "$input/bins/"*.gz
792024-09-26T19:40:47.853Z++ basename /input/build/work/bins/crucible-hammer.gz
802024-09-26T19:40:47.853Z+ b=crucible-hammer.gz
812024-09-26T19:40:47.853Z+ b=crucible-hammer
822024-09-26T19:40:47.853Z+ gunzip
832024-09-26T19:40:50.002Z+ chmod +x /var/tmp/bins/crucible-hammer
842024-09-26T19:40:50.005Z+ for t in "$input/bins/"*.gz
852024-09-26T19:40:50.007Z++ basename /input/build/work/bins/crutest.gz
862024-09-26T19:40:50.007Z+ b=crutest.gz
872024-09-26T19:40:50.007Z+ b=crutest
882024-09-26T19:40:50.007Z+ gunzip
892024-09-26T19:40:52.297Z+ chmod +x /var/tmp/bins/crutest
902024-09-26T19:40:52.299Z+ for t in "$input/bins/"*.gz
912024-09-26T19:40:52.301Z++ basename /input/build/work/bins/dsc.gz
922024-09-26T19:40:52.303Z+ b=dsc.gz
932024-09-26T19:40:52.303Z+ b=dsc
942024-09-26T19:40:52.303Z+ gunzip
952024-09-26T19:40:53.698Z+ chmod +x /var/tmp/bins/dsc
962024-09-26T19:40:53.701Z+ export BINDIR=/var/tmp/bins
972024-09-26T19:40:53.701Z+ BINDIR=/var/tmp/bins
982024-09-26T19:40:53.701Z+ jobpid=1139
992024-09-26T19:40:53.703Z+ echo 'Setup debug logging'
1002024-09-26T19:40:53.703ZSetup debug logging
1012024-09-26T19:40:53.703Z+ mkdir /tmp/debug
1022024-09-26T19:40:53.704Z+ sleep 7200
1032024-09-26T19:40:53.704Z+ psrinfo -v
1042024-09-26T19:40:53.707Z+ df -h
1052024-09-26T19:40:53.715Z+ prstat -d d -mLc 1
1062024-09-26T19:40:53.717Z+ iostat -T d -xn 1
1072024-09-26T19:40:53.717Z+ mpstat -T d 1
1082024-09-26T19:40:53.717Z+ vmstat -T d -p 1
1092024-09-26T19:40:53.717Z+ pfexec dtrace -Z -s /input/build/work/scripts/perf-downstairs-tick.d
1102024-09-26T19:40:53.717Z+ banner test_up_encrypted
1112024-09-26T19:40:53.720Z+ pfexec dtrace -Z -s /input/build/work/scripts/upstairs_info.d
1122024-09-26T19:40:53.720Z
1132024-09-26T19:40:53.720Z ##### ###### #### ##### # # ##### ###### # #
1142024-09-26T19:40:53.720Z # # # # # # # # # ## #
1152024-09-26T19:40:53.720Z # ##### #### # # # # # ##### # # #
1162024-09-26T19:40:53.720Z # # # # # # ##### # # # #
1172024-09-26T19:40:53.720Z # # # # # # # # # # ##
1182024-09-26T19:40:53.720Z # ###### #### # ####### #### # ####### ###### # #
1192024-09-26T19:40:53.720Z
1202024-09-26T19:40:53.720Z+ ptime -m bash /input/build/work/scripts/test_up.sh -N encrypted
1212024-09-26T19:40:53.731Z/input/build/work
1222024-09-26T19:40:53.743ZTurn off color for downstairs dump
1232024-09-26T19:40:53.759ZUpstairs using key: KeruT92rSzpt7C11x2JojzDpOaeMwkBp0YCWUYVSNTs=
1242024-09-26T19:40:53.762Zdsc output goes to /tmp/test_up-build/dsc-out.txt
1252024-09-26T19:40:53.762ZCreating three downstairs regions
1262024-09-26T19:40:54.208ZStarting three downstairs
1272024-09-26T19:40:59.216ZDisable automatic restart on all downstairs
1282024-09-26T19:40:59.277Z
1292024-09-26T19:40:59.277ZBegin tests, output goes to /tmp/test_up-build/test_up_out.txt
1302024-09-26T19:40:59.281ZRunning test: span
1312024-09-26T19:41:03.424ZCompleted test: span
1322024-09-26T19:41:08.432ZRunning test: big
1332024-09-26T19:41:12.842ZCompleted test: big
1342024-09-26T19:41:17.850ZRunning test: dep
1352024-09-26T19:42:12.615ZCompleted test: dep
1362024-09-26T19:42:17.623ZRunning test: balloon
1372024-09-26T19:43:03.481ZCompleted test: balloon
1382024-09-26T19:43:08.489ZRunning test: deactivate
1392024-09-26T19:43:59.242ZCompleted test: deactivate
1402024-09-26T19:44:04.243ZRunning hammer
1412024-09-26T19:44:17.849ZRun repair tests
1422024-09-26T19:44:17.853Z/var/tmp/bins/crutest fill -g 31 -q --key KeruT92rSzpt7C11x2JojzDpOaeMwkBp0YCWUYVSNTs= -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-26T19:44:17.868Z{"msg":"look at: http://127.0.0.1:12810 ","v":0,"name":"crucible","level":30,"time":"2024-09-26T19:44:16.913193614Z","hostname":"w-01J8QXH7SYQS95RZY0ACANYM79","pid":1219,"task":"crutest"}
1442024-09-26T19:44:17.912Z{"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-26T19:44:16.957357029Z","hostname":"w-01J8QXH7SYQS95RZY0ACANYM79","pid":1219,"task":"crutest"}
1452024-09-26T19:44:17.914Z{"msg":"Upstairs starts","v":0,"name":"crucible","level":30,"time":"2024-09-26T19:44:16.958002308Z","hostname":"w-01J8QXH7SYQS95RZY0ACANYM79","pid":1219}
1462024-09-26T19:44:17.914Z{"msg":"Crucible Version: BuildInfo {\n version: \"0.0.1\",\n git_sha: \"8e980c14034391699f5d7f17cfb24177d0aafaf2\",\n git_commit_timestamp: \"2024-09-26T19:23:10.000000000Z\",\n git_branch: \"alan/crutest-meet-dsc\",\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-26T19:44:16.958049351Z","hostname":"w-01J8QXH7SYQS95RZY0ACANYM79","pid":1219}
1472024-09-26T19:44:17.914Z{"msg":"Upstairs <-> Downstairs Message Version: 11","v":0,"name":"crucible","level":30,"time":"2024-09-26T19:44:16.958064898Z","hostname":"w-01J8QXH7SYQS95RZY0ACANYM79","pid":1219}
1482024-09-26T19:44:17.914Z{"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-26T19:44:16.958080036Z","hostname":"w-01J8QXH7SYQS95RZY0ACANYM79","pid":1219}
1492024-09-26T19:44:17.914Z{"msg":"Crucible 665942fa-cecc-4828-8d7e-95f1fd4eb08d has session id: d808d5d5-6209-4392-a723-f8a79a6b8dab","v":0,"name":"crucible","level":30,"time":"2024-09-26T19:44:16.958587396Z","hostname":"w-01J8QXH7SYQS95RZY0ACANYM79","pid":1219,"session_id":"d808d5d5-6209-4392-a723-f8a79a6b8dab"}
1502024-09-26T19:44:17.914Z{"msg":"Upstairs opts: Upstairs UUID: 665942fa-cecc-4828-8d7e-95f1fd4eb08d, 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-26T19:44:16.958643967Z","hostname":"w-01J8QXH7SYQS95RZY0ACANYM79","pid":1219,"session_id":"d808d5d5-6209-4392-a723-f8a79a6b8dab"}
1512024-09-26T19:44:17.914Z{"msg":"Crucible stats registered with UUID: 665942fa-cecc-4828-8d7e-95f1fd4eb08d","v":0,"name":"crucible","level":30,"time":"2024-09-26T19:44:16.958671333Z","hostname":"w-01J8QXH7SYQS95RZY0ACANYM79","pid":1219,"session_id":"d808d5d5-6209-4392-a723-f8a79a6b8dab"}
1522024-09-26T19:44:17.944Z{"msg":"The guest has requested activation with gen:31","v":0,"name":"crucible","level":30,"time":"2024-09-26T19:44:16.989637984Z","hostname":"w-01J8QXH7SYQS95RZY0ACANYM79","pid":1219}
1532024-09-26T19:44:17.944Z{"msg":"665942fa-cecc-4828-8d7e-95f1fd4eb08d active request set","v":0,"name":"crucible","level":30,"time":"2024-09-26T19:44:16.989681527Z","hostname":"w-01J8QXH7SYQS95RZY0ACANYM79","pid":1219,"session_id":"d808d5d5-6209-4392-a723-f8a79a6b8dab"}
1542024-09-26T19:44:17.947Z{"msg":"sending connect oneshot to client","v":0,"name":"crucible","level":30,"time":"2024-09-26T19:44:16.989701144Z","hostname":"w-01J8QXH7SYQS95RZY0ACANYM79","pid":1219,"client":"0","":"downstairs","session_id":"d808d5d5-6209-4392-a723-f8a79a6b8dab"}
1552024-09-26T19:44:17.947Z{"msg":"client set_active_request while in New; waiting...","v":0,"name":"crucible","level":30,"time":"2024-09-26T19:44:16.989741828Z","hostname":"w-01J8QXH7SYQS95RZY0ACANYM79","pid":1219,"client":"0","":"downstairs","session_id":"d808d5d5-6209-4392-a723-f8a79a6b8dab"}
1562024-09-26T19:44:17.947Z{"msg":"sending connect oneshot to client","v":0,"name":"crucible","level":30,"time":"2024-09-26T19:44:16.989762225Z","hostname":"w-01J8QXH7SYQS95RZY0ACANYM79","pid":1219,"client":"1","":"downstairs","session_id":"d808d5d5-6209-4392-a723-f8a79a6b8dab"}
1572024-09-26T19:44:17.948Z{"msg":"client set_active_request while in New; waiting...","v":0,"name":"crucible","level":30,"time":"2024-09-26T19:44:16.989803328Z","hostname":"w-01J8QXH7SYQS95RZY0ACANYM79","pid":1219,"client":"1","":"downstairs","session_id":"d808d5d5-6209-4392-a723-f8a79a6b8dab"}
1582024-09-26T19:44:17.948Z{"msg":"sending connect oneshot to client","v":0,"name":"crucible","level":30,"time":"2024-09-26T19:44:16.989834324Z","hostname":"w-01J8QXH7SYQS95RZY0ACANYM79","pid":1219,"client":"2","":"downstairs","session_id":"d808d5d5-6209-4392-a723-f8a79a6b8dab"}
1592024-09-26T19:44:17.948Z{"msg":"client set_active_request while in New; waiting...","v":0,"name":"crucible","level":30,"time":"2024-09-26T19:44:16.989862489Z","hostname":"w-01J8QXH7SYQS95RZY0ACANYM79","pid":1219,"client":"2","":"downstairs","session_id":"d808d5d5-6209-4392-a723-f8a79a6b8dab"}
1602024-09-26T19:44:17.948Z{"msg":"connecting to 127.0.0.1:8830","v":0,"name":"crucible","level":30,"time":"2024-09-26T19:44:16.989905512Z","hostname":"w-01J8QXH7SYQS95RZY0ACANYM79","pid":1219,"":"io task","client":"2","":"downstairs","session_id":"d808d5d5-6209-4392-a723-f8a79a6b8dab"}
1612024-09-26T19:44:17.948Z{"msg":"connecting to 127.0.0.1:8810","v":0,"name":"crucible","level":30,"time":"2024-09-26T19:44:16.989952165Z","hostname":"w-01J8QXH7SYQS95RZY0ACANYM79","pid":1219,"":"io task","client":"0","":"downstairs","session_id":"d808d5d5-6209-4392-a723-f8a79a6b8dab"}
1622024-09-26T19:44:17.948Z{"msg":"connecting to 127.0.0.1:8820","v":0,"name":"crucible","level":30,"time":"2024-09-26T19:44:16.98998535Z","hostname":"w-01J8QXH7SYQS95RZY0ACANYM79","pid":1219,"":"io task","client":"1","":"downstairs","session_id":"d808d5d5-6209-4392-a723-f8a79a6b8dab"}
1632024-09-26T19:44:17.948Z{"msg":"ds_connection connected from Ok(127.0.0.1:47244)","v":0,"name":"crucible","level":30,"time":"2024-09-26T19:44:16.990249479Z","hostname":"w-01J8QXH7SYQS95RZY0ACANYM79","pid":1219,"":"io task","client":"2","":"downstairs","session_id":"d808d5d5-6209-4392-a723-f8a79a6b8dab"}
1642024-09-26T19:44:17.948Z{"msg":"ds_connection connected from Ok(127.0.0.1:60946)","v":0,"name":"crucible","level":30,"time":"2024-09-26T19:44:16.99030347Z","hostname":"w-01J8QXH7SYQS95RZY0ACANYM79","pid":1219,"":"io task","client":"0","":"downstairs","session_id":"d808d5d5-6209-4392-a723-f8a79a6b8dab"}
1652024-09-26T19:44:17.948Z{"msg":"ds_connection connected from Ok(127.0.0.1:62685)","v":0,"name":"crucible","level":30,"time":"2024-09-26T19:44:16.990344964Z","hostname":"w-01J8QXH7SYQS95RZY0ACANYM79","pid":1219,"":"io task","client":"1","":"downstairs","session_id":"d808d5d5-6209-4392-a723-f8a79a6b8dab"}
1662024-09-26T19:44:17.948Z{"msg":"ds_transition from New to WaitActive","v":0,"name":"crucible","level":30,"time":"2024-09-26T19:44:16.990729454Z","hostname":"w-01J8QXH7SYQS95RZY0ACANYM79","pid":1219,"client":"1","":"downstairs","session_id":"d808d5d5-6209-4392-a723-f8a79a6b8dab"}
1672024-09-26T19:44:17.948Z{"msg":"[1] Transition from New to WaitActive","v":0,"name":"crucible","level":30,"time":"2024-09-26T19:44:16.990775936Z","hostname":"w-01J8QXH7SYQS95RZY0ACANYM79","pid":1219,"client":"1","":"downstairs","session_id":"d808d5d5-6209-4392-a723-f8a79a6b8dab"}
1682024-09-26T19:44:17.948Z{"msg":"ds_transition from New to WaitActive","v":0,"name":"crucible","level":30,"time":"2024-09-26T19:44:16.990803202Z","hostname":"w-01J8QXH7SYQS95RZY0ACANYM79","pid":1219,"client":"2","":"downstairs","session_id":"d808d5d5-6209-4392-a723-f8a79a6b8dab"}
1692024-09-26T19:44:17.948Z{"msg":"[2] Transition from New to WaitActive","v":0,"name":"crucible","level":30,"time":"2024-09-26T19:44:16.990830388Z","hostname":"w-01J8QXH7SYQS95RZY0ACANYM79","pid":1219,"client":"2","":"downstairs","session_id":"d808d5d5-6209-4392-a723-f8a79a6b8dab"}
1702024-09-26T19:44:17.948Z{"msg":"ds_transition from New to WaitActive","v":0,"name":"crucible","level":30,"time":"2024-09-26T19:44:16.990855184Z","hostname":"w-01J8QXH7SYQS95RZY0ACANYM79","pid":1219,"client":"0","":"downstairs","session_id":"d808d5d5-6209-4392-a723-f8a79a6b8dab"}
1712024-09-26T19:44:17.948Z{"msg":"[0] Transition from New to WaitActive","v":0,"name":"crucible","level":30,"time":"2024-09-26T19:44:16.990889608Z","hostname":"w-01J8QXH7SYQS95RZY0ACANYM79","pid":1219,"client":"0","":"downstairs","session_id":"d808d5d5-6209-4392-a723-f8a79a6b8dab"}
1722024-09-26T19:44:17.948Z{"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-26T19:44:16.991430684Z","hostname":"w-01J8QXH7SYQS95RZY0ACANYM79","pid":1219,"client":"1","":"downstairs","session_id":"d808d5d5-6209-4392-a723-f8a79a6b8dab"}
1732024-09-26T19:44:17.948Z{"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-26T19:44:16.991601527Z","hostname":"w-01J8QXH7SYQS95RZY0ACANYM79","pid":1219,"client":"0","":"downstairs","session_id":"d808d5d5-6209-4392-a723-f8a79a6b8dab"}
1742024-09-26T19:44:17.948Z{"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-26T19:44:16.991650079Z","hostname":"w-01J8QXH7SYQS95RZY0ACANYM79","pid":1219,"client":"2","":"downstairs","session_id":"d808d5d5-6209-4392-a723-f8a79a6b8dab"}
1752024-09-26T19:44:17.948Z{"msg":"ds_transition from WaitActive to WaitQuorum","v":0,"name":"crucible","level":30,"time":"2024-09-26T19:44:16.991812024Z","hostname":"w-01J8QXH7SYQS95RZY0ACANYM79","pid":1219,"client":"1","":"downstairs","session_id":"d808d5d5-6209-4392-a723-f8a79a6b8dab"}
1762024-09-26T19:44:17.948Z{"msg":"[1] Transition from WaitActive to WaitQuorum","v":0,"name":"crucible","level":30,"time":"2024-09-26T19:44:16.991845389Z","hostname":"w-01J8QXH7SYQS95RZY0ACANYM79","pid":1219,"client":"1","":"downstairs","session_id":"d808d5d5-6209-4392-a723-f8a79a6b8dab"}
1772024-09-26T19:44:17.948Z{"msg":"Waiting for more clients to be ready","v":0,"name":"crucible","level":30,"time":"2024-09-26T19:44:16.991871225Z","hostname":"w-01J8QXH7SYQS95RZY0ACANYM79","pid":1219,"session_id":"d808d5d5-6209-4392-a723-f8a79a6b8dab"}
1782024-09-26T19:44:17.948Z{"msg":"ds_transition from WaitActive to WaitQuorum","v":0,"name":"crucible","level":30,"time":"2024-09-26T19:44:16.991975308Z","hostname":"w-01J8QXH7SYQS95RZY0ACANYM79","pid":1219,"client":"0","":"downstairs","session_id":"d808d5d5-6209-4392-a723-f8a79a6b8dab"}
1792024-09-26T19:44:17.948Z{"msg":"[0] Transition from WaitActive to WaitQuorum","v":0,"name":"crucible","level":30,"time":"2024-09-26T19:44:16.992016822Z","hostname":"w-01J8QXH7SYQS95RZY0ACANYM79","pid":1219,"client":"0","":"downstairs","session_id":"d808d5d5-6209-4392-a723-f8a79a6b8dab"}
1802024-09-26T19:44:17.948Z{"msg":"Waiting for more clients to be ready","v":0,"name":"crucible","level":30,"time":"2024-09-26T19:44:16.992032809Z","hostname":"w-01J8QXH7SYQS95RZY0ACANYM79","pid":1219,"session_id":"d808d5d5-6209-4392-a723-f8a79a6b8dab"}
1812024-09-26T19:44:17.948Z{"msg":"ds_transition from WaitActive to WaitQuorum","v":0,"name":"crucible","level":30,"time":"2024-09-26T19:44:16.992053196Z","hostname":"w-01J8QXH7SYQS95RZY0ACANYM79","pid":1219,"client":"2","":"downstairs","session_id":"d808d5d5-6209-4392-a723-f8a79a6b8dab"}
1822024-09-26T19:44:17.948Z{"msg":"[2] Transition from WaitActive to WaitQuorum","v":0,"name":"crucible","level":30,"time":"2024-09-26T19:44:16.992067514Z","hostname":"w-01J8QXH7SYQS95RZY0ACANYM79","pid":1219,"client":"2","":"downstairs","session_id":"d808d5d5-6209-4392-a723-f8a79a6b8dab"}
1832024-09-26T19:44:17.948Z{"msg":"[0]R flush_numbers: [1696, 1696, 1696, 1696, 1696]","v":0,"name":"crucible","level":30,"time":"2024-09-26T19:44:16.992080992Z","hostname":"w-01J8QXH7SYQS95RZY0ACANYM79","pid":1219,"":"downstairs","":"downstairs","session_id":"d808d5d5-6209-4392-a723-f8a79a6b8dab"}
1842024-09-26T19:44:17.948Z{"msg":"[0]R generation: [25, 25, 25, 25, 25]","v":0,"name":"crucible","level":30,"time":"2024-09-26T19:44:16.992095489Z","hostname":"w-01J8QXH7SYQS95RZY0ACANYM79","pid":1219,"":"downstairs","":"downstairs","session_id":"d808d5d5-6209-4392-a723-f8a79a6b8dab"}
1852024-09-26T19:44:17.948Z{"msg":"[0]R dirty: [false, false, false, false, false]","v":0,"name":"crucible","level":30,"time":"2024-09-26T19:44:16.992109127Z","hostname":"w-01J8QXH7SYQS95RZY0ACANYM79","pid":1219,"":"downstairs","":"downstairs","session_id":"d808d5d5-6209-4392-a723-f8a79a6b8dab"}
1862024-09-26T19:44:17.948Z{"msg":"[1]R flush_numbers: [1696, 1696, 1696, 1696, 1696]","v":0,"name":"crucible","level":30,"time":"2024-09-26T19:44:16.992130074Z","hostname":"w-01J8QXH7SYQS95RZY0ACANYM79","pid":1219,"":"downstairs","":"downstairs","session_id":"d808d5d5-6209-4392-a723-f8a79a6b8dab"}
1872024-09-26T19:44:17.948Z{"msg":"[1]R generation: [25, 25, 25, 25, 25]","v":0,"name":"crucible","level":30,"time":"2024-09-26T19:44:16.992143712Z","hostname":"w-01J8QXH7SYQS95RZY0ACANYM79","pid":1219,"":"downstairs","":"downstairs","session_id":"d808d5d5-6209-4392-a723-f8a79a6b8dab"}
1882024-09-26T19:44:17.948Z{"msg":"[1]R dirty: [false, false, false, false, false]","v":0,"name":"crucible","level":30,"time":"2024-09-26T19:44:16.99215686Z","hostname":"w-01J8QXH7SYQS95RZY0ACANYM79","pid":1219,"":"downstairs","":"downstairs","session_id":"d808d5d5-6209-4392-a723-f8a79a6b8dab"}
1892024-09-26T19:44:17.948Z{"msg":"[2]R flush_numbers: [1696, 1696, 1696, 1696, 1696]","v":0,"name":"crucible","level":30,"time":"2024-09-26T19:44:16.992178007Z","hostname":"w-01J8QXH7SYQS95RZY0ACANYM79","pid":1219,"":"downstairs","":"downstairs","session_id":"d808d5d5-6209-4392-a723-f8a79a6b8dab"}
1902024-09-26T19:44:17.948Z{"msg":"[2]R generation: [25, 25, 25, 25, 25]","v":0,"name":"crucible","level":30,"time":"2024-09-26T19:44:16.992191725Z","hostname":"w-01J8QXH7SYQS95RZY0ACANYM79","pid":1219,"":"downstairs","":"downstairs","session_id":"d808d5d5-6209-4392-a723-f8a79a6b8dab"}
1912024-09-26T19:44:17.948Z{"msg":"[2]R dirty: [false, false, false, false, false]","v":0,"name":"crucible","level":30,"time":"2024-09-26T19:44:16.992205882Z","hostname":"w-01J8QXH7SYQS95RZY0ACANYM79","pid":1219,"":"downstairs","":"downstairs","session_id":"d808d5d5-6209-4392-a723-f8a79a6b8dab"}
1922024-09-26T19:44:17.948Z{"msg":"Max found gen is 26","v":0,"name":"crucible","level":30,"time":"2024-09-26T19:44:16.992225729Z","hostname":"w-01J8QXH7SYQS95RZY0ACANYM79","pid":1219,"":"downstairs","":"downstairs","session_id":"d808d5d5-6209-4392-a723-f8a79a6b8dab"}
1932024-09-26T19:44:17.948Z{"msg":"Generation requested: 31 >= found:26","v":0,"name":"crucible","level":30,Wait for a query_work_queue command to finish before sending IO
1942024-09-26T19:44:17.948Z"time":"2024-09-26T19:44:16.992239207Z","hostname":"w-01J8QXH7SYQS95RZY0ACANYM79","pid":1219,"":"downstairs","":"downstairs","session_id":"d808d5d5-6209-4392-a723-f8a79a6b8dab"}
1952024-09-26T19:44:17.948Z{"msg":"Next flush: 1697","v":0,"name":"crucible","level":30,"time":"2024-09-26T19:44:16.99228472Z","hostname":"w-01J8QXH7SYQS95RZY0ACANYM79","pid":1219,"":"downstairs","":"downstairs","session_id":"d808d5d5-6209-4392-a723-f8a79a6b8dab"}
1962024-09-26T19:44:17.949Z{"msg":"All extents match","v":0,"name":"crucible","level":30,"time":"2024-09-26T19:44:16.992299258Z","hostname":"w-01J8QXH7SYQS95RZY0ACANYM79","pid":1219,"":"downstairs","":"downstairs","session_id":"d808d5d5-6209-4392-a723-f8a79a6b8dab"}
1972024-09-26T19:44:17.949Z{"msg":"No downstairs reconciliation required","v":0,"name":"crucible","level":30,"time":"2024-09-26T19:44:16.992320644Z","hostname":"w-01J8QXH7SYQS95RZY0ACANYM79","pid":1219,"session_id":"d808d5d5-6209-4392-a723-f8a79a6b8dab"}
1982024-09-26T19:44:17.949Z{"msg":"Transition from WaitQuorum to Active","v":0,"name":"crucible","level":30,"time":"2024-09-26T19:44:16.992333342Z","hostname":"w-01J8QXH7SYQS95RZY0ACANYM79","pid":1219,"client":"0","":"downstairs","session_id":"d808d5d5-6209-4392-a723-f8a79a6b8dab"}
1992024-09-26T19:44:17.949Z{"msg":"Transition from WaitQuorum to Active","v":0,"name":"crucible","level":30,"time":"2024-09-26T19:44:16.992359468Z","hostname":"w-01J8QXH7SYQS95RZY0ACANYM79","pid":1219,"client":"1","":"downstairs","session_id":"d808d5d5-6209-4392-a723-f8a79a6b8dab"}
2002024-09-26T19:44:17.949Z{"msg":"Transition from WaitQuorum to Active","v":0,"name":"crucible","level":30,"time":"2024-09-26T19:44:16.992373146Z","hostname":"w-01J8QXH7SYQS95RZY0ACANYM79","pid":1219,"client":"2","":"downstairs","session_id":"d808d5d5-6209-4392-a723-f8a79a6b8dab"}
2012024-09-26T19:44:17.951Z{"msg":"All required reconciliation work is completed","v":0,"name":"crucible","level":30,"time":"2024-09-26T19:44:16.992387144Z","hostname":"w-01J8QXH7SYQS95RZY0ACANYM79","pid":1219,"session_id":"d808d5d5-6209-4392-a723-f8a79a6b8dab"}
2022024-09-26T19:44:17.951Z{"msg":"Set Downstairs and Upstairs active after reconciliation","v":0,"name":"crucible","level":30,"time":"2024-09-26T19:44:16.992400382Z","hostname":"w-01J8QXH7SYQS95RZY0ACANYM79","pid":1219,"session_id":"d808d5d5-6209-4392-a723-f8a79a6b8dab"}
2032024-09-26T19:44:17.951Z{"msg":"665942fa-cecc-4828-8d7e-95f1fd4eb08d is now active with session: d808d5d5-6209-4392-a723-f8a79a6b8dab","v":0,"name":"crucible","level":30,"time":"2024-09-26T19:44:16.99241325Z","hostname":"w-01J8QXH7SYQS95RZY0ACANYM79","pid":1219,"session_id":"d808d5d5-6209-4392-a723-f8a79a6b8dab"}
2042024-09-26T19:44:17.951Z{"msg":"Set Active after no reconciliation","v":0,"name":"crucible","level":30,"time":"2024-09-26T19:44:16.992433047Z","hostname":"w-01J8QXH7SYQS95RZY0ACANYM79","pid":1219,"session_id":"d808d5d5-6209-4392-a723-f8a79a6b8dab"}
2052024-09-26T19:44:17.951Z{"msg":"The guest has finished waiting for activation with:31","v":0,"name":"crucible","level":30Region: es:10 ec:5 bs:4096 ts:204800 tb:50 max_io:50 or 204800
2062024-09-26T19:44:17.951Z,"time":"2024-09-26T19:44:16.992446885Z","hostname":"w-01J8QXH7SYQS95RZY0ACANYM79","pid":1219}
2072024-09-26T19:44:17.951ZFill test
2082024-09-26T19:44:17.989ZRead and Verify all blocks (0..50 range:false)
2092024-09-26T19:44:18.031ZWrote out file "/var/tmp/test_up-build/verify_file"
2102024-09-26T19:44:18.031ZCLIENT: Tests done. All submitted work has been ACK'd
2112024-09-26T19:44:18.033Z----------------------------------------------------------------
2122024-09-26T19:44:18.033Z Crucible gen:31 GIO:true work queues: Upstairs:0 downstairs:1
2132024-09-26T19:44:18.033ZStates: Active Active Active
2142024-09-26T19:44:18.033ZGW_ID ACK DSID TYPE BKS/EXT DS:0 DS:1 DS:2 REPLAY
2152024-09-26T19:44:18.033Z 3 Acked 1002 Read 50 Done Done Done false
2162024-09-26T19:44:18.033Z STATES DS:0 DS:1 DS:2 TOTAL
2172024-09-26T19:44:18.033Z Sent 0 0 0 0
2182024-09-26T19:44:18.033Z Done 1 1 1 3
2192024-09-26T19:44:18.033Z Skipped 0 0 0 0
2202024-09-26T19:44:18.033Z Error 0 0 0 0
2212024-09-26T19:44:18.033ZLast Flush: 1001 1001 1001
2222024-09-26T19:44:18.033ZDownstairs last five completed: 1001 1000
2232024-09-26T19:44:18.033ZUpstairs last five completed: 3 2 1
2242024-09-26T19:44:18.033ZCLIENT: Up:0 ds:1 act:3
2252024-09-26T19:44:22.034Z----------------------------------------------------------------
2262024-09-26T19:44:22.034Z Crucible gen:31 GIO:true work queues: Upstairs:0 downstairs:0
2272024-09-26T19:44:22.034ZDownstairs last five completed: 1003 1002 1001 1000
2282024-09-26T19:44:22.034ZUpstairs last five completed: 4 3 2 1
2292024-09-26T19:44:22.034ZCLIENT: Up:0 ds:0 act:3
2302024-09-26T19:44:22.034ZCLIENT: All crucible jobs finished, exiting program
2312024-09-26T19:44:22.036Z{"msg":"Guest handle has been dropped","v":0,"name":"crucible","level":40,"time":"2024-09-26T19:44:21.078438169Z","hostname":"w-01J8QXH7SYQS95RZY0ACANYM79","pid":1219}
2322024-09-26T19:44:22.045ZRepair setup passed
2332024-09-26T19:44:22.048ZCopy the 8830 file
2342024-09-26T19:44:22.051Zcp -r /var/tmp/test_up-build/8830 /var/tmp/test_up-build/previous
2352024-09-26T19:44:22.054Z/var/tmp/bins/crutest repair -g 32 -q --key KeruT92rSzpt7C11x2JojzDpOaeMwkBp0YCWUYVSNTs= -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-26T19:44:22.066Z{"msg":"look at: http://127.0.0.1:12810 ","v":0,"name":"crucible","level":30,"time":"2024-09-26T19:44:21.111124021Z","hostname":"w-01J8QXH7SYQS95RZY0ACANYM79","pid":1225,"task":"crutest"}
2372024-09-26T19:44:22.111Z{"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-26T19:44:21.155586339Z","hostname":"w-01J8QXH7SYQS95RZY0ACANYM79","pid":1225,"task":"crutest"}
2382024-09-26T19:44:22.113Z{"msg":"Upstairs starts","v":0,"name":"crucible","level":30,"time":"2024-09-26T19:44:21.156252565Z","hostname":"w-01J8QXH7SYQS95RZY0ACANYM79","pid":1225}
2392024-09-26T19:44:22.113Z{"msg":"Crucible Version: BuildInfo {\n version: \"0.0.1\",\n git_sha: \"8e980c14034391699f5d7f17cfb24177d0aafaf2\",\n git_commit_timestamp: \"2024-09-26T19:23:10.000000000Z\",\n git_branch: \"alan/crutest-meet-dsc\",\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-26T19:44:21.156307806Z","hostname":"w-01J8QXH7SYQS95RZY0ACANYM79","pid":1225}
2402024-09-26T19:44:22.113Z{"msg":"Upstairs <-> Downstairs Message Version: 11","v":0,"name":"crucible","level":30,"time":"2024-09-26T19:44:21.156328883Z","hostname":"w-01J8QXH7SYQS95RZY0ACANYM79","pid":1225}
2412024-09-26T19:44:22.113Z{"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-26T19:44:21.156357299Z","hostname":"w-01J8QXH7SYQS95RZY0ACANYM79","pid":1225}
2422024-09-26T19:44:22.113Z{"msg":"Crucible da458d71-e833-429a-b0d7-5c6d6aafea5a has session id: f8dba5d1-9777-4827-9cbb-a33f45e17ed4","v":0,"name":"crucible","level":30,"time":"2024-09-26T19:44:21.156722051Z","hostname":"w-01J8QXH7SYQS95RZY0ACANYM79","pid":1225,"session_id":"f8dba5d1-9777-4827-9cbb-a33f45e17ed4"}
2432024-09-26T19:44:22.113Z{"msg":"Upstairs opts: Upstairs UUID: da458d71-e833-429a-b0d7-5c6d6aafea5a, 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-26T19:44:21.156771664Z","hostname":"w-01J8QXH7SYQS95RZY0ACANYM79","pid":1225,"session_id":"f8dba5d1-9777-4827-9cbb-a33f45e17ed4"}
2442024-09-26T19:44:22.113Z{"msg":"Crucible stats registered with UUID: da458d71-e833-429a-b0d7-5c6d6aafea5a","v":0,"name":"crucible","level":30,"time":"2024-09-26T19:44:21.156806978Z","hostname":"w-01J8QXH7SYQS95RZY0ACANYM79","pid":1225,"session_id":"f8dba5d1-9777-4827-9cbb-a33f45e17ed4"}
2452024-09-26T19:44:22.144Z{"msg":"The guest has requested activation with gen:32","v":0,"name":"crucible","level":30,"time":"2024-09-26T19:44:21.188425667Z","hostname":"w-01J8QXH7SYQS95RZY0ACANYM79","pid":1225}
2462024-09-26T19:44:22.144Z{"msg":"da458d71-e833-429a-b0d7-5c6d6aafea5a active request set","v":0,"name":"crucible","level":30,"time":"2024-09-26T19:44:21.188468291Z","hostname":"w-01J8QXH7SYQS95RZY0ACANYM79","pid":1225,"session_id":"f8dba5d1-9777-4827-9cbb-a33f45e17ed4"}
2472024-09-26T19:44:22.144Z{"msg":"sending connect oneshot to client","v":0,"name":"crucible","level":30,"time":"2024-09-26T19:44:21.188486268Z","hostname":"w-01J8QXH7SYQS95RZY0ACANYM79","pid":1225,"client":"0","":"downstairs","session_id":"f8dba5d1-9777-4827-9cbb-a33f45e17ed4"}
2482024-09-26T19:44:22.146Z{"msg":"client set_active_request while in New; waiting...","v":0,"name":"crucible","level":30,"time":"2024-09-26T19:44:21.188516143Z","hostname":"w-01J8QXH7SYQS95RZY0ACANYM79","pid":1225,"client":"0","":"downstairs","session_id":"f8dba5d1-9777-4827-9cbb-a33f45e17ed4"}
2492024-09-26T19:44:22.147Z{"msg":"sending connect oneshot to client","v":0,"name":"crucible","level":30,"time":"2024-09-26T19:44:21.188555787Z","hostname":"w-01J8QXH7SYQS95RZY0ACANYM79","pid":1225,"client":"1","":"downstairs","session_id":"f8dba5d1-9777-4827-9cbb-a33f45e17ed4"}
2502024-09-26T19:44:22.147Z{"msg":"client set_active_request while in New; waiting...","v":0,"name":"crucible","level":30,"time":"2024-09-26T19:44:21.188623506Z","hostname":"w-01J8QXH7SYQS95RZY0ACANYM79","pid":1225,"client":"1","":"downstairs","session_id":"f8dba5d1-9777-4827-9cbb-a33f45e17ed4"}
2512024-09-26T19:44:22.147Z{"msg":"sending connect oneshot to client","v":0,"name":"crucible","level":30,"time":"2024-09-26T19:44:21.188655051Z","hostname":"w-01J8QXH7SYQS95RZY0ACANYM79","pid":1225,"client":"2","":"downstairs","session_id":"f8dba5d1-9777-4827-9cbb-a33f45e17ed4"}
2522024-09-26T19:44:22.147Z{"msg":"client set_active_request while in New; waiting...","v":0,"name":"crucible","level":30,"time":"2024-09-26T19:44:21.188683677Z","hostname":"w-01J8QXH7SYQS95RZY0ACANYM79","pid":1225,"client":"2","":"downstairs","session_id":"f8dba5d1-9777-4827-9cbb-a33f45e17ed4"}
2532024-09-26T19:44:22.147Z{"msg":"connecting to 127.0.0.1:8830","v":0,"name":"crucible","level":30,"time":"2024-09-26T19:44:21.188708763Z","hostname":"w-01J8QXH7SYQS95RZY0ACANYM79","pid":1225,"":"io task","client":"2","":"downstairs","session_id":"f8dba5d1-9777-4827-9cbb-a33f45e17ed4"}
2542024-09-26T19:44:22.147Z{"msg":"connecting to 127.0.0.1:8810","v":0,"name":"crucible","level":30,"time":"2024-09-26T19:44:21.188731939Z","hostname":"w-01J8QXH7SYQS95RZY0ACANYM79","pid":1225,"":"io task","client":"0","":"downstairs","session_id":"f8dba5d1-9777-4827-9cbb-a33f45e17ed4"}
2552024-09-26T19:44:22.147Z{"msg":"connecting to 127.0.0.1:8820","v":0,"name":"crucible","level":30,"time":"2024-09-26T19:44:21.188769033Z","hostname":"w-01J8QXH7SYQS95RZY0ACANYM79","pid":1225,"":"io task","client":"1","":"downstairs","session_id":"f8dba5d1-9777-4827-9cbb-a33f45e17ed4"}
2562024-09-26T19:44:22.147Z{"msg":"ds_connection connected from Ok(127.0.0.1:45727)","v":0,"name":"crucible","level":30,"time":"2024-09-26T19:44:21.188969712Z","hostname":"w-01J8QXH7SYQS95RZY0ACANYM79","pid":1225,"":"io task","client":"2","":"downstairs","session_id":"f8dba5d1-9777-4827-9cbb-a33f45e17ed4"}
2572024-09-26T19:44:22.147Z{"msg":"ds_connection connected from Ok(127.0.0.1:39571)","v":0,"name":"crucible","level":30,"time":"2024-09-26T19:44:21.18904559Z","hostname":"w-01J8QXH7SYQS95RZY0ACANYM79","pid":1225,"":"io task","client":"1","":"downstairs","session_id":"f8dba5d1-9777-4827-9cbb-a33f45e17ed4"}
2582024-09-26T19:44:22.147Z{"msg":"ds_connection connected from Ok(127.0.0.1:41185)","v":0,"name":"crucible","level":30,"time":"2024-09-26T19:44:21.189082564Z","hostname":"w-01J8QXH7SYQS95RZY0ACANYM79","pid":1225,"":"io task","client":"0","":"downstairs","session_id":"f8dba5d1-9777-4827-9cbb-a33f45e17ed4"}
2592024-09-26T19:44:22.147Z{"msg":"ds_transition from New to WaitActive","v":0,"name":"crucible","level":30,"time":"2024-09-26T19:44:21.189530964Z","hostname":"w-01J8QXH7SYQS95RZY0ACANYM79","pid":1225,"client":"0","":"downstairs","session_id":"f8dba5d1-9777-4827-9cbb-a33f45e17ed4"}
2602024-09-26T19:44:22.147Z{"msg":"[0] Transition from New to WaitActive","v":0,"name":"crucible","level":30,"time":"2024-09-26T19:44:21.189635438Z","hostname":"w-01J8QXH7SYQS95RZY0ACANYM79","pid":1225,"client":"0","":"downstairs","session_id":"f8dba5d1-9777-4827-9cbb-a33f45e17ed4"}
2612024-09-26T19:44:22.147Z{"msg":"ds_transition from New to WaitActive","v":0,"name":"crucible","level":30,"time":"2024-09-26T19:44:21.189708996Z","hostname":"w-01J8QXH7SYQS95RZY0ACANYM79","pid":1225,"client":"2","":"downstairs","session_id":"f8dba5d1-9777-4827-9cbb-a33f45e17ed4"}
2622024-09-26T19:44:22.147Z{"msg":"[2] Transition from New to WaitActive","v":0,"name":"crucible","level":30,"time":"2024-09-26T19:44:21.18975121Z","hostname":"w-01J8QXH7SYQS95RZY0ACANYM79","pid":1225,"client":"2","":"downstairs","session_id":"f8dba5d1-9777-4827-9cbb-a33f45e17ed4"}
2632024-09-26T19:44:22.147Z{"msg":"ds_transition from New to WaitActive","v":0,"name":"crucible","level":30,"time":"2024-09-26T19:44:21.189787174Z","hostname":"w-01J8QXH7SYQS95RZY0ACANYM79","pid":1225,"client":"1","":"downstairs","session_id":"f8dba5d1-9777-4827-9cbb-a33f45e17ed4"}
2642024-09-26T19:44:22.147Z{"msg":"[1] Transition from New to WaitActive","v":0,"name":"crucible","level":30,"time":"2024-09-26T19:44:21.189855803Z","hostname":"w-01J8QXH7SYQS95RZY0ACANYM79","pid":1225,"client":"1","":"downstairs","session_id":"f8dba5d1-9777-4827-9cbb-a33f45e17ed4"}
2652024-09-26T19:44:22.147Z{"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-26T19:44:21.190226025Z","hostname":"w-01J8QXH7SYQS95RZY0ACANYM79","pid":1225,"client":"2","":"downstairs","session_id":"f8dba5d1-9777-4827-9cbb-a33f45e17ed4"}
2662024-09-26T19:44:22.147Z{"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-26T19:44:21.190264339Z","hostname":"w-01J8QXH7SYQS95RZY0ACANYM79","pid":1225,"client":"0","":"downstairs","session_id":"f8dba5d1-9777-4827-9cbb-a33f45e17ed4"}
2672024-09-26T19:44:22.147Z{"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-26T19:44:21.190392469Z","hostname":"w-01J8QXH7SYQS95RZY0ACANYM79","pid":1225,"client":"1","":"downstairs","session_id":"f8dba5d1-9777-4827-9cbb-a33f45e17ed4"}
2682024-09-26T19:44:22.147Z{"msg":"ds_transition from WaitActive to WaitQuorum","v":0,"name":"crucible","level":30,"time":"2024-09-26T19:44:21.190654388Z","hostname":"w-01J8QXH7SYQS95RZY0ACANYM79","pid":1225,"client":"0","":"downstairs","session_id":"f8dba5d1-9777-4827-9cbb-a33f45e17ed4"}
2692024-09-26T19:44:22.147Z{"msg":"[0] Transition from WaitActive to WaitQuorum","v":0,"name":"crucible","level":30,"time":"2024-09-26T19:44:21.190703421Z","hostname":"w-01J8QXH7SYQS95RZY0ACANYM79","pid":1225,"client":"0","":"downstairs","session_id":"f8dba5d1-9777-4827-9cbb-a33f45e17ed4"}
2702024-09-26T19:44:22.147Z{"msg":"Waiting for more clients to be ready","v":0,"name":"crucible","level":30,"time":"2024-09-26T19:44:21.190731726Z","hostname":"w-01J8QXH7SYQS95RZY0ACANYM79","pid":1225,"session_id":"f8dba5d1-9777-4827-9cbb-a33f45e17ed4"}
2712024-09-26T19:44:22.147Z{"msg":"ds_transition from WaitActive to WaitQuorum","v":0,"name":"crucible","level":30,"time":"2024-09-26T19:44:21.190760512Z","hostname":"w-01J8QXH7SYQS95RZY0ACANYM79","pid":1225,"client":"1","":"downstairs","session_id":"f8dba5d1-9777-4827-9cbb-a33f45e17ed4"}
2722024-09-26T19:44:22.147Z{"msg":"[1] Transition from WaitActive to WaitQuorum","v":0,"name":"crucible","level":30,"time":"2024-09-26T19:44:21.190783548Z","hostname":"w-01J8QXH7SYQS95RZY0ACANYM79","pid":1225,"client":"1","":"downstairs","session_id":"f8dba5d1-9777-4827-9cbb-a33f45e17ed4"}
2732024-09-26T19:44:22.147Z{"msg":"Waiting for more clients to be ready","v":0,"name":"crucible","level":30,"time":"2024-09-26T19:44:21.190810224Z","hostname":"w-01J8QXH7SYQS95RZY0ACANYM79","pid":1225,"session_id":"f8dba5d1-9777-4827-9cbb-a33f45e17ed4"}
2742024-09-26T19:44:22.147Z{"msg":"ds_transition from WaitActive to WaitQuorum","v":0,"name":"crucible","level":30,"time":"2024-09-26T19:44:21.190849328Z","hostname":"w-01J8QXH7SYQS95RZY0ACANYM79","pid":1225,"client":"2","":"downstairs","session_id":"f8dba5d1-9777-4827-9cbb-a33f45e17ed4"}
2752024-09-26T19:44:22.147Z{"msg":"[2] Transition from WaitActive to WaitQuorum","v":0,"name":"crucible","level":30,"time":"2024-09-26T19:44:21.190864915Z","hostname":"w-01J8QXH7SYQS95RZY0ACANYM79","pid":1225,"client":"2","":"downstairs","session_id":"f8dba5d1-9777-4827-9cbb-a33f45e17ed4"}
2762024-09-26T19:44:22.147Z{"msg":"[0]R flush_numbers: [1697, 1697, 1697, 1697, 1697]","v":0,"name":"crucible","level":30,"time":"2024-09-26T19:44:21.190879193Z","hostname":"w-01J8QXH7SYQS95RZY0ACANYM79","pid":1225,"":"downstairs","":"downstairs","session_id":"f8dba5d1-9777-4827-9cbb-a33f45e17ed4"}
2772024-09-26T19:44:22.147Z{"msg":"[0]R generation: [31, 31, 31, 31, 31]","v":0,"name":"crucible","level":30,"time":"2024-09-26T19:44:21.190892841Z","hostname":"w-01J8QXH7SYQS95RZY0ACANYM79","pid":1225,"":"downstairs","":"downstairs","session_id":"f8dba5d1-9777-4827-9cbb-a33f45e17ed4"}
2782024-09-26T19:44:22.147Z{"msg":"[0]R dirty: [false, false, false, false, false]","v":0,"name":"crucible","level":30,"time":"2024-09-26T19:44:21.190914148Z","hostname":"w-01J8QXH7SYQS95RZY0ACANYM79","pid":1225,"":"downstairs","":"downstairs","session_id":"f8dba5d1-9777-4827-9cbb-a33f45e17ed4"}
2792024-09-26T19:44:22.147Z{"msg":"[1]R flush_numbers: [1697, 1697, 1697, 1697, 1697]","v":0,"name":"crucible","level":30,"time":"2024-09-26T19:44:21.190928275Z","hostname":"w-01J8QXH7SYQS95RZY0ACANYM79","pid":1225,"":"downstairs","":"downstairs","session_id":"f8dba5d1-9777-4827-9cbb-a33f45e17ed4"}
2802024-09-26T19:44:22.147Z{"msg":"[1]R generation: [31, 31, 31, 31, 31]","v":0,"name":"crucible","level":30,"time":"2024-09-26T19:44:21.190948542Z","hostname":"w-01J8QXH7SYQS95RZY0ACANYM79","pid":1225,"":"downstairs","":"downstairs","session_id":"f8dba5d1-9777-4827-9cbb-a33f45e17ed4"}
2812024-09-26T19:44:22.147Z{"msg":"[1]R dirty: [false, false, false, false, false]","v":0,"name":"crucible","level":30,"time":"2024-09-26T19:44:21.19096218Z","hostname":"w-01J8QXH7SYQS95RZY0ACANYM79","pid":1225,"":"downstairs","":"downstairs","session_id":"f8dba5d1-9777-4827-9cbb-a33f45e17ed4"}
2822024-09-26T19:44:22.148Z{"msg":"[2]R flush_numbers: [1697, 1697, 1697, 1697, 1697]","v":0,"name":"crucible","level":30,"time":"2024-09-26T19:44:21.190982127Z","hostname":"w-01J8QXH7SYQS95RZY0ACANYM79","pid":1225,"":"downstairs","":"downstairs","session_id":"f8dba5d1-9777-4827-9cbb-a33f45e17ed4"}
2832024-09-26T19:44:22.148Z{"msg":"[2]R generation: [31, 31, 31, 31, 31]","v":0,"name":"crucible","level":30,"time":"2024-09-26T19:44:21.190995615Z","hostname":"w-01J8QXH7SYQS95RZY0ACANYM79","pid":1225,"":"downstairs","":"downstairs","session_id":"f8dba5d1-9777-4827-9cbb-a33f45e17ed4"}
2842024-09-26T19:44:22.148Z{"msg":"[2]R dirty: [false, false, false, false, false]","v":0,"name":"crucible","level":30,"time":"2024-09-26T19:44:21.191015682Z","hostname":"w-01J8QXH7SYQS95RZY0ACANYM79","pid":1225,"":"downstairs","":"downstairs","session_id":"f8dba5d1-9777-4827-9cbb-a33f45e17ed4"}
2852024-09-26T19:44:22.148Z{"msg":"Max found gen is 32","v":0,"name":"crucible","level":30Wait for a query_work_queue command to finish before sending IO
2862024-09-26T19:44:22.148Z,"time":"2024-09-26T19:44:21.191035678Z","hostname":"w-01J8QXH7SYQS95RZY0ACANYM79","pid":1225,"":"downstairs","":"downstairs","session_id":"f8dba5d1-9777-4827-9cbb-a33f45e17ed4"}
2872024-09-26T19:44:22.148Z{"msg":"Generation requested: 32 >= found:32","v":0,"name":"crucible","level":30,"time":"2024-09-26T19:44:21.191055646Z","hostname":"w-01J8QXH7SYQS95RZY0ACANYM79","pid":1225,"":"downstairs","":"downstairs","session_id":"f8dba5d1-9777-4827-9cbb-a33f45e17ed4"}
2882024-09-26T19:44:22.148Z{"msg":"Next flush: 1698","v":0,"name":"crucible","level":30,"time":"2024-09-26T19:44:21.191068384Z","hostname":"w-01J8QXH7SYQS95RZY0ACANYM79","pid":1225,"":"downstairs","":"downstairs","session_id":"f8dba5d1-9777-4827-9cbb-a33f45e17ed4"}
2892024-09-26T19:44:22.148Z{"msg":"All extents match","v":0,"name":"crucible","level":30,"time":"2024-09-26T19:44:21.191083961Z","hostname":"w-01J8QXH7SYQS95RZY0ACANYM79","pid":1225,"":"downstairs","":"downstairs","session_id":"f8dba5d1-9777-4827-9cbb-a33f45e17ed4"}
2902024-09-26T19:44:22.148Z{"msg":"No downstairs reconciliation required","v":0,"name":"crucible","level":30,"time":"2024-09-26T19:44:21.191101348Z","hostname":"w-01J8QXH7SYQS95RZY0ACANYM79","pid":1225,"session_id":"f8dba5d1-9777-4827-9cbb-a33f45e17ed4"}
2912024-09-26T19:44:22.148Z{"msg":"Transition from WaitQuorum to Active","v":0,"name":"crucible","level":30,"time":"2024-09-26T19:44:21.191114076Z","hostname":"w-01J8QXH7SYQS95RZY0ACANYM79","pid":1225,"client":"0","":"downstairs","session_id":"f8dba5d1-9777-4827-9cbb-a33f45e17ed4"}
2922024-09-26T19:44:22.148Z{"msg":"Transition from WaitQuorum to Active","v":0,"name":"crucible","level":30,"time":"2024-09-26T19:44:21.191145611Z","hostname":"w-01J8QXH7SYQS95RZY0ACANYM79","pid":1225,"client":"1","":"downstairs","session_id":"f8dba5d1-9777-4827-9cbb-a33f45e17ed4"}
2932024-09-26T19:44:22.151Z{"msg":"Transition from WaitQuorum to Active","v":0,"name":"crucible","level":30,"time":"2024-09-26T19:44:21.191183146Z","hostname":"w-01J8QXH7SYQS95RZY0ACANYM79","pid":1225,"client":"2","":"downstairs","session_id":"f8dba5d1-9777-4827-9cbb-a33f45e17ed4"}
2942024-09-26T19:44:22.151Z{"msg":"All required reconciliation work is completed","v":0,"name":"crucible","level":30,"time":"2024-09-26T19:44:21.191213491Z","hostname":"w-01J8QXH7SYQS95RZY0ACANYM79","pid":1225,"session_id":"f8dba5d1-9777-4827-9cbb-a33f45e17ed4"}
2952024-09-26T19:44:22.151Z{"msg":"Set Downstairs and Upstairs active after reconciliation","v":0,"name":"crucible","level":30,"time":"2024-09-26T19:44:21.191237447Z","hostname":"w-01J8QXH7SYQS95RZY0ACANYM79","pid":1225,"session_id":"f8dba5d1-9777-4827-9cbb-a33f45e17ed4"}
2962024-09-26T19:44:22.151Z{"msg":"da458d71-e833-429a-b0d7-5c6d6aafea5a is now active with session: f8dba5d1-9777-4827-9cbb-a33f45e17ed4","v":0,"name":"crucible","level":30,"time":"2024-09-26T19:44:21.191274341Z","hostname":"w-01J8QXH7SYQS95RZY0ACANYM79","pid":1225,"session_id":"f8dba5d1-9777-4827-9cbb-a33f45e17ed4"}
2972024-09-26T19:44:22.151Z{"msg":"Set Active after no reconciliation","v":0,"name":"crucible","level":30,"time":"2024-09-26T19:44:21.191291749Z","hostname":"w-01J8QXH7SYQS95RZY0ACANYM79","pid":1225,"session_id":"f8dba5d1-9777-4827-9cbb-a33f45e17ed4"}
2982024-09-26T19:44:22.151Z{"msg":"The guest has finished waiting for activation with:32"Region: es:10 ec:5 bs:4096 ts:204800 tb:50 max_io:50 or 204800
2992024-09-26T19:44:22.151Z,"v":0,"name":"crucible","level":30,"time":"2024-09-26T19:44:21.191327423Z","hostname":"w-01J8QXH7SYQS95RZY0ACANYM79","pid":1225}
3002024-09-26T19:44:22.151ZLoading write count information from file "/var/tmp/test_up-build/verify_file"
3012024-09-26T19:44:22.151ZRun Repair workload
3022024-09-26T19:44:22.151Z01/10 Flush
3032024-09-26T19:44:22.151Z02/10 Write block 41 len 8192 data: 2 2
3042024-09-26T19:44:22.151Z03/10 Read block 24 len 32768
3052024-09-26T19:44:22.159Z04/10 Read block 39 len 32768
3062024-09-26T19:44:22.170Z05/10 Write block 29 len 24576 data: 2 2 2 2 2 2
3072024-09-26T19:44:22.173Z06/10 Read block 3 len 4096
3082024-09-26T19:44:22.178Z07/10 Read block 12 len 24576
3092024-09-26T19:44:22.185Z08/10 Read block 8 len 36864
3102024-09-26T19:44:22.197Z09/10 Write block 24 len 32768 data: 2 2 2 2 2 3 3 3
3112024-09-26T19:44:22.200Z10/10 Read block 39 len 40960
3122024-09-26T19:44:22.213Z----------------------------------------------------------------
3132024-09-26T19:44:22.213Z Crucible gen:32 GIO:true work queues: Upstairs:0 downstairs:9
3142024-09-26T19:44:22.213ZStates: Active Active Active
3152024-09-26T19:44:22.213ZGW_ID ACK DSID TYPE BKS/EXT DS:0 DS:1 DS:2 REPLAY
3162024-09-26T19:44:22.213Z 2 Acked 1001 Write 2 Done Done Done false
3172024-09-26T19:44:22.213Z 3 Acked 1002 Read 8 Done Done Done false
3182024-09-26T19:44:22.213Z 4 Acked 1003 Read 8 Done Done Done false
3192024-09-26T19:44:22.213Z 5 Acked 1004 Write 6 Done Done Done false
3202024-09-26T19:44:22.213Z 6 Acked 1005 Read 1 Done Done Done false
3212024-09-26T19:44:22.213Z 7 Acked 1006 Read 6 Done Done Done false
3222024-09-26T19:44:22.213Z 8 Acked 1007 Read 9 Done Done Done false
3232024-09-26T19:44:22.213Z 9 Acked 1008 Write 8 Sent Done Done false
3242024-09-26T19:44:22.213Z 10 Acked 1009 Read 10 Sent Done Sent false
3252024-09-26T19:44:22.213Z STATES DS:0 DS:1 DS:2 TOTAL
3262024-09-26T19:44:22.213Z Sent 2 0 1 3
3272024-09-26T19:44:22.213Z Done 7 9 8 24
3282024-09-26T19:44:22.213Z Skipped 0 0 0 0
3292024-09-26T19:44:22.213Z Error 0 0 0 0
3302024-09-26T19:44:22.213ZLast Flush: 1000 1000 1000
3312024-09-26T19:44:22.216ZDownstairs last five completed: 1000
3322024-09-26T19:44:22.217ZUpstairs last five completed: 10 9 8 7 6
3332024-09-26T19:44:22.217Z{"msg":"Guest handle has been dropped","v":0,"name":"crucible","level":40,"time":"2024-09-26T19:44:21.257570591Z","hostname":"w-01J8QXH7SYQS95RZY0ACANYM79","pid":1225}
3342024-09-26T19:44:22.217ZWrote out file "/var/tmp/test_up-build/verify_file"
3352024-09-26T19:44:22.220ZRepair part 1 passed
3362024-09-26T19:44:22.222Z
3372024-09-26T19:44:22.222ZKill the current downstairs
3382024-09-26T19:44:22.335Zrm -rf /var/tmp/test_up-build/8830
3392024-09-26T19:44:22.335ZNow put back the original so we have a mismatch
3402024-09-26T19:44:22.335Zmv /var/tmp/test_up-build/previous /var/tmp/test_up-build/8830
3412024-09-26T19:44:22.340ZRestart downstairs with old directory
3422024-09-26T19:44:22.396Z/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
3432024-09-26T19:44:22.415ZEXT BLOCKS GEN0 GEN1 GEN2 FL0 FL1 FL2 D0 D1 D2 DIFF
3442024-09-26T19:44:22.417Z 0 000-009 31 31 31 1697 1697 1697 F F F
3452024-09-26T19:44:22.417Z 1 010-019 31 31 31 1697 1697 1697 F F F
3462024-09-26T19:44:22.417Z 2 020-029 31 31 31 1697 1697 1697 T T F <---
3472024-09-26T19:44:22.417Z 3 030-039 31 31 31 1697 1697 1697 T T F <---
3482024-09-26T19:44:22.417Z 4 040-049 31 31 31 1697 1697 1697 T T F <---
3492024-09-26T19:44:22.417ZMax gen: 31, Max flush: 1697
3502024-09-26T19:44:22.417ZError: Difference in extent metadata found!
3512024-09-26T19:44:22.420Zdump test found error as expected
3522024-09-26T19:44:22.420Z
3532024-09-26T19:44:22.420Z
3542024-09-26T19:44:22.420Z/var/tmp/bins/crutest verify --range -g 33 -q --key KeruT92rSzpt7C11x2JojzDpOaeMwkBp0YCWUYVSNTs= -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
3552024-09-26T19:44:22.435Z{"msg":"look at: http://127.0.0.1:12810 ","v":0,"name":"crucible","level":30,"time":"2024-09-26T19:44:21.479370541Z","hostname":"w-01J8QXH7SYQS95RZY0ACANYM79","pid":1232,"task":"crutest"}
3562024-09-26T19:44:22.479Z{"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-26T19:44:21.524253413Z","hostname":"w-01J8QXH7SYQS95RZY0ACANYM79","pid":1232,"task":"crutest"}
3572024-09-26T19:44:22.482Z{"msg":"Upstairs starts","v":0,"name":"crucible","level":30,"time":"2024-09-26T19:44:21.52491084Z","hostname":"w-01J8QXH7SYQS95RZY0ACANYM79","pid":1232}
3582024-09-26T19:44:22.483Z{"msg":"Crucible Version: BuildInfo {\n version: \"0.0.1\",\n git_sha: \"8e980c14034391699f5d7f17cfb24177d0aafaf2\",\n git_commit_timestamp: \"2024-09-26T19:23:10.000000000Z\",\n git_branch: \"alan/crutest-meet-dsc\",\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-26T19:44:21.524956883Z","hostname":"w-01J8QXH7SYQS95RZY0ACANYM79","pid":1232}
3592024-09-26T19:44:22.483Z{"msg":"Upstairs <-> Downstairs Message Version: 11","v":0,"name":"crucible","level":30,"time":"2024-09-26T19:44:21.524972171Z","hostname":"w-01J8QXH7SYQS95RZY0ACANYM79","pid":1232}
3602024-09-26T19:44:22.483Z{"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-26T19:44:21.524996867Z","hostname":"w-01J8QXH7SYQS95RZY0ACANYM79","pid":1232}
3612024-09-26T19:44:22.483Z{"msg":"Crucible 00c8b31c-f9c1-4fbb-b6b6-4115996ff28c has session id: d0e127a7-2e03-4989-be5c-cdca1830c60f","v":0,"name":"crucible","level":30,"time":"2024-09-26T19:44:21.525445377Z","hostname":"w-01J8QXH7SYQS95RZY0ACANYM79","pid":1232,"session_id":"d0e127a7-2e03-4989-be5c-cdca1830c60f"}
3622024-09-26T19:44:22.483Z{"msg":"Upstairs opts: Upstairs UUID: 00c8b31c-f9c1-4fbb-b6b6-4115996ff28c, 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-26T19:44:21.525494299Z","hostname":"w-01J8QXH7SYQS95RZY0ACANYM79","pid":1232,"session_id":"d0e127a7-2e03-4989-be5c-cdca1830c60f"}
3632024-09-26T19:44:22.483Z{"msg":"Crucible stats registered with UUID: 00c8b31c-f9c1-4fbb-b6b6-4115996ff28c","v":0,"name":"crucible","level":30,"time":"2024-09-26T19:44:21.525518965Z","hostname":"w-01J8QXH7SYQS95RZY0ACANYM79","pid":1232,"session_id":"d0e127a7-2e03-4989-be5c-cdca1830c60f"}
3642024-09-26T19:44:22.512Z{"msg":"The guest has requested activation with gen:33","v":0,"name":"crucible","level":30,"time":"2024-09-26T19:44:21.556636323Z","hostname":"w-01J8QXH7SYQS95RZY0ACANYM79","pid":1232}
3652024-09-26T19:44:22.512Z{"msg":"00c8b31c-f9c1-4fbb-b6b6-4115996ff28c active request set","v":0,"name":"crucible","level":30,"time":"2024-09-26T19:44:21.556679216Z","hostname":"w-01J8QXH7SYQS95RZY0ACANYM79","pid":1232,"session_id":"d0e127a7-2e03-4989-be5c-cdca1830c60f"}
3662024-09-26T19:44:22.515Z{"msg":"sending connect oneshot to client","v":0,"name":"crucible","level":30,"time":"2024-09-26T19:44:21.556697673Z","hostname":"w-01J8QXH7SYQS95RZY0ACANYM79","pid":1232,"client":"0","":"downstairs","session_id":"d0e127a7-2e03-4989-be5c-cdca1830c60f"}
3672024-09-26T19:44:22.515Z{"msg":"client set_active_request while in New; waiting...","v":0,"name":"crucible","level":30,"time":"2024-09-26T19:44:21.556756864Z","hostname":"w-01J8QXH7SYQS95RZY0ACANYM79","pid":1232,"client":"0","":"downstairs","session_id":"d0e127a7-2e03-4989-be5c-cdca1830c60f"}
3682024-09-26T19:44:22.515Z{"msg":"sending connect oneshot to client","v":0,"name":"crucible","level":30,"time":"2024-09-26T19:44:21.556811945Z","hostname":"w-01J8QXH7SYQS95RZY0ACANYM79","pid":1232,"client":"1","":"downstairs","session_id":"d0e127a7-2e03-4989-be5c-cdca1830c60f"}
3692024-09-26T19:44:22.515Z{"msg":"client set_active_request while in New; waiting...","v":0,"name":"crucible","level":30,"time":"2024-09-26T19:44:21.556851089Z","hostname":"w-01J8QXH7SYQS95RZY0ACANYM79","pid":1232,"client":"1","":"downstairs","session_id":"d0e127a7-2e03-4989-be5c-cdca1830c60f"}
3702024-09-26T19:44:22.515Z{"msg":"sending connect oneshot to client","v":0,"name":"crucible","level":30,"time":"2024-09-26T19:44:21.556896302Z","hostname":"w-01J8QXH7SYQS95RZY0ACANYM79","pid":1232,"client":"2","":"downstairs","session_id":"d0e127a7-2e03-4989-be5c-cdca1830c60f"}
3712024-09-26T19:44:22.515Z{"msg":"client set_active_request while in New; waiting...","v":0,"name":"crucible","level":30,"time":"2024-09-26T19:44:21.556982579Z","hostname":"w-01J8QXH7SYQS95RZY0ACANYM79","pid":1232,"client":"2","":"downstairs","session_id":"d0e127a7-2e03-4989-be5c-cdca1830c60f"}
3722024-09-26T19:44:22.515Z{"msg":"connecting to 127.0.0.1:8830","v":0,"name":"crucible","level":30,"time":"2024-09-26T19:44:21.557044899Z","hostname":"w-01J8QXH7SYQS95RZY0ACANYM79","pid":1232,"":"io task","client":"2","":"downstairs","session_id":"d0e127a7-2e03-4989-be5c-cdca1830c60f"}
3732024-09-26T19:44:22.515Z{"msg":"connecting to 127.0.0.1:8810","v":0,"name":"crucible","level":30,"time":"2024-09-26T19:44:21.557088742Z","hostname":"w-01J8QXH7SYQS95RZY0ACANYM79","pid":1232,"":"io task","client":"0","":"downstairs","session_id":"d0e127a7-2e03-4989-be5c-cdca1830c60f"}
3742024-09-26T19:44:22.515Z{"msg":"connecting to 127.0.0.1:8820","v":0,"name":"crucible","level":30,"time":"2024-09-26T19:44:21.5571687Z","hostname":"w-01J8QXH7SYQS95RZY0ACANYM79","pid":1232,"":"io task","client":"1","":"downstairs","session_id":"d0e127a7-2e03-4989-be5c-cdca1830c60f"}
3752024-09-26T19:44:22.515Z{"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-26T19:44:21.557201244Z","hostname":"w-01J8QXH7SYQS95RZY0ACANYM79","pid":1232,"":"io task","client":"2","":"downstairs","session_id":"d0e127a7-2e03-4989-be5c-cdca1830c60f"}
3762024-09-26T19:44:22.515Z{"msg":"client task is sending Done(ConnectionFailed(Os { code: 146, kind: ConnectionRefused, message: \"Connection refused\" }))","v":0,"name":"crucible","level":40,"time":"2024-09-26T19:44:21.557235879Z","hostname":"w-01J8QXH7SYQS95RZY0ACANYM79","pid":1232,"":"io task","client":"2","":"downstairs","session_id":"d0e127a7-2e03-4989-be5c-cdca1830c60f"}
3772024-09-26T19:44:22.515Z{"msg":"ds_connection connected from Ok(127.0.0.1:63465)","v":0,"name":"crucible","level":30,"time":"2024-09-26T19:44:21.557252236Z","hostname":"w-01J8QXH7SYQS95RZY0ACANYM79","pid":1232,"":"io task","client":"1","":"downstairs","session_id":"d0e127a7-2e03-4989-be5c-cdca1830c60f"}
3782024-09-26T19:44:22.515Z{"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-26T19:44:21.557271653Z","hostname":"w-01J8QXH7SYQS95RZY0ACANYM79","pid":1232,"session_id":"d0e127a7-2e03-4989-be5c-cdca1830c60f"}
3792024-09-26T19:44:22.515Z{"msg":"ds_connection connected from Ok(127.0.0.1:62776)","v":0,"name":"crucible","level":30,"time":"2024-09-26T19:44:21.557303208Z","hostname":"w-01J8QXH7SYQS95RZY0ACANYM79","pid":1232,"":"io task","client":"0","":"downstairs","session_id":"d0e127a7-2e03-4989-be5c-cdca1830c60f"}
3802024-09-26T19:44:22.516Z{"msg":"Gone missing, transition from New to Disconnected","v":0,"name":"crucible","level":30,"time":"2024-09-26T19:44:21.557333534Z","hostname":"w-01J8QXH7SYQS95RZY0ACANYM79","pid":1232,"client":"2","":"downstairs","session_id":"d0e127a7-2e03-4989-be5c-cdca1830c60f"}
3812024-09-26T19:44:22.516Z{"msg":"Disconnected -> New","v":0,"name":"crucible","level":30,"time":"2024-09-26T19:44:21.55735356Z","hostname":"w-01J8QXH7SYQS95RZY0ACANYM79","pid":1232,"client":"2","":"downstairs","session_id":"d0e127a7-2e03-4989-be5c-cdca1830c60f"}
3822024-09-26T19:44:22.516Z{"msg":"client task is exiting","v":0,"name":"crucible","level":30,"time":"2024-09-26T19:44:21.557386845Z","hostname":"w-01J8QXH7SYQS95RZY0ACANYM79","pid":1232,"":"io task","client":"2","":"downstairs","session_id":"d0e127a7-2e03-4989-be5c-cdca1830c60f"}
3832024-09-26T19:44:22.516Z{"msg":"ds_transition from New to WaitActive","v":0,"name":"crucible","level":30,"time":"2024-09-26T19:44:21.557822727Z","hostname":"w-01J8QXH7SYQS95RZY0ACANYM79","pid":1232,"client":"0","":"downstairs","session_id":"d0e127a7-2e03-4989-be5c-cdca1830c60f"}
3842024-09-26T19:44:22.516Z{"msg":"[0] Transition from New to WaitActive","v":0,"name":"crucible","level":30,"time":"2024-09-26T19:44:21.557863201Z","hostname":"w-01J8QXH7SYQS95RZY0ACANYM79","pid":1232,"client":"0","":"downstairs","session_id":"d0e127a7-2e03-4989-be5c-cdca1830c60f"}
3852024-09-26T19:44:22.516Z{"msg":"ds_transition from New to WaitActive","v":0,"name":"crucible","level":30,"time":"2024-09-26T19:44:21.557890307Z","hostname":"w-01J8QXH7SYQS95RZY0ACANYM79","pid":1232,"client":"1","":"downstairs","session_id":"d0e127a7-2e03-4989-be5c-cdca1830c60f"}
3862024-09-26T19:44:22.516Z{"msg":"[1] Transition from New to WaitActive","v":0,"name":"crucible","level":30,"time":"2024-09-26T19:44:21.557913293Z","hostname":"w-01J8QXH7SYQS95RZY0ACANYM79","pid":1232,"client":"1","":"downstairs","session_id":"d0e127a7-2e03-4989-be5c-cdca1830c60f"}
3872024-09-26T19:44:22.516Z{"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-26T19:44:21.558489673Z","hostname":"w-01J8QXH7SYQS95RZY0ACANYM79","pid":1232,"client":"1","":"downstairs","session_id":"d0e127a7-2e03-4989-be5c-cdca1830c60f"}
3882024-09-26T19:44:22.516Z{"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-26T19:44:21.558538285Z","hostname":"w-01J8QXH7SYQS95RZY0ACANYM79","pid":1232,"client":"0","":"downstairs","session_id":"d0e127a7-2e03-4989-be5c-cdca1830c60f"}
3892024-09-26T19:44:22.516Z{"msg":"ds_transition from WaitActive to WaitQuorum","v":0,"name":"crucible","level":30,"time":"2024-09-26T19:44:21.558967028Z","hostname":"w-01J8QXH7SYQS95RZY0ACANYM79","pid":1232,"client":"0","":"downstairs","session_id":"d0e127a7-2e03-4989-be5c-cdca1830c60f"}
3902024-09-26T19:44:22.516Z{"msg":"[0] Transition from WaitActive to WaitQuorum","v":0,"name":"crucible","level":30,"time":"2024-09-26T19:44:21.559007222Z","hostname":"w-01J8QXH7SYQS95RZY0ACANYM79","pid":1232,"client":"0","":"downstairs","session_id":"d0e127a7-2e03-4989-be5c-cdca1830c60f"}
3912024-09-26T19:44:22.516Z{"msg":"Waiting for more clients to be ready","v":0,"name":"crucible","level":30,"time":"2024-09-26T19:44:21.559034267Z","hostname":"w-01J8QXH7SYQS95RZY0ACANYM79","pid":1232,"session_id":"d0e127a7-2e03-4989-be5c-cdca1830c60f"}
3922024-09-26T19:44:22.516Z{"msg":"ds_transition from WaitActive to WaitQuorum","v":0,"name":"crucible","level":30,"time":"2024-09-26T19:44:21.559058684Z","hostname":"w-01J8QXH7SYQS95RZY0ACANYM79","pid":1232,"client":"1","":"downstairs","session_id":"d0e127a7-2e03-4989-be5c-cdca1830c60f"}
3932024-09-26T19:44:22.516Z{"msg":"[1] Transition from WaitActive to WaitQuorum","v":0,"name":"crucible","level":30,"time":"2024-09-26T19:44:21.559073721Z","hostname":"w-01J8QXH7SYQS95RZY0ACANYM79","pid":1232,"client":"1","":"downstairs","session_id":"d0e127a7-2e03-4989-be5c-cdca1830c60f"}
3942024-09-26T19:44:22.516Z{"msg":"Waiting for more clients to be ready","v":0,"name":"crucible","level":30,"time":"2024-09-26T19:44:21.559095528Z","hostname":"w-01J8QXH7SYQS95RZY0ACANYM79","pid":1232,"session_id":"d0e127a7-2e03-4989-be5c-cdca1830c60f"}
3952024-09-26T19:44:32.515Z{"msg":"connecting to 127.0.0.1:8830","v":0,"name":"crucible","level":30,"time":"2024-09-26T19:44:31.55828506Z","hostname":"w-01J8QXH7SYQS95RZY0ACANYM79","pid":1232,"":"io task","client":"2","":"downstairs","session_id":"d0e127a7-2e03-4989-be5c-cdca1830c60f"}
3962024-09-26T19:44:32.519Z{"msg":"ds_connection connected from Ok(127.0.0.1:44058)","v":0,"name":"crucible","level":30,"time":"2024-09-26T19:44:31.558420159Z","hostname":"w-01J8QXH7SYQS95RZY0ACANYM79","pid":1232,"":"io task","client":"2","":"downstairs","session_id":"d0e127a7-2e03-4989-be5c-cdca1830c60f"}
3972024-09-26T19:44:32.519Z{"msg":"ds_transition from New to WaitActive","v":0,"name":"crucible","level":30,"time":"2024-09-26T19:44:31.559525446Z","hostname":"w-01J8QXH7SYQS95RZY0ACANYM79","pid":1232,"client":"2","":"downstairs","session_id":"d0e127a7-2e03-4989-be5c-cdca1830c60f"}
3982024-09-26T19:44:32.519Z{"msg":"[2] Transition from New to WaitActive","v":0,"name":"crucible","level":30,"time":"2024-09-26T19:44:31.559580907Z","hostname":"w-01J8QXH7SYQS95RZY0ACANYM79","pid":1232,"client":"2","":"downstairs","session_id":"d0e127a7-2e03-4989-be5c-cdca1830c60f"}
3992024-09-26T19:44:32.519Z{"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-26T19:44:31.560102505Z","hostname":"w-01J8QXH7SYQS95RZY0ACANYM79","pid":1232,"client":"2","":"downstairs","session_id":"d0e127a7-2e03-4989-be5c-cdca1830c60f"}
4002024-09-26T19:44:32.519Z{"msg":"ds_transition from WaitActive to WaitQuorum","v":0,"name":"crucible","level":30,"time":"2024-09-26T19:44:31.560464069Z","hostname":"w-01J8QXH7SYQS95RZY0ACANYM79","pid":1232,"client":"2","":"downstairs","session_id":"d0e127a7-2e03-4989-be5c-cdca1830c60f"}
4012024-09-26T19:44:32.519Z{"msg":"[2] Transition from WaitActive to WaitQuorum","v":0,"name":"crucible","level":30,"time":"2024-09-26T19:44:31.560504622Z","hostname":"w-01J8QXH7SYQS95RZY0ACANYM79","pid":1232,"client":"2","":"downstairs","session_id":"d0e127a7-2e03-4989-be5c-cdca1830c60f"}
4022024-09-26T19:44:32.519Z{"msg":"[0]R flush_numbers: [1697, 1697, 1697, 1697, 1697]","v":0,"name":"crucible","level":30,"time":"2024-09-26T19:44:31.560525039Z","hostname":"w-01J8QXH7SYQS95RZY0ACANYM79","pid":1232,"":"downstairs","":"downstairs","session_id":"d0e127a7-2e03-4989-be5c-cdca1830c60f"}
4032024-09-26T19:44:32.519Z{"msg":"[0]R generation: [31, 31, 31, 31, 31]","v":0,"name":"crucible","level":30,"time":"2024-09-26T19:44:31.560559564Z","hostname":"w-01J8QXH7SYQS95RZY0ACANYM79","pid":1232,"":"downstairs","":"downstairs","session_id":"d0e127a7-2e03-4989-be5c-cdca1830c60f"}
4042024-09-26T19:44:32.519Z{"msg":"[0]R dirty: [false, false, true, true, true]","v":0,"name":"crucible","level":30,"time":"2024-09-26T19:44:31.560578581Z","hostname":"w-01J8QXH7SYQS95RZY0ACANYM79","pid":1232,"":"downstairs","":"downstairs","session_id":"d0e127a7-2e03-4989-be5c-cdca1830c60f"}
4052024-09-26T19:44:32.519Z{"msg":"[1]R flush_numbers: [1697, 1697, 1697, 1697, 1697]","v":0,"name":"crucible","level":30,"time":"2024-09-26T19:44:31.560604927Z","hostname":"w-01J8QXH7SYQS95RZY0ACANYM79","pid":1232,"":"downstairs","":"downstairs","session_id":"d0e127a7-2e03-4989-be5c-cdca1830c60f"}
4062024-09-26T19:44:32.519Z{"msg":"[1]R generation: [31, 31, 31, 31, 31]","v":0,"name":"crucible","level":30,"time":"2024-09-26T19:44:31.560622144Z","hostname":"w-01J8QXH7SYQS95RZY0ACANYM79","pid":1232,"":"downstairs","":"downstairs","session_id":"d0e127a7-2e03-4989-be5c-cdca1830c60f"}
4072024-09-26T19:44:32.519Z{"msg":"[1]R dirty: [false, false, true, true, true]","v":0,"name":"crucible","level":30,"time":"2024-09-26T19:44:31.56064729Z","hostname":"w-01J8QXH7SYQS95RZY0ACANYM79","pid":1232,"":"downstairs","":"downstairs","session_id":"d0e127a7-2e03-4989-be5c-cdca1830c60f"}
4082024-09-26T19:44:32.519Z{"msg":"[2]R flush_numbers: [1697, 1697, 1697, 1697, 1697]","v":0,"name":"crucible","level":30,"time":"2024-09-26T19:44:31.560665397Z","hostname":"w-01J8QXH7SYQS95RZY0ACANYM79","pid":1232,"":"downstairs","":"downstairs","session_id":"d0e127a7-2e03-4989-be5c-cdca1830c60f"}
4092024-09-26T19:44:32.519Z{"msg":"[2]R generation: [31, 31, 31, 31, 31]","v":0,"name":"crucible","level":30,"time":"2024-09-26T19:44:31.560690173Z","hostname":"w-01J8QXH7SYQS95RZY0ACANYM79","pid":1232,"":"downstairs","":"downstairs","session_id":"d0e127a7-2e03-4989-be5c-cdca1830c60f"}
4102024-09-26T19:44:32.519Z{"msg":"[2]R dirty: [false, false, false, false, false]","v":0,"name":"crucible","level":30,"time":"2024-09-26T19:44:31.560707041Z","hostname":"w-01J8QXH7SYQS95RZY0ACANYM79","pid":1232,"":"downstairs","":"downstairs","session_id":"d0e127a7-2e03-4989-be5c-cdca1830c60f"}
4112024-09-26T19:44:32.519Z{"msg":"Max found gen is 32","v":0,"name":"crucible","level":30,"time":"2024-09-26T19:44:31.560731657Z","hostname":"w-01J8QXH7SYQS95RZY0ACANYM79","pid":1232,"":"downstairs","":"downstairs","session_id":"d0e127a7-2e03-4989-be5c-cdca1830c60f"}
4122024-09-26T19:44:32.519Z{"msg":"Generation requested: 33 >= found:32","v":0,"name":"crucible","level":30,"time":"2024-09-26T19:44:31.560748374Z","hostname":"w-01J8QXH7SYQS95RZY0ACANYM79","pid":1232,"":"downstairs","":"downstairs","session_id":"d0e127a7-2e03-4989-be5c-cdca1830c60f"}
4132024-09-26T19:44:32.519Z{"msg":"Next flush: 1698","v":0,"name":"crucible","level":30,"time":"2024-09-26T19:44:31.56077296Z","hostname":"w-01J8QXH7SYQS95RZY0ACANYM79","pid":1232,"":"downstairs","":"downstairs","session_id":"d0e127a7-2e03-4989-be5c-cdca1830c60f"}
4142024-09-26T19:44:32.519Z{"msg":"Extents 2 dirty","v":0,"name":"crucible","level":30,"time":"2024-09-26T19:44:31.560789368Z","hostname":"w-01J8QXH7SYQS95RZY0ACANYM79","pid":1232,"":"mend","":"downstairs","":"downstairs","session_id":"d0e127a7-2e03-4989-be5c-cdca1830c60f"}
4152024-09-26T19:44:32.519Z{"msg":"First source client ID for extent 2","v":0,"name":"crucible","level":30,"time":"2024-09-26T19:44:31.560814824Z","hostname":"w-01J8QXH7SYQS95RZY0ACANYM79","pid":1232,"mrl":"dirty","":"mend","":"downstairs","":"downstairs","session_id":"d0e127a7-2e03-4989-be5c-cdca1830c60f"}
4162024-09-26T19:44:32.519Z{"msg":"extent:2 gens: 31 31 31","v":0,"name":"crucible","level":30,"time":"2024-09-26T19:44:31.560833491Z","hostname":"w-01J8QXH7SYQS95RZY0ACANYM79","pid":1232,"mrl":"dirty","":"mend","":"downstairs","":"downstairs","session_id":"d0e127a7-2e03-4989-be5c-cdca1830c60f"}
4172024-09-26T19:44:32.519Z{"msg":"extent:2 flush: 1697 1697 1697 scs: [ClientId(0), ClientId(1), ClientId(2)]","v":0,"name":"crucible","level":30,"time":"2024-09-26T19:44:31.560851928Z","hostname":"w-01J8QXH7SYQS95RZY0ACANYM79","pid":1232,"mrl":"dirty","":"mend","":"downstairs","":"downstairs","session_id":"d0e127a7-2e03-4989-be5c-cdca1830c60f"}
4182024-09-26T19:44:32.519Z{"msg":"max_flush now has: [ClientId(0), ClientId(1), ClientId(2)]","v":0,"name":"crucible","level":30,"time":"2024-09-26T19:44:31.560878574Z","hostname":"w-01J8QXH7SYQS95RZY0ACANYM79","pid":1232,"mrl":"dirty","":"mend","":"downstairs","":"downstairs","session_id":"d0e127a7-2e03-4989-be5c-cdca1830c60f"}
4192024-09-26T19:44:32.519Z{"msg":"extent:2 dirty: true true false","v":0,"name":"crucible","level":30,"time":"2024-09-26T19:44:31.560897411Z","hostname":"w-01J8QXH7SYQS95RZY0ACANYM79","pid":1232,"mrl":"dirty","":"mend","":"downstairs","":"downstairs","session_id":"d0e127a7-2e03-4989-be5c-cdca1830c60f"}
4202024-09-26T19:44:32.519Z{"msg":"find dest for source 0 for extent at index 2","v":0,"name":"crucible","level":30,"time":"2024-09-26T19:44:31.560915908Z","hostname":"w-01J8QXH7SYQS95RZY0ACANYM79","pid":1232,"mrl":"dirty","":"mend","":"downstairs","":"downstairs","session_id":"d0e127a7-2e03-4989-be5c-cdca1830c60f"}
4212024-09-26T19:44:32.519Z{"msg":"source 0, add dest 1 source flush","v":0,"name":"crucible","level":30,"time":"2024-09-26T19:44:31.560954642Z","hostname":"w-01J8QXH7SYQS95RZY0ACANYM79","pid":1232,"mrl":"dirty","":"mend","":"downstairs","":"downstairs","session_id":"d0e127a7-2e03-4989-be5c-cdca1830c60f"}
4222024-09-26T19:44:32.519Z{"msg":"source 0, add dest 2 source flush","v":0,"name":"crucible","level":30,"time":"2024-09-26T19:44:31.560975359Z","hostname":"w-01J8QXH7SYQS95RZY0ACANYM79","pid":1232,"mrl":"dirty","":"mend","":"downstairs","":"downstairs","session_id":"d0e127a7-2e03-4989-be5c-cdca1830c60f"}
4232024-09-26T19:44:32.519Z{"msg":"Extents 3 dirty","v":0,"name":"crucible","level":30,"time":"2024-09-26T19:44:31.56103297Z","hostname":"w-01J8QXH7SYQS95RZY0ACANYM79","pid":1232,"":"mend","":"downstairs","":"downstairs","session_id":"d0e127a7-2e03-4989-be5c-cdca1830c60f"}
4242024-09-26T19:44:32.519Z{"msg":"First source client ID for extent 3","v":0,"name":"crucible","level":30,"time":"2024-09-26T19:44:31.561065615Z","hostname":"w-01J8QXH7SYQS95RZY0ACANYM79","pid":1232,"mrl":"dirty","":"mend","":"downstairs","":"downstairs","session_id":"d0e127a7-2e03-4989-be5c-cdca1830c60f"}
4252024-09-26T19:44:32.520Z{"msg":"extent:3 gens: 31 31 31","v":0,"name":"crucible","level":30,"time":"2024-09-26T19:44:31.561084832Z","hostname":"w-01J8QXH7SYQS95RZY0ACANYM79","pid":1232,"mrl":"dirty","":"mend","":"downstairs","":"downstairs","session_id":"d0e127a7-2e03-4989-be5c-cdca1830c60f"}
4262024-09-26T19:44:32.520Z{"msg":"extent:3 flush: 1697 1697 1697 scs: [ClientId(0), ClientId(1), ClientId(2)]","v":0,"name":"crucible","level":30,"time":"2024-09-26T19:44:31.561113557Z","hostname":"w-01J8QXH7SYQS95RZY0ACANYM79","pid":1232,"mrl":"dirty","":"mend","":"downstairs","":"downstairs","session_id":"d0e127a7-2e03-4989-be5c-cdca1830c60f"}
4272024-09-26T19:44:32.520Z{"msg":"max_flush now has: [ClientId(0), ClientId(1), ClientId(2)]","v":0,"name":"crucible","level":30,"time":"2024-09-26T19:44:31.561132524Z","hostname":"w-01J8QXH7SYQS95RZY0ACANYM79","pid":1232,"mrl":"dirty","":"mend","":"downstairs","":"downstairs","session_id":"d0e127a7-2e03-4989-be5c-cdca1830c60f"}
4282024-09-26T19:44:32.520Z{"msg":"extent:3 dirty: true true false","v":0,"name":"crucible","level":30,"time":"2024-09-26T19:44:31.561154521Z","hostname":"w-01J8QXH7SYQS95RZY0ACANYM79","pid":1232,"mrl":"dirty","":"mend","":"downstairs","":"downstairs","session_id":"d0e127a7-2e03-4989-be5c-cdca1830c60f"}
4292024-09-26T19:44:32.525Z{"msg":"find dest for source 0 for extent at index 3","v":0,"name":"crucible","level":30,"time":"2024-09-26T19:44:31.561169538Z","hostname":"w-01J8QXH7SYQS95RZY0ACANYM79","pid":1232,"mrl":"dirty","":"mend","":"downstairs","":"downstairs","session_id":"d0e127a7-2e03-4989-be5c-cdca1830c60f"}
4302024-09-26T19:44:32.525Z{"msg":"source 0, add dest 1 source flush","v":0,"name":"crucible","level":30,"time":"2024-09-26T19:44:31.561190655Z","hostname":"w-01J8QXH7SYQS95RZY0ACANYM79","pid":1232,"mrl":"dirty","":"mend","":"downstairs","":"downstairs","session_id":"d0e127a7-2e03-4989-be5c-cdca1830c60f"}
4312024-09-26T19:44:32.525Z{"msg":"source 0, add dest 2 source flush","v":0,"name":"crucible","level":30,"time":"2024-09-26T19:44:31.561205743Z","hostname":"w-01J8QXH7SYQS95RZY0ACANYM79","pid":1232,"mrl":"dirty","":"mend","":"downstairs","":"downstairs","session_id":"d0e127a7-2e03-4989-be5c-cdca1830c60f"}
4322024-09-26T19:44:32.525Z{"msg":"Extents 4 dirty","v":0,"name":"crucible","level":30,"time":"2024-09-26T19:44:31.561228019Z","hostname":"w-01J8QXH7SYQS95RZY0ACANYM79","pid":1232,"":"mend","":"downstairs","":"downstairs","session_id":"d0e127a7-2e03-4989-be5c-cdca1830c60f"}
4332024-09-26T19:44:32.525Z{"msg":"First source client ID for extent 4","v":0,"name":"crucible","level":30,"time":"2024-09-26T19:44:31.561258584Z","hostname":"w-01J8QXH7SYQS95RZY0ACANYM79","pid":1232,"mrl":"dirty","":"mend","":"downstairs","":"downstairs","session_id":"d0e127a7-2e03-4989-be5c-cdca1830c60f"}
4342024-09-26T19:44:32.525Z{"msg":"extent:4 gens: 31 31 31","v":0,"name":"crucible","level":30,"time":"2024-09-26T19:44:31.561274532Z","hostname":"w-01J8QXH7SYQS95RZY0ACANYM79","pid":1232,"mrl":"dirty","":"mend","":"downstairs","":"downstairs","session_id":"d0e127a7-2e03-4989-be5c-cdca1830c60f"}
4352024-09-26T19:44:32.525Z{"msg":"extent:4 flush: 1697 1697 1697 scs: [ClientId(0), ClientId(1), ClientId(2)]","v":0,"name":"crucible","level":30,"time":"2024-09-26T19:44:31.561322174Z","hostname":"w-01J8QXH7SYQS95RZY0ACANYM79","pid":1232,"mrl":"dirty","":"mend","":"downstairs","":"downstairs","session_id":"d0e127a7-2e03-4989-be5c-cdca1830c60f"}
4362024-09-26T19:44:32.525Z{"msg":"max_flush now has: [ClientId(0), ClientId(1), ClientId(2)]","v":0,"name":"crucible","level":30,"time":"2024-09-26T19:44:31.56135068Z","hostname":"w-01J8QXH7SYQS95RZY0ACANYM79","pid":1232,"mrl":"dirty","":"mend","":"downstairs","":"downstairs","session_id":"d0e127a7-2e03-4989-be5c-cdca1830c60f"}
4372024-09-26T19:44:32.525Z{"msg":"extent:4 dirty: true true false","v":0,"name":"crucible","level":30,"time":"2024-09-26T19:44:31.561366068Z","hostname":"w-01J8QXH7SYQS95RZY0ACANYM79","pid":1232,"mrl":"dirty","":"mend","":"downstairs","":"downstairs","session_id":"d0e127a7-2e03-4989-be5c-cdca1830c60f"}
4382024-09-26T19:44:32.525Z{"msg":"find dest for source 0 for extent at index 4","v":0,"name":"crucible","level":30,"time":"2024-09-26T19:44:31.561387844Z","hostname":"w-01J8QXH7SYQS95RZY0ACANYM79","pid":1232,"mrl":"dirty","":"mend","":"downstairs","":"downstairs","session_id":"d0e127a7-2e03-4989-be5c-cdca1830c60f"}
4392024-09-26T19:44:32.525Z{"msg":"source 0, add dest 1 source flush","v":0,"name":"crucible","level":30,"time":"2024-09-26T19:44:31.561402532Z","hostname":"w-01J8QXH7SYQS95RZY0ACANYM79","pid":1232,"mrl":"dirty","":"mend","":"downstairs","":"downstairs","session_id":"d0e127a7-2e03-4989-be5c-cdca1830c60f"}
4402024-09-26T19:44:32.525Z{"msg":"source 0, add dest 2 source flush","v":0,"name":"crucible","level":30,"time":"2024-09-26T19:44:31.561423519Z","hostname":"w-01J8QXH7SYQS95RZY0ACANYM79","pid":1232,"mrl":"dirty","":"mend","":"downstairs","":"downstairs","session_id":"d0e127a7-2e03-4989-be5c-cdca1830c60f"}
4412024-09-26T19:44:32.526Z{"msg":"Transition from WaitQuorum to Reconcile","v":0,"name":"crucible","level":30,"time":"2024-09-26T19:44:31.561438526Z","hostname":"w-01J8QXH7SYQS95RZY0ACANYM79","pid":1232,"client":"0","":"downstairs","session_id":"d0e127a7-2e03-4989-be5c-cdca1830c60f"}
4422024-09-26T19:44:32.526Z{"msg":"Transition from WaitQuorum to Reconcile","v":0,"name":"crucible","level":30,"time":"2024-09-26T19:44:31.561458853Z","hostname":"w-01J8QXH7SYQS95RZY0ACANYM79","pid":1232,"client":"1","":"downstairs","session_id":"d0e127a7-2e03-4989-be5c-cdca1830c60f"}
4432024-09-26T19:44:32.526Z{"msg":"Transition from WaitQuorum to Reconcile","v":0,"name":"crucible","level":30,"time":"2024-09-26T19:44:31.561472481Z","hostname":"w-01J8QXH7SYQS95RZY0ACANYM79","pid":1232,"client":"2","":"downstairs","session_id":"d0e127a7-2e03-4989-be5c-cdca1830c60f"}
4442024-09-26T19:44:32.526Z{"msg":"starting reconciliation 2b4c4a0d-da35-4a9a-a6eb-db75a4112fa5: found 3 extents that need repair","v":0,"name":"crucible","level":30,"time":"2024-09-26T19:44:31.561493528Z","hostname":"w-01J8QXH7SYQS95RZY0ACANYM79","pid":1232,"":"downstairs","":"downstairs","session_id":"d0e127a7-2e03-4989-be5c-cdca1830c60f"}
4452024-09-26T19:44:32.526Z{"msg":"Full repair list: {ExtentId(2): ExtentFix { source: ClientId(0), dest: [ClientId(1), ClientId(2)] }, ExtentId(3): ExtentFix { source: ClientId(0), dest: [ClientId(1), ClientId(2)] }, ExtentId(4): ExtentFix { source: ClientId(0), dest: [ClientId(1), ClientId(2)] }}","v":0,"name":"crucible","level":30,"time":"2024-09-26T19:44:31.561509805Z","hostname":"w-01J8QXH7SYQS95RZY0ACANYM79","pid":1232,"":"downstairs","":"downstairs","session_id":"d0e127a7-2e03-4989-be5c-cdca1830c60f"}
4462024-09-26T19:44:32.526Z{"msg":"Task list: [ReconcileIO { id: ReconciliationId(0), op: ExtentFlush { repair_id: ReconciliationId(0), extent_id: ExtentId(2), client_id: ClientId(0), flush_number: 1698, gen_number: 32 }, state: ClientData([New, New, New]) }, ReconcileIO { id: ReconciliationId(1), op: ExtentClose { repair_id: ReconciliationId(1), extent_id: ExtentId(2) }, state: ClientData([New, New, New]) }, ReconcileIO { id: ReconciliationId(2), op: ExtentRepair { repair_id: ReconciliationId(2), 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(3), op: ExtentReopen { repair_id: ReconciliationId(3), extent_id: ExtentId(2) }, state: ClientData([New, New, New]) }, ReconcileIO { id: ReconciliationId(4), op: ExtentFlush { repair_id: ReconciliationId(4), extent_id: ExtentId(3), client_id: ClientId(0), flush_number: 1698, gen_number: 32 }, state: ClientData([New, New, New]) }, ReconcileIO { id: ReconciliationId(5), op: ExtentClose { repair_id: ReconciliationId(5), extent_id: ExtentId(3) }, state: ClientData([New, New, New]) }, ReconcileIO { id: ReconciliationId(6), op: ExtentRepair { repair_id: ReconciliationId(6), extent_id: ExtentId(3), source_client_id: ClientId(0), source_repair_address: 0.0.0.0:12810, dest_clients: [ClientId(1), ClientId(2)] }, state: ClientData([New, New, New]) }, ReconcileIO { id: ReconciliationId(7), op: ExtentReopen { repair_id: ReconciliationId(7), extent_id: ExtentId(3) }, state: ClientData([New, New, New]) }, ReconcileIO { id: ReconciliationId(8), op: ExtentFlush { repair_id: ReconciliationId(8), extent_id: ExtentId(4), client_id: ClientId(0), flush_number: 1698, gen_number: 32 }, state: ClientData([New, New, New]) }, ReconcileIO { id: ReconciliationId(9), op: ExtentClose { repair_id: ReconciliationId(9), extent_id: ExtentId(4) }, state: ClientData([New, New, New]) }, ReconcileIO { id: ReconciliationId(10), op: ExtentRepair { repair_id: ReconciliationId(10), 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(11), op: ExtentReopen { repair_id: ReconciliationId(11), extent_id: ExtentId(4) }, state: ClientData([New, New, New]) }]","v":0,"name":"crucible","level":30,"time":"2024-09-26T19:44:31.561579944Z","hostname":"w-01J8QXH7SYQS95RZY0ACANYM79","pid":1232,"":"downstairs","":"downstairs","session_id":"d0e127a7-2e03-4989-be5c-cdca1830c60f"}
4472024-09-26T19:44:32.526Z{"msg":"no Nexus client from DNS, aborting start notification","v":0,"name":"crucible","level":50,"time":"2024-09-26T19:44:31.56160506Z","hostname":"w-01J8QXH7SYQS95RZY0ACANYM79","pid":1232,"reconcile":"2b4c4a0d-da35-4a9a-a6eb-db75a4112fa5","":"downstairs","":"downstairs","session_id":"d0e127a7-2e03-4989-be5c-cdca1830c60f"}
4482024-09-26T19:44:32.526Z{"msg":"no Nexus client from DNS, aborting progress notification","v":0,"name":"crucible","level":50,"time":"2024-09-26T19:44:31.561621208Z","hostname":"w-01J8QXH7SYQS95RZY0ACANYM79","pid":1232,"reconcile":"2b4c4a0d-da35-4a9a-a6eb-db75a4112fa5","":"downstairs","":"downstairs","session_id":"d0e127a7-2e03-4989-be5c-cdca1830c60f"}
4492024-09-26T19:44:32.526Z{"msg":"no Nexus client from DNS, aborting progress notification","v":0,"name":"crucible","level":50,"time":"2024-09-26T19:44:31.562517107Z","hostname":"w-01J8QXH7SYQS95RZY0ACANYM79","pid":1232,"reconcile":"2b4c4a0d-da35-4a9a-a6eb-db75a4112fa5","":"downstairs","":"downstairs","session_id":"d0e127a7-2e03-4989-be5c-cdca1830c60f"}
4502024-09-26T19:44:32.526Z{"msg":"sending reconcile request ReconciliationId(2)","v":0,"name":"crucible","level":30,"time":"2024-09-26T19:44:31.562774787Z","hostname":"w-01J8QXH7SYQS95RZY0ACANYM79","pid":1232,"client":"1","":"downstairs","session_id":"d0e127a7-2e03-4989-be5c-cdca1830c60f"}
4512024-09-26T19:44:32.526Z{"msg":"sending reconcile request ReconciliationId(2)","v":0,"name":"crucible","level":30,"time":"2024-09-26T19:44:31.562812831Z","hostname":"w-01J8QXH7SYQS95RZY0ACANYM79","pid":1232,"client":"2","":"downstairs","session_id":"d0e127a7-2e03-4989-be5c-cdca1830c60f"}
4522024-09-26T19:44:32.526Z{"msg":"no Nexus client from DNS, aborting progress notification","v":0,"name":"crucible","level":50,"time":"2024-09-26T19:44:31.562833558Z","hostname":"w-01J8QXH7SYQS95RZY0ACANYM79","pid":1232,"reconcile":"2b4c4a0d-da35-4a9a-a6eb-db75a4112fa5","":"downstairs","":"downstairs","session_id":"d0e127a7-2e03-4989-be5c-cdca1830c60f"}
4532024-09-26T19:44:32.543Z{"msg":"no Nexus client from DNS, aborting progress notification","v":0,"name":"crucible","level":50,"time":"2024-09-26T19:44:31.586043954Z","hostname":"w-01J8QXH7SYQS95RZY0ACANYM79","pid":1232,"reconcile":"2b4c4a0d-da35-4a9a-a6eb-db75a4112fa5","":"downstairs","":"downstairs","session_id":"d0e127a7-2e03-4989-be5c-cdca1830c60f"}
4542024-09-26T19:44:32.545Z{"msg":"no Nexus client from DNS, aborting progress notification","v":0,"name":"crucible","level":50,"time":"2024-09-26T19:44:31.586415496Z","hostname":"w-01J8QXH7SYQS95RZY0ACANYM79","pid":1232,"reconcile":"2b4c4a0d-da35-4a9a-a6eb-db75a4112fa5","":"downstairs","":"downstairs","session_id":"d0e127a7-2e03-4989-be5c-cdca1830c60f"}
4552024-09-26T19:44:32.545Z{"msg":"no Nexus client from DNS, aborting progress notification","v":0,"name":"crucible","level":50,"time":"2024-09-26T19:44:31.587306726Z","hostname":"w-01J8QXH7SYQS95RZY0ACANYM79","pid":1232,"reconcile":"2b4c4a0d-da35-4a9a-a6eb-db75a4112fa5","":"downstairs","":"downstairs","session_id":"d0e127a7-2e03-4989-be5c-cdca1830c60f"}
4562024-09-26T19:44:32.545Z{"msg":"sending reconcile request ReconciliationId(6)","v":0,"name":"crucible","level":30,"time":"2024-09-26T19:44:31.587609418Z","hostname":"w-01J8QXH7SYQS95RZY0ACANYM79","pid":1232,"client":"1","":"downstairs","session_id":"d0e127a7-2e03-4989-be5c-cdca1830c60f"}
4572024-09-26T19:44:32.545Z{"msg":"sending reconcile request ReconciliationId(6)","v":0,"name":"crucible","level":30,"time":"2024-09-26T19:44:31.587640574Z","hostname":"w-01J8QXH7SYQS95RZY0ACANYM79","pid":1232,"client":"2","":"downstairs","session_id":"d0e127a7-2e03-4989-be5c-cdca1830c60f"}
4582024-09-26T19:44:32.545Z{"msg":"no Nexus client from DNS, aborting progress notification","v":0,"name":"crucible","level":50,"time":"2024-09-26T19:44:31.587678318Z","hostname":"w-01J8QXH7SYQS95RZY0ACANYM79","pid":1232,"reconcile":"2b4c4a0d-da35-4a9a-a6eb-db75a4112fa5","":"downstairs","":"downstairs","session_id":"d0e127a7-2e03-4989-be5c-cdca1830c60f"}
4592024-09-26T19:44:32.555Z{"msg":"no Nexus client from DNS, aborting progress notification","v":0,"name":"crucible","level":50,"time":"2024-09-26T19:44:31.598303164Z","hostname":"w-01J8QXH7SYQS95RZY0ACANYM79","pid":1232,"reconcile":"2b4c4a0d-da35-4a9a-a6eb-db75a4112fa5","":"downstairs","":"downstairs","session_id":"d0e127a7-2e03-4989-be5c-cdca1830c60f"}
4602024-09-26T19:44:32.558Z{"msg":"no Nexus client from DNS, aborting progress notification","v":0,"name":"crucible","level":50,"time":"2024-09-26T19:44:31.598692553Z","hostname":"w-01J8QXH7SYQS95RZY0ACANYM79","pid":1232,"reconcile":"2b4c4a0d-da35-4a9a-a6eb-db75a4112fa5","":"downstairs","":"downstairs","session_id":"d0e127a7-2e03-4989-be5c-cdca1830c60f"}
4612024-09-26T19:44:32.558Z{"msg":"no Nexus client from DNS, aborting progress notification","v":0,"name":"crucible","level":50,"time":"2024-09-26T19:44:31.599850992Z","hostname":"w-01J8QXH7SYQS95RZY0ACANYM79","pid":1232,"reconcile":"2b4c4a0d-da35-4a9a-a6eb-db75a4112fa5","":"downstairs","":"downstairs","session_id":"d0e127a7-2e03-4989-be5c-cdca1830c60f"}
4622024-09-26T19:44:32.558Z{"msg":"sending reconcile request ReconciliationId(10)","v":0,"name":"crucible","level":30,"time":"2024-09-26T19:44:31.600161863Z","hostname":"w-01J8QXH7SYQS95RZY0ACANYM79","pid":1232,"client":"1","":"downstairs","session_id":"d0e127a7-2e03-4989-be5c-cdca1830c60f"}
4632024-09-26T19:44:32.558Z{"msg":"sending reconcile request ReconciliationId(10)","v":0,"name":"crucible","level":30,"time":"2024-09-26T19:44:31.600199647Z","hostname":"w-01J8QXH7SYQS95RZY0ACANYM79","pid":1232,"client":"2","":"downstairs","session_id":"d0e127a7-2e03-4989-be5c-cdca1830c60f"}
4642024-09-26T19:44:32.558Z{"msg":"no Nexus client from DNS, aborting progress notification","v":0,"name":"crucible","level":50,"time":"2024-09-26T19:44:31.600216264Z","hostname":"w-01J8QXH7SYQS95RZY0ACANYM79","pid":1232,"reconcile":"2b4c4a0d-da35-4a9a-a6eb-db75a4112fa5","":"downstairs","":"downstairs","session_id":"d0e127a7-2e03-4989-be5c-cdca1830c60f"}
4652024-09-26T19:44:32.574Z{"msg":"no Nexus client from DNS, aborting progress notification","v":0,"name":"crucible","level":50,"time":"2024-09-26T19:44:31.61691742Z","hostname":"w-01J8QXH7SYQS95RZY0ACANYM79","pid":1232,"reconcile":"2b4c4a0d-da35-4a9a-a6eb-db75a4112fa5","":"downstairs","":"downstairs","session_id":"d0e127a7-2e03-4989-be5c-cdca1830c60f"}
4662024-09-26T19:44:32.577Z{"msg":"done with reconciliation","v":0,"name":"crucible","level":30,"time":"2024-09-26T19:44:31.617247308Z","hostname":"w-01J8QXH7SYQS95RZY0ACANYM79","pid":1232,"":"downstairs","":"downstairs","session_id":"d0e127a7-2e03-4989-be5c-cdca1830c60f"}
4672024-09-26T19:44:32.578Z{"msg":"Transition from Reconcile to Active","v":0,"name":"crucible","level":30,"time":"2024-09-26T19:44:31.617286392Z","hostname":"w-01J8QXH7SYQS95RZY0ACANYM79","pid":1232,"client":"0","":"downstairs","session_id":"d0e127a7-2e03-4989-be5c-cdca1830c60f"}
4682024-09-26T19:44:32.578Z{"msg":"Transition from Reconcile to Active","v":0,"name":"crucible","level":30,"time":"2024-09-26T19:44:31.617313817Z","hostname":"w-01J8QXH7SYQS95RZY0ACANYM79","pid":1232,"client":"1","":"downstairs","session_id":"d0e127a7-2e03-4989-be5c-cdca1830c60f"}
4692024-09-26T19:44:32.578Z{"msg":"Transition from Reconcile to Active","v":0,"name":"crucible","level":30,"time":"2024-09-26T19:44:31.617343683Z","hostname":"w-01J8QXH7SYQS95RZY0ACANYM79","pid":1232,"client":"2","":"downstairs","session_id":"d0e127a7-2e03-4989-be5c-cdca1830c60f"}
4702024-09-26T19:44:32.578Z{"msg":"All required reconciliation work is completed","v":0,"name":"crucible","level":30,"time":"2024-09-26T19:44:31.617369029Z","hostname":"w-01J8QXH7SYQS95RZY0ACANYM79","pid":1232,"session_id":"d0e127a7-2e03-4989-be5c-cdca1830c60f"}
4712024-09-26T19:44:32.578ZWait for a query_work_queue command to finish before sending IO
4722024-09-26T19:44:32.578Z{"msg":"Set Downstairs and Upstairs active after reconciliation","v":0,"name":"crucible","level":30,"time":"2024-09-26T19:44:31.617403443Z","hostname":"w-01J8QXH7SYQS95RZY0ACANYM79","pid":1232,"session_id":"d0e127a7-2e03-4989-be5c-cdca1830c60f"}
4732024-09-26T19:44:32.578Z{"msg":"00c8b31c-f9c1-4fbb-b6b6-4115996ff28c is now active with session: d0e127a7-2e03-4989-be5c-cdca1830c60f","v":0,"name":"crucible","level":30,"time":"2024-09-26T19:44:31.617439218Z","hostname":"w-01J8QXH7SYQS95RZY0ACANYM79","pid":1232,"session_id":"d0e127a7-2e03-4989-be5c-cdca1830c60f"}
4742024-09-26T19:44:32.578Z{"msg":"The guest has finished waiting for activation with:33","v":0,"name":"crucible","level":30,"time":"2024-09-26T19:44:31.617471353Z","hostname":"w-01J8QXH7SYQS95RZY0ACANYM79","pid":1232}
4752024-09-26T19:44:32.578Z{"msg":"no Nexus client from DNS, aborting finish notification","v":0,"name":"crucible","level":50,"time":"2024-09-26T19:44:31.617493609Z","hostname":"w-01J8QXH7SYQS95RZY0ACANYM79","pid":1232,"reconcile":"2b4c4a0d-da35-4a9a-a6eb-db75a4112fa5","":"downstairs","":"downstairs","session_id":"d0e127a7-2e03-4989-be5c-cdca1830c60f"}
4762024-09-26T19:44:32.578ZRegion: es:10 ec:5 bs:4096 ts:204800 tb:50 max_io:50 or 204800
4772024-09-26T19:44:32.578ZLoading write count information from file "/var/tmp/test_up-build/verify_file"
4782024-09-26T19:44:32.578ZRead and Verify all blocks (0..50 range:true)
4792024-09-26T19:44:32.616ZWrote out file "/var/tmp/test_up-build/verify_file"
4802024-09-26T19:44:32.616ZVerify test completed
4812024-09-26T19:44:32.619ZWrote out file "/var/tmp/test_up-build/verify_file"
4822024-09-26T19:44:32.619ZCLIENT: Tests done. All submitted work has been ACK'd
4832024-09-26T19:44:32.619Z----------------------------------------------------------------
4842024-09-26T19:44:32.619Z Crucible gen:33 GIO:true work queues: Upstairs:0 downstairs:1
4852024-09-26T19:44:32.619ZStates: Active Active Active
4862024-09-26T19:44:32.619ZGW_ID ACK DSID TYPE BKS/EXT DS:0 DS:1 DS:2 REPLAY
4872024-09-26T19:44:32.619Z 1 Acked 1000 Read 50 Done Done Done false
4882024-09-26T19:44:32.619Z STATES DS:0 DS:1 DS:2 TOTAL
4892024-09-26T19:44:32.619Z Sent 0 0 0 0
4902024-09-26T19:44:32.619Z Done 1 1 1 3
4912024-09-26T19:44:32.619Z Skipped 0 0 0 0
4922024-09-26T19:44:32.619Z Error 0 0 0 0
4932024-09-26T19:44:32.619ZLast Flush: 0 0 0
4942024-09-26T19:44:32.619ZDownstairs last five completed:
4952024-09-26T19:44:32.619ZUpstairs last five completed: 1
4962024-09-26T19:44:32.619ZCLIENT: Up:0 ds:1 act:3
4972024-09-26T19:44:36.619Z----------------------------------------------------------------
4982024-09-26T19:44:36.619Z Crucible gen:33 GIO:true work queues: Upstairs:0 downstairs:0
4992024-09-26T19:44:36.619ZDownstairs last five completed: 1001 1000
5002024-09-26T19:44:36.619ZUpstairs last five completed: 2 1
5012024-09-26T19:44:36.619ZCLIENT: Up:0 ds:0 act:3
5022024-09-26T19:44:36.619ZCLIENT: All crucible jobs finished, exiting program
5032024-09-26T19:44:36.621Z{"msg":"Guest handle has been dropped","v":0,"name":"crucible","level":40,"time":"2024-09-26T19:44:35.661390396Z","hostname":"w-01J8QXH7SYQS95RZY0ACANYM79","pid":1232}
5042024-09-26T19:44:36.626ZRepair part 2 passed
5052024-09-26T19:44:36.629Z/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
5062024-09-26T19:44:36.643ZEXT BLOCKS GEN0 GEN1 GEN2 FL0 FL1 FL2 D0 D1 D2 DIFF
5072024-09-26T19:44:36.643Z 0 000-009 31 31 31 1697 1697 1697 F F F
5082024-09-26T19:44:36.646Z 1 010-019 31 31 31 1697 1697 1697 F F F
5092024-09-26T19:44:36.646Z 2 020-029 32 32 32 1698 1698 1698 F F F
5102024-09-26T19:44:36.646Z 3 030-039 32 32 32 1698 1698 1698 F F F
5112024-09-26T19:44:36.646Z 4 040-049 32 32 32 1698 1698 1698 F F F
5122024-09-26T19:44:36.646ZMax gen: 32, Max flush: 1698
5132024-09-26T19:44:36.649Zdump test passed
5142024-09-26T19:44:36.649Z/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
5152024-09-26T19:44:36.662Z Extent 1
5162024-09-26T19:44:36.665ZGEN 31 31 31
5172024-09-26T19:44:36.665ZFLUSH_ID 1697 1697 1697
5182024-09-26T19:44:36.665ZDIRTY
5192024-09-26T19:44:36.665Z
5202024-09-26T19:44:36.665ZBLOCK D0 D1 D2 C0 C1 C2 DIFF
5212024-09-26T19:44:36.665Z010 A A A A A A
5222024-09-26T19:44:36.667Z011 A A A A A A
5232024-09-26T19:44:36.667Z012 A A A A A A
5242024-09-26T19:44:36.670Z013 A A A A A A
5252024-09-26T19:44:36.671Z014 A A A A A A
5262024-09-26T19:44:36.671Z015 A A A A A A
5272024-09-26T19:44:36.673Z016 A A A A A A
5282024-09-26T19:44:36.673Z017 A A A A A A
5292024-09-26T19:44:36.675Z018 A A A A A A
5302024-09-26T19:44:36.678Z019 A A A A A A
5312024-09-26T19:44:36.681Zdump extent test passed
5322024-09-26T19:44:36.681Z/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
5332024-09-26T19:44:36.694ZExtent 2 Block in extent 0 Actual block 20
5342024-09-26T19:44:36.694Z
5352024-09-26T19:44:36.698Z DATA SHA256 VER
5362024-09-26T19:44:36.698Z------ ---------------------------------------------------------------- ---
5372024-09-26T19:44:36.698Z 0 4b63b610a2b395899632b318b1b4434d9921f5cde03d850fe3f621a0da6446c1 A
5382024-09-26T19:44:36.698Z 1 4b63b610a2b395899632b318b1b4434d9921f5cde03d850fe3f621a0da6446c1 A
5392024-09-26T19:44:36.698Z 2 4b63b610a2b395899632b318b1b4434d9921f5cde03d850fe3f621a0da6446c1 A
5402024-09-26T19:44:36.698Z
5412024-09-26T19:44:36.698ZNONCES 0 1 2 DIFF
5422024-09-26T19:44:36.698Z------ ------------------------ ------------------------ ------------------------ -----
5432024-09-26T19:44:36.698Z 0 76fd18f680268988d74bb6da 76fd18f680268988d74bb6da 76fd18f680268988d74bb6da
5442024-09-26T19:44:36.699Z
5452024-09-26T19:44:36.699Z TAGS 0 1 2 DIFF
5462024-09-26T19:44:36.699Z------ -------------------------------- -------------------------------- -------------------------------- -----
5472024-09-26T19:44:36.699Z 0 2cebe2aeb9d8067739b0a65e6bae30ae 2cebe2aeb9d8067739b0a65e6bae30ae 2cebe2aeb9d8067739b0a65e6bae30ae
5482024-09-26T19:44:36.699Z
5492024-09-26T19:44:36.699ZHASHES 0 1 2 DIFF
5502024-09-26T19:44:36.699Z------ ---------------- ---------------- ---------------- -----
5512024-09-26T19:44:36.699Z
5522024-09-26T19:44:36.702Zdump block test passed
5532024-09-26T19:44:36.702ZUpstairs tests have completed, stopping all downstairs
5542024-09-26T19:44:41.766ZCreating four larger downstairs regions
5552024-09-26T19:44:42.283ZStarting four downstairs
5562024-09-26T19:44:47.290ZNow do the replace-reconcile test
5572024-09-26T19:47:22.232ZCompleted test: replace-reconcile
5582024-09-26T19:47:22.236ZNow do the replace-before-active test
5592024-09-26T19:50:06.593ZCompleted test: replace-before-active
5602024-09-26T19:50:06.593ZTests have completed, stopping all downstairs
5612024-09-26T19:50:06.654Z
5622024-09-26T19:50:06.654ZAll Tests have passed
5632024-09-26T19:50:06.656Z9:13 Test duration
5642024-09-26T19:50:06.656Z
5652024-09-26T19:50:06.656Zreal 9:12.833356360
5662024-09-26T19:50:06.656Zuser 3:38.285871831
5672024-09-26T19:50:06.656Zsys 13.897461413
5682024-09-26T19:50:06.656Ztrap 0.209862951
5692024-09-26T19:50:06.656Ztflt 0.014702201
5702024-09-26T19:50:06.656Zdflt 0.020284943
5712024-09-26T19:50:06.656Zkflt 0.000880530
5722024-09-26T19:50:06.656Zlock 8:20:43.045842760
5732024-09-26T19:50:06.656Zslp 32:41.997902797
5742024-09-26T19:50:06.656Zlat 11.744828947
5752024-09-26T19:50:06.656Zstop 0.129641904
5762024-09-26T19:50:06.656Z+ echo 'test-up-encrypted ends'
5772024-09-26T19:50:06.657Ztest-up-encrypted ends
5782024-09-26T19:50:11.659Zprocess exited: duration 560979 ms, exit code 0
5792024-09-26T19:50:11.659Zexec warning: : stdio descriptors remain open after task exit; waiting 60 seconds for them to close
5802024-09-26T19:51:11.704Zexec warning: : stdout descriptor may be held open by a background process; giving up!
5812024-09-26T19:51:11.704Zexec warning: : stderr descriptor may be held open by a background process; giving up!
 
5822024-09-26T19:51:11.714Zfound 8 output files
5832024-09-26T19:51:11.714Zuploading: /tmp/debug/df.txt (1270 bytes)
5842024-09-26T19:51:12.723Zuploaded: /tmp/debug/df.txt
5852024-09-26T19:51:12.723Zuploading: /tmp/debug/dtrace.txt (487631 bytes)
5862024-09-26T19:51:13.741Zuploaded: /tmp/debug/dtrace.txt
5872024-09-26T19:51:13.743Zuploading: /tmp/debug/iostat.txt (186688 bytes)
5882024-09-26T19:51:13.750Zupload warning: file "/tmp/debug/iostat.txt" changed size mid upload: 186688 -> 187292
5892024-09-26T19:51:14.759Zuploaded: /tmp/debug/iostat.txt
5902024-09-26T19:51:14.759Zuploading: /tmp/debug/mpstat.txt (451763 bytes)
5912024-09-26T19:51:14.775Zupload warning: file "/tmp/debug/mpstat.txt" changed size mid upload: 451763 -> 453956
5922024-09-26T19:51:15.781Zuploaded: /tmp/debug/mpstat.txt
5932024-09-26T19:51:15.783Zuploading: /tmp/debug/paging.txt (82102 bytes)
5942024-09-26T19:51:15.788Zupload warning: file "/tmp/debug/paging.txt" changed size mid upload: 82102 -> 82728
5952024-09-26T19:51:16.793Zuploaded: /tmp/debug/paging.txt
5962024-09-26T19:51:16.795Zuploading: /tmp/debug/prstat.txt (870978 bytes)
5972024-09-26T19:51:16.809Zupload warning: file "/tmp/debug/prstat.txt" changed size mid upload: 870978 -> 877456
5982024-09-26T19:51:17.816Zuploaded: /tmp/debug/prstat.txt
5992024-09-26T19:51:17.818Zuploading: /tmp/debug/psrinfo.txt (1528 bytes)
6002024-09-26T19:51:18.824Zuploaded: /tmp/debug/psrinfo.txt
6012024-09-26T19:51:18.828Zuploading: /tmp/debug/upstairs-info.txt (92114 bytes)
6022024-09-26T19:51:19.835Zuploaded: /tmp/debug/upstairs-info.txt