01J8RRNCZDX7DJEQ84KYDDJGNH: test-up-unencrypted

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: 01J8RRNVPGKR32XER2QB59GEA4

Tags:

Artefacts:

Output:

SEQ GLOBAL TIME DETAILS
12024-09-27T03:49:00.463Zjob dependencies complete; ready to run (waiting for 14 m 58 s)
22024-09-27T03:50:13.939Zjob assigned to worker 01J8RSHJZQ5Z54Q36K202C5NZC (queued for 1 m 13 s)
32024-09-27T03:50:21.970Zdownloading input: /input/build/work/bins/crucible-downstairs.gz
42024-09-27T03:50:23.196Zdownloaded input: /input/build/work/bins/crucible-downstairs.gz
52024-09-27T03:50:23.196Zdownloading input: /input/build/work/bins/crucible-hammer.gz
62024-09-27T03:50:24.242Zdownloaded input: /input/build/work/bins/crucible-hammer.gz
72024-09-27T03:50:24.242Zdownloading input: /input/build/work/bins/crutest.gz
82024-09-27T03:50:25.333Zdownloaded input: /input/build/work/bins/crutest.gz
92024-09-27T03:50:25.333Zdownloading input: /input/build/work/bins/dsc.gz
102024-09-27T03:50:25.995Zdownloaded input: /input/build/work/bins/dsc.gz
112024-09-27T03:50:26.000Zdownloading input: /input/build/work/scripts/perf-downstairs-tick.d
122024-09-27T03:50:26.010Zdownloaded input: /input/build/work/scripts/perf-downstairs-tick.d
132024-09-27T03:50:26.010Zdownloading input: /input/build/work/scripts/test_ds.sh
142024-09-27T03:50:26.028Zdownloaded input: /input/build/work/scripts/test_ds.sh
152024-09-27T03:50:26.028Zdownloading input: /input/build/work/scripts/test_live_repair.sh
162024-09-27T03:50:26.045Zdownloaded input: /input/build/work/scripts/test_live_repair.sh
172024-09-27T03:50:26.045Zdownloading input: /input/build/work/scripts/test_repair.sh
182024-09-27T03:50:26.063Zdownloaded input: /input/build/work/scripts/test_repair.sh
192024-09-27T03:50:26.063Zdownloading input: /input/build/work/scripts/test_replay.sh
202024-09-27T03:50:26.078Zdownloaded input: /input/build/work/scripts/test_replay.sh
212024-09-27T03:50:26.078Zdownloading input: /input/build/work/scripts/test_up.sh
222024-09-27T03:50:26.099Zdownloaded input: /input/build/work/scripts/test_up.sh
232024-09-27T03:50:26.099Zdownloading input: /input/build/work/scripts/upstairs_info.d
242024-09-27T03:50:26.116Zdownloaded input: /input/build/work/scripts/upstairs_info.d
252024-09-27T03:50:26.119Zdownloading input: /input/build/tmp/cargo-test-out.log
262024-09-27T03:50:26.880Zdownloaded input: /input/build/tmp/cargo-test-out.log
 
272024-09-27T03:50:26.880Zstarting task 0: "setup"
282024-09-27T03:50:26.891Z++ uname -s
292024-09-27T03:50:26.894Z+ kern=SunOS
302024-09-27T03:50:26.894Z+ case "$kern" in
312024-09-27T03:50:26.894Z+ groupadd -g 12345 build
322024-09-27T03:50:26.896Z+ useradd -u 12345 -g build -d /home/build -s /bin/bash -c build -P 'Primary Administrator' build
332024-09-27T03:50:28.906Z+ zfs create -o mountpoint=/work rpool/work
342024-09-27T03:50:29.158Z++ awk '$2 == "/home" { print $3 }' /etc/mnttab
352024-09-27T03:50:29.160Z+ home_fs=zfs
362024-09-27T03:50:29.160Z+ [[ zfs == autofs ]]
372024-09-27T03:50:29.160Z+ mkdir -p /home/build
382024-09-27T03:50:29.162Z+ chown build:build /home/build /work
392024-09-27T03:50:30.173Z+ chmod 0700 /home/build /work
402024-09-27T03:50:30.181Zprocess exited: duration 3286 ms, exit code 0
 
412024-09-27T03:50:30.190Zstarting task 1: "authentication"
422024-09-27T03:50:30.211Zprocess exited: duration 18 ms, exit code 0
 
432024-09-27T03:50:30.227Zstarting task 2: "build"
442024-09-27T03:50:30.236Z+ banner cores
452024-09-27T03:50:30.251Z
462024-09-27T03:50:30.251Z #### #### ##### ###### ####
472024-09-27T03:50:30.251Z # # # # # # # #
482024-09-27T03:50:30.252Z # # # # # ##### ####
492024-09-27T03:50:30.252Z # # # ##### # #
502024-09-27T03:50:30.252Z # # # # # # # # #
512024-09-27T03:50:30.252Z #### #### # # ###### ####
522024-09-27T03:50:30.252Z
532024-09-27T03:50:30.269Z+ pfexec coreadm -i /tmp/core.%f.%p -g /tmp/core.%f.%p -e global -e log -e proc-setid -e global-setid
542024-09-27T03:50:30.269Z+ echo 'input bins dir contains:'
552024-09-27T03:50:30.269Zinput bins dir contains:
562024-09-27T03:50:30.269Z+ ls -ltr /input/build/work/bins
572024-09-27T03:50:30.280Ztotal 751246
582024-09-27T03:50:30.280Z-rw-r--r-- 1 root root 108131710 Sep 27 03:50 crucible-downstairs.gz
592024-09-27T03:50:30.280Z-rw-r--r-- 1 root root 102511635 Sep 27 03:50 crucible-hammer.gz
602024-09-27T03:50:30.281Z-rw-r--r-- 1 root root 108522272 Sep 27 03:50 crutest.gz
612024-09-27T03:50:30.281Z-rw-r--r-- 1 root root 65218862 Sep 27 03:50 dsc.gz
622024-09-27T03:50:30.281Z+ banner unpack
632024-09-27T03:50:30.281Z
642024-09-27T03:50:30.281Z # # # # ##### ## #### # #
652024-09-27T03:50:30.281Z # # ## # # # # # # # # #
662024-09-27T03:50:30.281Z # # # # # # # # # # ####
672024-09-27T03:50:30.281Z # # # # # ##### ###### # # #
682024-09-27T03:50:30.281Z # # # ## # # # # # # #
692024-09-27T03:50:30.281Z #### # # # # # #### # #
702024-09-27T03:50:30.282Z
712024-09-27T03:50:30.282Z+ mkdir -p /var/tmp/bins
722024-09-27T03:50:30.282Z+ for t in "$input/bins/"*.gz
732024-09-27T03:50:30.282Z++ basename /input/build/work/bins/crucible-downstairs.gz
742024-09-27T03:50:30.282Z+ b=crucible-downstairs.gz
752024-09-27T03:50:30.282Z+ b=crucible-downstairs
762024-09-27T03:50:30.282Z+ gunzip
772024-09-27T03:50:32.527Z+ chmod +x /var/tmp/bins/crucible-downstairs
782024-09-27T03:50:32.530Z+ for t in "$input/bins/"*.gz
792024-09-27T03:50:32.532Z++ basename /input/build/work/bins/crucible-hammer.gz
802024-09-27T03:50:32.532Z+ b=crucible-hammer.gz
812024-09-27T03:50:32.532Z+ b=crucible-hammer
822024-09-27T03:50:32.532Z+ gunzip
832024-09-27T03:50:34.706Z+ chmod +x /var/tmp/bins/crucible-hammer
842024-09-27T03:50:34.710Z+ for t in "$input/bins/"*.gz
852024-09-27T03:50:34.710Z++ basename /input/build/work/bins/crutest.gz
862024-09-27T03:50:34.713Z+ b=crutest.gz
872024-09-27T03:50:34.713Z+ b=crutest
882024-09-27T03:50:34.713Z+ gunzip
892024-09-27T03:50:36.955Z+ chmod +x /var/tmp/bins/crutest
902024-09-27T03:50:36.958Z+ for t in "$input/bins/"*.gz
912024-09-27T03:50:36.961Z++ basename /input/build/work/bins/dsc.gz
922024-09-27T03:50:36.961Z+ b=dsc.gz
932024-09-27T03:50:36.961Z+ b=dsc
942024-09-27T03:50:36.961Z+ gunzip
952024-09-27T03:50:38.342Z+ chmod +x /var/tmp/bins/dsc
962024-09-27T03:50:38.345Z+ export BINDIR=/var/tmp/bins
972024-09-27T03:50:38.345Z+ BINDIR=/var/tmp/bins
982024-09-27T03:50:38.345Z+ jobpid=1137
992024-09-27T03:50:38.347Z+ echo 'Setup debug logging'
1002024-09-27T03:50:38.347ZSetup debug logging
1012024-09-27T03:50:38.347Z+ mkdir /tmp/debug
1022024-09-27T03:50:38.347Z+ sleep 7200
1032024-09-27T03:50:38.347Z+ psrinfo -v
1042024-09-27T03:50:38.351Z+ df -h
1052024-09-27T03:50:38.377Z+ prstat -d d -mLc 1
1062024-09-27T03:50:38.379Z+ iostat -T d -xn 1
1072024-09-27T03:50:38.379Z+ mpstat -T d 1
1082024-09-27T03:50:38.379Z+ vmstat -T d -p 1
1092024-09-27T03:50:38.382Z+ pfexec dtrace -Z -s /input/build/work/scripts/perf-downstairs-tick.d
1102024-09-27T03:50:38.382Z+ banner test_up_unencrypted
1112024-09-27T03:50:38.382Z+ pfexec dtrace -Z -s /input/build/work/scripts/upstairs_info.d
1122024-09-27T03:50:38.384Z
1132024-09-27T03:50:38.384Z ##### ###### #### ##### # # ##### # # # #
1142024-09-27T03:50:38.384Z # # # # # # # # # # ## #
1152024-09-27T03:50:38.384Z # ##### #### # # # # # # # # # #
1162024-09-27T03:50:38.384Z # # # # # # ##### # # # # #
1172024-09-27T03:50:38.384Z # # # # # # # # # # # ##
1182024-09-27T03:50:38.384Z # ###### #### # ####### #### # ####### #### # #
1192024-09-27T03:50:38.385Z
1202024-09-27T03:50:38.385Z+ ptime -m bash /input/build/work/scripts/test_up.sh -N unencrypted
1212024-09-27T03:50:38.395Z/input/build/work
1222024-09-27T03:50:38.425ZTurn off color for downstairs dump
1232024-09-27T03:50:38.428Zdsc output goes to /tmp/test_up-build/dsc-out.txt
1242024-09-27T03:50:38.428ZCreating three downstairs regions
1252024-09-27T03:50:38.816ZStarting three downstairs
1262024-09-27T03:50:43.824ZDisable automatic restart on all downstairs
1272024-09-27T03:50:43.896Z
1282024-09-27T03:50:43.896ZBegin tests, output goes to /tmp/test_up-build/test_up_out.txt
1292024-09-27T03:50:43.899ZRunning test: span
1302024-09-27T03:50:48.043ZCompleted test: span
1312024-09-27T03:50:53.051ZRunning test: big
1322024-09-27T03:50:57.284ZCompleted test: big
1332024-09-27T03:51:02.292ZRunning test: dep
1342024-09-27T03:51:19.431ZCompleted test: dep
1352024-09-27T03:51:20.612ZRunning test: balloon
1362024-09-27T03:51:33.979ZCompleted test: balloon
1372024-09-27T03:51:39.000ZRunning test: deactivate
1382024-09-27T03:52:33.280ZCompleted test: deactivate
1392024-09-27T03:52:38.287ZRunning hammer
1402024-09-27T03:52:41.942ZRun repair tests
1412024-09-27T03:52:41.946Z/var/tmp/bins/crutest fill -g 31 -q --dsc 127.0.0.1:9998 --verify-out /var/tmp/test_up-build/verify_file
1422024-09-27T03:52:42.008Z{"msg":"use region info: RegionExtentInfo { block_size: 4096, blocks_per_extent: 10, extent_count: 5 }","v":0,"name":"crucible","level":30,"time":"2024-09-27T03:52:40.996371275Z","hostname":"w-01J8RSHJZQ5Z54Q36K202C5NZC","pid":1216,"task":"crutest"}
1432024-09-27T03:52:42.011Z{"msg":"dsc has 3 regions. This means 1 sub_volumes","v":0,"name":"crucible","level":30,"time":"2024-09-27T03:52:40.997086165Z","hostname":"w-01J8RSHJZQ5Z54Q36K202C5NZC","pid":1216,"task":"crutest"}
1442024-09-27T03:52:42.011Z{"msg":"SV 0 has targets: [127.0.0.1:8810, 127.0.0.1:8820, 127.0.0.1:8830]","v":0,"name":"crucible","level":30,"time":"2024-09-27T03:52:40.998893244Z","hostname":"w-01J8RSHJZQ5Z54Q36K202C5NZC","pid":1216,"task":"crutest"}
1452024-09-27T03:52:42.011Z{"msg":"Upstairs starts","v":0,"name":"crucible","level":30,"time":"2024-09-27T03:52:40.999110457Z","hostname":"w-01J8RSHJZQ5Z54Q36K202C5NZC","pid":1216}
1462024-09-27T03:52:42.011Z{"msg":"Crucible Version: BuildInfo {\n version: \"0.0.1\",\n git_sha: \"6901b9ee7172d672adc2780a2da758752eb0a2a4\",\n git_commit_timestamp: \"2024-09-27T03:30:33.000000000Z\",\n git_branch: \"alan/more-dsc-for-tests\",\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-27T03:52:40.999152392Z","hostname":"w-01J8RSHJZQ5Z54Q36K202C5NZC","pid":1216}
1472024-09-27T03:52:42.011Z{"msg":"Upstairs <-> Downstairs Message Version: 11","v":0,"name":"crucible","level":30,"time":"2024-09-27T03:52:40.999190957Z","hostname":"w-01J8RSHJZQ5Z54Q36K202C5NZC","pid":1216}
1482024-09-27T03:52:42.011Z{"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: false, database_read_version: 1, database_write_version: 1 }","v":0,"name":"crucible","level":30,"time":"2024-09-27T03:52:40.999207045Z","hostname":"w-01J8RSHJZQ5Z54Q36K202C5NZC","pid":1216}
1492024-09-27T03:52:42.013Z{"msg":"Crucible 51ac2f29-e3cb-42b2-9a33-b987f0a6b3b1 has session id: 1ed25cfe-7b1e-48f0-8177-4a8f5fec9c27","v":0,"name":"crucible","level":30,"time":"2024-09-27T03:52:40.999672096Z","hostname":"w-01J8RSHJZQ5Z54Q36K202C5NZC","pid":1216,"session_id":"1ed25cfe-7b1e-48f0-8177-4a8f5fec9c27"}
1502024-09-27T03:52:42.013Z{"msg":"Upstairs opts: Upstairs UUID: 51ac2f29-e3cb-42b2-9a33-b987f0a6b3b1, Targets: [127.0.0.1:8810, 127.0.0.1:8820, 127.0.0.1:8830], lossy: false, flush_timeout: None, key populated: false, 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-27T03:52:40.99971604Z","hostname":"w-01J8RSHJZQ5Z54Q36K202C5NZC","pid":1216,"session_id":"1ed25cfe-7b1e-48f0-8177-4a8f5fec9c27"}
1512024-09-27T03:52:42.013Z{"msg":"Crucible stats registered with UUID: 51ac2f29-e3cb-42b2-9a33-b987f0a6b3b1","v":0,"name":"crucible","level":30,"time":"2024-09-27T03:52:40.999735987Z","hostname":"w-01J8RSHJZQ5Z54Q36K202C5NZC","pid":1216,"session_id":"1ed25cfe-7b1e-48f0-8177-4a8f5fec9c27"}
1522024-09-27T03:52:42.046Z{"msg":"The guest has requested activation with gen:31","v":0,"name":"crucible","level":30,"time":"2024-09-27T03:52:41.034120084Z","hostname":"w-01J8RSHJZQ5Z54Q36K202C5NZC","pid":1216}
1532024-09-27T03:52:42.049Z{"msg":"51ac2f29-e3cb-42b2-9a33-b987f0a6b3b1 active request set","v":0,"name":"crucible","level":30,"time":"2024-09-27T03:52:41.034243738Z","hostname":"w-01J8RSHJZQ5Z54Q36K202C5NZC","pid":1216,"session_id":"1ed25cfe-7b1e-48f0-8177-4a8f5fec9c27"}
1542024-09-27T03:52:42.049Z{"msg":"sending connect oneshot to client","v":0,"name":"crucible","level":30,"time":"2024-09-27T03:52:41.034291512Z","hostname":"w-01J8RSHJZQ5Z54Q36K202C5NZC","pid":1216,"client":"0","":"downstairs","session_id":"1ed25cfe-7b1e-48f0-8177-4a8f5fec9c27"}
1552024-09-27T03:52:42.049Z{"msg":"client set_active_request while in New; waiting...","v":0,"name":"crucible","level":30,"time":"2024-09-27T03:52:41.034356084Z","hostname":"w-01J8RSHJZQ5Z54Q36K202C5NZC","pid":1216,"client":"0","":"downstairs","session_id":"1ed25cfe-7b1e-48f0-8177-4a8f5fec9c27"}
1562024-09-27T03:52:42.049Z{"msg":"sending connect oneshot to client","v":0,"name":"crucible","level":30,"time":"2024-09-27T03:52:41.034436974Z","hostname":"w-01J8RSHJZQ5Z54Q36K202C5NZC","pid":1216,"client":"1","":"downstairs","session_id":"1ed25cfe-7b1e-48f0-8177-4a8f5fec9c27"}
1572024-09-27T03:52:42.049Z{"msg":"client set_active_request while in New; waiting...","v":0,"name":"crucible","level":30,"time":"2024-09-27T03:52:41.034499646Z","hostname":"w-01J8RSHJZQ5Z54Q36K202C5NZC","pid":1216,"client":"1","":"downstairs","session_id":"1ed25cfe-7b1e-48f0-8177-4a8f5fec9c27"}
1582024-09-27T03:52:42.049Z{"msg":"sending connect oneshot to client","v":0,"name":"crucible","level":30,"time":"2024-09-27T03:52:41.034531502Z","hostname":"w-01J8RSHJZQ5Z54Q36K202C5NZC","pid":1216,"client":"2","":"downstairs","session_id":"1ed25cfe-7b1e-48f0-8177-4a8f5fec9c27"}
1592024-09-27T03:52:42.049Z{"msg":"client set_active_request while in New; waiting...","v":0,"name":"crucible","level":30,"time":"2024-09-27T03:52:41.034560718Z","hostname":"w-01J8RSHJZQ5Z54Q36K202C5NZC","pid":1216,"client":"2","":"downstairs","session_id":"1ed25cfe-7b1e-48f0-8177-4a8f5fec9c27"}
1602024-09-27T03:52:42.049Z{"msg":"connecting to 127.0.0.1:8830","v":0,"name":"crucible","level":30,"time":"2024-09-27T03:52:41.034739795Z","hostname":"w-01J8RSHJZQ5Z54Q36K202C5NZC","pid":1216,"":"io task","client":"2","":"downstairs","session_id":"1ed25cfe-7b1e-48f0-8177-4a8f5fec9c27"}
1612024-09-27T03:52:42.049Z{"msg":"connecting to 127.0.0.1:8810","v":0,"name":"crucible","level":30,"time":"2024-09-27T03:52:41.034862909Z","hostname":"w-01J8RSHJZQ5Z54Q36K202C5NZC","pid":1216,"":"io task","client":"0","":"downstairs","session_id":"1ed25cfe-7b1e-48f0-8177-4a8f5fec9c27"}
1622024-09-27T03:52:42.049Z{"msg":"connecting to 127.0.0.1:8820","v":0,"name":"crucible","level":30,"time":"2024-09-27T03:52:41.034902004Z","hostname":"w-01J8RSHJZQ5Z54Q36K202C5NZC","pid":1216,"":"io task","client":"1","":"downstairs","session_id":"1ed25cfe-7b1e-48f0-8177-4a8f5fec9c27"}
1632024-09-27T03:52:42.049Z{"msg":"ds_connection connected from Ok(127.0.0.1:41085)","v":0,"name":"crucible","level":30,"time":"2024-09-27T03:52:41.034918922Z","hostname":"w-01J8RSHJZQ5Z54Q36K202C5NZC","pid":1216,"":"io task","client":"1","":"downstairs","session_id":"1ed25cfe-7b1e-48f0-8177-4a8f5fec9c27"}
1642024-09-27T03:52:42.049Z{"msg":"ds_connection connected from Ok(127.0.0.1:56590)","v":0,"name":"crucible","level":30,"time":"2024-09-27T03:52:41.03493485Z","hostname":"w-01J8RSHJZQ5Z54Q36K202C5NZC","pid":1216,"":"io task","client":"0","":"downstairs","session_id":"1ed25cfe-7b1e-48f0-8177-4a8f5fec9c27"}
1652024-09-27T03:52:42.049Z{"msg":"ds_connection connected from Ok(127.0.0.1:41355)","v":0,"name":"crucible","level":30,"time":"2024-09-27T03:52:41.034951158Z","hostname":"w-01J8RSHJZQ5Z54Q36K202C5NZC","pid":1216,"":"io task","client":"2","":"downstairs","session_id":"1ed25cfe-7b1e-48f0-8177-4a8f5fec9c27"}
1662024-09-27T03:52:42.049Z{"msg":"ds_transition from New to WaitActive","v":0,"name":"crucible","level":30,"time":"2024-09-27T03:52:41.03556535Z","hostname":"w-01J8RSHJZQ5Z54Q36K202C5NZC","pid":1216,"client":"0","":"downstairs","session_id":"1ed25cfe-7b1e-48f0-8177-4a8f5fec9c27"}
1672024-09-27T03:52:42.049Z{"msg":"[0] Transition from New to WaitActive","v":0,"name":"crucible","level":30,"time":"2024-09-27T03:52:41.035601016Z","hostname":"w-01J8RSHJZQ5Z54Q36K202C5NZC","pid":1216,"client":"0","":"downstairs","session_id":"1ed25cfe-7b1e-48f0-8177-4a8f5fec9c27"}
1682024-09-27T03:52:42.049Z{"msg":"ds_transition from New to WaitActive","v":0,"name":"crucible","level":30,"time":"2024-09-27T03:52:41.035616584Z","hostname":"w-01J8RSHJZQ5Z54Q36K202C5NZC","pid":1216,"client":"1","":"downstairs","session_id":"1ed25cfe-7b1e-48f0-8177-4a8f5fec9c27"}
1692024-09-27T03:52:42.049Z{"msg":"[1] Transition from New to WaitActive","v":0,"name":"crucible","level":30,"time":"2024-09-27T03:52:41.035630532Z","hostname":"w-01J8RSHJZQ5Z54Q36K202C5NZC","pid":1216,"client":"1","":"downstairs","session_id":"1ed25cfe-7b1e-48f0-8177-4a8f5fec9c27"}
1702024-09-27T03:52:42.049Z{"msg":"ds_transition from New to WaitActive","v":0,"name":"crucible","level":30,"time":"2024-09-27T03:52:41.035654099Z","hostname":"w-01J8RSHJZQ5Z54Q36K202C5NZC","pid":1216,"client":"2","":"downstairs","session_id":"1ed25cfe-7b1e-48f0-8177-4a8f5fec9c27"}
1712024-09-27T03:52:42.049Z{"msg":"[2] Transition from New to WaitActive","v":0,"name":"crucible","level":30,"time":"2024-09-27T03:52:41.035678876Z","hostname":"w-01J8RSHJZQ5Z54Q36K202C5NZC","pid":1216,"client":"2","":"downstairs","session_id":"1ed25cfe-7b1e-48f0-8177-4a8f5fec9c27"}
1722024-09-27T03:52:42.049Z{"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-27T03:52:41.036280749Z","hostname":"w-01J8RSHJZQ5Z54Q36K202C5NZC","pid":1216,"client":"2","":"downstairs","session_id":"1ed25cfe-7b1e-48f0-8177-4a8f5fec9c27"}
1732024-09-27T03:52:42.049Z{"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-27T03:52:41.036329113Z","hostname":"w-01J8RSHJZQ5Z54Q36K202C5NZC","pid":1216,"client":"0","":"downstairs","session_id":"1ed25cfe-7b1e-48f0-8177-4a8f5fec9c27"}
1742024-09-27T03:52:42.050Z{"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-27T03:52:41.036374177Z","hostname":"w-01J8RSHJZQ5Z54Q36K202C5NZC","pid":1216,"client":"1","":"downstairs","session_id":"1ed25cfe-7b1e-48f0-8177-4a8f5fec9c27"}
1752024-09-27T03:52:42.052Z{"msg":"ds_transition from WaitActive to WaitQuorum","v":0,"name":"crucible","level":30,"time":"2024-09-27T03:52:41.036775236Z","hostname":"w-01J8RSHJZQ5Z54Q36K202C5NZC","pid":1216,"client":"0","":"downstairs","session_id":"1ed25cfe-7b1e-48f0-8177-4a8f5fec9c27"}
1762024-09-27T03:52:42.052Z{"msg":"[0] Transition from WaitActive to WaitQuorum","v":0,"name":"crucible","level":30,"time":"2024-09-27T03:52:41.03682233Z","hostname":"w-01J8RSHJZQ5Z54Q36K202C5NZC","pid":1216,"client":"0","":"downstairs","session_id":"1ed25cfe-7b1e-48f0-8177-4a8f5fec9c27"}
1772024-09-27T03:52:42.052Z{"msg":"Waiting for more clients to be ready","v":0,"name":"crucible","level":30,"time":"2024-09-27T03:52:41.036840278Z","hostname":"w-01J8RSHJZQ5Z54Q36K202C5NZC","pid":1216,"session_id":"1ed25cfe-7b1e-48f0-8177-4a8f5fec9c27"}
1782024-09-27T03:52:42.052Z{"msg":"ds_transition from WaitActive to WaitQuorum","v":0,"name":"crucible","level":30,"time":"2024-09-27T03:52:41.036852826Z","hostname":"w-01J8RSHJZQ5Z54Q36K202C5NZC","pid":1216,"client":"1","":"downstairs","session_id":"1ed25cfe-7b1e-48f0-8177-4a8f5fec9c27"}
1792024-09-27T03:52:42.053Z{"msg":"[1] Transition from WaitActive to WaitQuorum","v":0,"name":"crucible","level":30,"time":"2024-09-27T03:52:41.036880723Z","hostname":"w-01J8RSHJZQ5Z54Q36K202C5NZC","pid":1216,"client":"1","":"downstairs","session_id":"1ed25cfe-7b1e-48f0-8177-4a8f5fec9c27"}
1802024-09-27T03:52:42.053Z{"msg":"Waiting for more clients to be ready","v":0,"name":"crucible","level":30,"time":"2024-09-27T03:52:41.03690526Z","hostname":"w-01J8RSHJZQ5Z54Q36K202C5NZC","pid":1216,"session_id":"1ed25cfe-7b1e-48f0-8177-4a8f5fec9c27"}
1812024-09-27T03:52:42.053Z{"msg":"ds_transition from WaitActive to WaitQuorum","v":0,"name":"crucible","level":30,"time":"2024-09-27T03:52:41.036932456Z","hostname":"w-01J8RSHJZQ5Z54Q36K202C5NZC","pid":1216,"client":"2","":"downstairs","session_id":"1ed25cfe-7b1e-48f0-8177-4a8f5fec9c27"}
1822024-09-27T03:52:42.053Z{"msg":"[2] Transition from WaitActive to WaitQuorum","v":0,"name":"crucible","level":30,"time":"2024-09-27T03:52:41.036957753Z","hostname":"w-01J8RSHJZQ5Z54Q36K202C5NZC","pid":1216,"client":"2","":"downstairs","session_id":"1ed25cfe-7b1e-48f0-8177-4a8f5fec9c27"}
1832024-09-27T03:52:42.053Z{"msg":"[0]R flush_numbers: [1533, 1533, 1533, 1533, 1533]","v":0,"name":"crucible","level":30,"time":"2024-09-27T03:52:41.03698228Z","hostname":"w-01J8RSHJZQ5Z54Q36K202C5NZC","pid":1216,"":"downstairs","":"downstairs","session_id":"1ed25cfe-7b1e-48f0-8177-4a8f5fec9c27"}
1842024-09-27T03:52:42.053Z{"msg":"[0]R generation: [25, 25, 25, 25, 25]","v":0,"name":"crucible","level":30,"time":"2024-09-27T03:52:41.037013036Z","hostname":"w-01J8RSHJZQ5Z54Q36K202C5NZC","pid":1216,"":"downstairs","":"downstairs","session_id":"1ed25cfe-7b1e-48f0-8177-4a8f5fec9c27"}
1852024-09-27T03:52:42.053Z{"msg":"[0]R dirty: [false, false, false, false, false]","v":0,"name":"crucible","level":30,"time":"2024-09-27T03:52:41.037038183Z","hostname":"w-01J8RSHJZQ5Z54Q36K202C5NZC","pid":1216,"":"downstairs","":"downstairs","session_id":"1ed25cfe-7b1e-48f0-8177-4a8f5fec9c27"}
1862024-09-27T03:52:42.053Z{"msg":"[1]R flush_numbers: [1533, 1533, 1533, 1533, 1533]","v":0,"name":"crucible","level":30,"time":"2024-09-27T03:52:41.037067119Z","hostname":"w-01J8RSHJZQ5Z54Q36K202C5NZC"Wait for a query_work_queue command to finish before sending IO
1872024-09-27T03:52:42.053Z,"pid":1216,"":"downstairs","":"downstairs","session_id":"1ed25cfe-7b1e-48f0-8177-4a8f5fec9c27"}
1882024-09-27T03:52:42.053Z{"msg":"[1]R generation: [25, 25, 25, 25, 25]","v":0,"name":"crucible","level":30,"time":"2024-09-27T03:52:41.037106384Z","hostname":"w-01J8RSHJZQ5Z54Q36K202C5NZC","pid":1216,"":"downstairs","":"downstairs","session_id":"1ed25cfe-7b1e-48f0-8177-4a8f5fec9c27"}
1892024-09-27T03:52:42.053Z{"msg":"[1]R dirty: [false, false, false, false, false]","v":0,"name":"crucible","level":30,"time":"2024-09-27T03:52:41.037149379Z","hostname":"w-01J8RSHJZQ5Z54Q36K202C5NZC","pid":1216,"":"downstairs","":"downstairs","session_id":"1ed25cfe-7b1e-48f0-8177-4a8f5fec9c27"}
1902024-09-27T03:52:42.053Z{"msg":"[2]R flush_numbers: [1533, 1533, 1533, 1533, 1533]","v":0,"name":"crucible","level":30,"time":"2024-09-27T03:52:41.037175895Z","hostname":"w-01J8RSHJZQ5Z54Q36K202C5NZC","pid":1216,"":"downstairs","":"downstairs","session_id":"1ed25cfe-7b1e-48f0-8177-4a8f5fec9c27"}
1912024-09-27T03:52:42.053Z{"msg":"[2]R generation: [25, 25, 25, 25, 25]","v":0,"name":"crucible","level":30,"time":"2024-09-27T03:52:41.037200402Z","hostname":"w-01J8RSHJZQ5Z54Q36K202C5NZC","pid":1216,"":"downstairs","":"downstairs","session_id":"1ed25cfe-7b1e-48f0-8177-4a8f5fec9c27"}
1922024-09-27T03:52:42.053Z{"msg":"[2]R dirty: [false, false, false, false, false]","v":0,"name":"crucible","level":30,"time":"2024-09-27T03:52:41.037229619Z","hostname":"w-01J8RSHJZQ5Z54Q36K202C5NZC","pid":1216,"":"downstairs","":"downstairs","session_id":"1ed25cfe-7b1e-48f0-8177-4a8f5fec9c27"}
1932024-09-27T03:52:42.053Z{"msg":"Max found gen is 26","v":0,"name":"crucible","level":30,"time":"2024-09-27T03:52:41.037253276Z","hostname":"w-01J8RSHJZQ5Z54Q36K202C5NZC","pid":1216,"":"downstairs","":"downstairs","session_id":"1ed25cfe-7b1e-48f0-8177-4a8f5fec9c27"}
1942024-09-27T03:52:42.053Z{"msg":"Generation requested: 31 >= found:26","v":0,"name":"crucible","level":30,"time":"2024-09-27T03:52:41.037280492Z","hostname":"w-01J8RSHJZQ5Z54Q36K202C5NZC","pid":1216,"":"downstairs","":"downstairs","session_id":"1ed25cfe-7b1e-48f0-8177-4a8f5fec9c27"}
1952024-09-27T03:52:42.053Z{"msg":"Next flush: 1534","v":0,"name":"crucible","level":30,"time":"2024-09-27T03:52:41.037304399Z","hostname":"w-01J8RSHJZQ5Z54Q36K202C5NZC","pid":1216,"":"downstairs","":"downstairs","session_id":"1ed25cfe-7b1e-48f0-8177-4a8f5fec9c27"}
1962024-09-27T03:52:42.053Zregion info:
1972024-09-27T03:52:42.053Z{ block size: 4096 bytes
1982024-09-27T03:52:42.053Z"msg":" sub_volume 0 blocks / extent: 10
1992024-09-27T03:52:42.053ZAll extents match","v":0,"name":"crucible","level":30,"time":"2024-09-27T03:52:41.037336575Z","hostname":"w-01J8RSHJZQ5Z54Q36K202C5NZC","pid":1216,"":"downstairs","":"downstairs","session_id":"1ed25cfe-7b1e-48f0-8177-4a8f5fec9c27"}
2002024-09-27T03:52:42.053Z{"msg":"No downstairs reconciliation required","v":0,"name":"crucible","level":30,"time":"2024-09-27T03:52:41.037360902Z","hostname":"w-01J8RSHJZQ5Z54Q36K202C5NZC","pid":1216,"session_id":"1ed25cfe-7b1e-48f0-8177-4a8f5fec9c27"}
2012024-09-27T03:52:42.053Z{"msg":"Transition from WaitQuorum to Active","v":0,"name":"crucible" sub_volume 0 extent size: 40 KiB
2022024-09-27T03:52:42.053Z, sub_volume 0 extent count: 5
2032024-09-27T03:52:42.053Z" total blocks: 50
2042024-09-27T03:52:42.053Zlevel":30 total size: 200 KiB
2052024-09-27T03:52:42.053Z encryption: no
2062024-09-27T03:52:42.053Z,"time":"2024-09-27T03:52:41.037392428Z","hostname":"w-01J8RSHJZQ5Z54Q36K202C5NZC","pid":1216,"client":"0","":"downstairs","session_id":"Fill test
2072024-09-27T03:52:42.053Z1ed25cfe-7b1e-48f0-8177-4a8f5fec9c27"}
2082024-09-27T03:52:42.053Z{"msg":"Transition from WaitQuorum to Active","v":0,"name":"crucible","level":30,"time":"2024-09-27T03:52:41.037418264Z","hostname":"w-01J8RSHJZQ5Z54Q36K202C5NZC","pid":1216,"client":"1","":"downstairs","session_id":"1ed25cfe-7b1e-48f0-8177-4a8f5fec9c27"}
2092024-09-27T03:52:42.053Z{"msg":"Transition from WaitQuorum to Active","v":0,"name":"crucible","level":30,"time":"2024-09-27T03:52:41.037445771Z","hostname":"w-01J8RSHJZQ5Z54Q36K202C5NZC","pid":1216,"client":"2","":"downstairs","session_id":"1ed25cfe-7b1e-48f0-8177-4a8f5fec9c27"}
2102024-09-27T03:52:42.053Z{"msg":"All required reconciliation work is completed","v":0,"name":"crucible","level":30,"time":"2024-09-27T03:52:41.037470268Z","hostname":"w-01J8RSHJZQ5Z54Q36K202C5NZC","pid":1216,"session_id":"1ed25cfe-7b1e-48f0-8177-4a8f5fec9c27"}
2112024-09-27T03:52:42.053Z{"msg":"Set Downstairs and Upstairs active after reconciliation","v":0,"name":"crucible","level":30,"time":"2024-09-27T03:52:41.037496665Z","hostname":"w-01J8RSHJZQ5Z54Q36K202C5NZC","pid":1216,"session_id":"1ed25cfe-7b1e-48f0-8177-4a8f5fec9c27"}
2122024-09-27T03:52:42.053Z{"msg":"51ac2f29-e3cb-42b2-9a33-b987f0a6b3b1 is now active with session: 1ed25cfe-7b1e-48f0-8177-4a8f5fec9c27","v":0,"name":"crucible","level":30,"time":"2024-09-27T03:52:41.037520322Z","hostname":"w-01J8RSHJZQ5Z54Q36K202C5NZC","pid":1216,"session_id":"1ed25cfe-7b1e-48f0-8177-4a8f5fec9c27"}
2132024-09-27T03:52:42.053Z{"msg":"Set Active after no reconciliation","v":0,"name":"crucible","level":30,"time":"2024-09-27T03:52:41.037546228Z","hostname":"w-01J8RSHJZQ5Z54Q36K202C5NZC","pid":1216,"session_id":"1ed25cfe-7b1e-48f0-8177-4a8f5fec9c27"}
2142024-09-27T03:52:42.053Z{"msg":"The guest has finished waiting for activation with:31","v":0,"name":"crucible","level":30,"time":"2024-09-27T03:52:41.037568085Z","hostname":"w-01J8RSHJZQ5Z54Q36K202C5NZC","pid":1216}
2152024-09-27T03:52:42.060ZRead and Verify all blocks (0..50 range:false)
2162024-09-27T03:52:42.066ZWrote out file "/var/tmp/test_up-build/verify_file"
2172024-09-27T03:52:42.066ZCLIENT: Tests done. All submitted work has been ACK'd
2182024-09-27T03:52:42.069Z----------------------------------------------------------------
2192024-09-27T03:52:42.069Z Crucible gen:31 GIO:true work queues: Upstairs:0 downstairs:1
2202024-09-27T03:52:42.069ZStates: Active Active Active
2212024-09-27T03:52:42.069ZGW_ID ACK DSID TYPE BKS/EXT DS:0 DS:1 DS:2 REPLAY
2222024-09-27T03:52:42.069Z 3 Acked 1002 Read 50 Done Done Done false
2232024-09-27T03:52:42.069Z STATES DS:0 DS:1 DS:2 TOTAL
2242024-09-27T03:52:42.069Z Sent 0 0 0 0
2252024-09-27T03:52:42.069Z Done 1 1 1 3
2262024-09-27T03:52:42.069Z Skipped 0 0 0 0
2272024-09-27T03:52:42.069Z Error 0 0 0 0
2282024-09-27T03:52:42.069ZLast Flush: 1001 1001 1001
2292024-09-27T03:52:42.069ZDownstairs last five completed: 1001 1000
2302024-09-27T03:52:42.069ZUpstairs last five completed: 3 2 1
2312024-09-27T03:52:42.069ZCLIENT: Up:0 ds:1 act:3
2322024-09-27T03:52:46.068Z----------------------------------------------------------------
2332024-09-27T03:52:46.069Z Crucible gen:31 GIO:true work queues: Upstairs:0 downstairs:0
2342024-09-27T03:52:46.069ZDownstairs last five completed: 1003 1002 1001 1000
2352024-09-27T03:52:46.069ZUpstairs last five completed: 4 3 2 1
2362024-09-27T03:52:46.069ZCLIENT: Up:0 ds:0 act:3
2372024-09-27T03:52:46.069ZCLIENT: All crucible jobs finished, exiting program
2382024-09-27T03:52:46.071Z{"msg":"Guest handle has been dropped","v":0,"name":"crucible","level":40,"time":"2024-09-27T03:52:45.056254087Z","hostname":"w-01J8RSHJZQ5Z54Q36K202C5NZC","pid":1216}
2392024-09-27T03:52:46.081ZRepair setup passed
2402024-09-27T03:52:46.085ZCopy the region for /var/tmp/test_up-build/8830
2412024-09-27T03:52:46.087Zcp -r /var/tmp/test_up-build/8830 /var/tmp/test_up-build/previous
2422024-09-27T03:52:46.089Z/var/tmp/bins/crutest repair -g 32 -q --dsc 127.0.0.1:9998 --verify-out /var/tmp/test_up-build/verify_file --verify-in /var/tmp/test_up-build/verify_file
2432024-09-27T03:52:46.150Z{"msg":"use region info: RegionExtentInfo { block_size: 4096, blocks_per_extent: 10, extent_count: 5 }","v":0,"name":"crucible","level":30,"time":"2024-09-27T03:52:45.136997906Z","hostname":"w-01J8RSHJZQ5Z54Q36K202C5NZC","pid":1222,"task":"crutest"}
2442024-09-27T03:52:46.152Z{"msg":"dsc has 3 regions. This means 1 sub_volumes","v":0,"name":"crucible","level":30,"time":"2024-09-27T03:52:45.137705746Z","hostname":"w-01J8RSHJZQ5Z54Q36K202C5NZC","pid":1222,"task":"crutest"}
2452024-09-27T03:52:46.152Z{"msg":"SV 0 has targets: [127.0.0.1:8810, 127.0.0.1:8820, 127.0.0.1:8830]","v":0,"name":"crucible","level":30,"time":"2024-09-27T03:52:45.139594476Z","hostname":"w-01J8RSHJZQ5Z54Q36K202C5NZC","pid":1222,"task":"crutest"}
2462024-09-27T03:52:46.153Z{"msg":"Upstairs starts","v":0,"name":"crucible","level":30,"time":"2024-09-27T03:52:45.139885309Z","hostname":"w-01J8RSHJZQ5Z54Q36K202C5NZC","pid":1222}
2472024-09-27T03:52:46.153Z{"msg":"Crucible Version: BuildInfo {\n version: \"0.0.1\",\n git_sha: \"6901b9ee7172d672adc2780a2da758752eb0a2a4\",\n git_commit_timestamp: \"2024-09-27T03:30:33.000000000Z\",\n git_branch: \"alan/more-dsc-for-tests\",\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-27T03:52:45.139933883Z","hostname":"w-01J8RSHJZQ5Z54Q36K202C5NZC","pid":1222}
2482024-09-27T03:52:46.153Z{"msg":"Upstairs <-> Downstairs Message Version: 11","v":0,"name":"crucible","level":30,"time":"2024-09-27T03:52:45.13996038Z","hostname":"w-01J8RSHJZQ5Z54Q36K202C5NZC","pid":1222}
2492024-09-27T03:52:46.153Z{"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: false, database_read_version: 1, database_write_version: 1 }","v":0,"name":"crucible","level":30,"time":"2024-09-27T03:52:45.139979617Z","hostname":"w-01J8RSHJZQ5Z54Q36K202C5NZC","pid":1222}
2502024-09-27T03:52:46.155Z{"msg":"Crucible 15f483d7-34dd-4b38-ad3b-1d0142b0e5ee has session id: ac545a27-ae9c-4971-b2a8-23c2927da1c3","v":0,"name":"crucible","level":30,"time":"2024-09-27T03:52:45.140547445Z","hostname":"w-01J8RSHJZQ5Z54Q36K202C5NZC","pid":1222,"session_id":"ac545a27-ae9c-4971-b2a8-23c2927da1c3"}
2512024-09-27T03:52:46.155Z{"msg":"Upstairs opts: Upstairs UUID: 15f483d7-34dd-4b38-ad3b-1d0142b0e5ee, Targets: [127.0.0.1:8810, 127.0.0.1:8820, 127.0.0.1:8830], lossy: false, flush_timeout: None, key populated: false, 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-27T03:52:45.140598139Z","hostname":"w-01J8RSHJZQ5Z54Q36K202C5NZC","pid":1222,"session_id":"ac545a27-ae9c-4971-b2a8-23c2927da1c3"}
2522024-09-27T03:52:46.155Z{"msg":"Crucible stats registered with UUID: 15f483d7-34dd-4b38-ad3b-1d0142b0e5ee","v":0,"name":"crucible","level":30,"time":"2024-09-27T03:52:45.140627065Z","hostname":"w-01J8RSHJZQ5Z54Q36K202C5NZC","pid":1222,"session_id":"ac545a27-ae9c-4971-b2a8-23c2927da1c3"}
2532024-09-27T03:52:46.189Z{"msg":"The guest has requested activation with gen:32","v":0,"name":"crucible","level":30,"time":"2024-09-27T03:52:45.175469343Z","hostname":"w-01J8RSHJZQ5Z54Q36K202C5NZC","pid":1222}
2542024-09-27T03:52:46.189Z{"msg":"15f483d7-34dd-4b38-ad3b-1d0142b0e5ee active request set","v":0,"name":"crucible","level":30,"time":"2024-09-27T03:52:45.175533595Z","hostname":"w-01J8RSHJZQ5Z54Q36K202C5NZC","pid":1222,"session_id":"ac545a27-ae9c-4971-b2a8-23c2927da1c3"}
2552024-09-27T03:52:46.189Z{"msg":"sending connect oneshot to client","v":0,"name":"crucible","level":30,"time":"2024-09-27T03:52:45.175553932Z","hostname":"w-01J8RSHJZQ5Z54Q36K202C5NZC","pid":1222,"client":"0","":"downstairs","session_id":"ac545a27-ae9c-4971-b2a8-23c2927da1c3"}
2562024-09-27T03:52:46.189Z{"msg":"client set_active_request while in New; waiting...","v":0,"name":"crucible","level":30,"time":"2024-09-27T03:52:45.175584318Z","hostname":"w-01J8RSHJZQ5Z54Q36K202C5NZC","pid":1222,"client":"0","":"downstairs","session_id":"ac545a27-ae9c-4971-b2a8-23c2927da1c3"}
2572024-09-27T03:52:46.193Z{"msg":"sending connect oneshot to client","v":0,"name":"crucible","level":30,"time":"2024-09-27T03:52:45.175607355Z","hostname":"w-01J8RSHJZQ5Z54Q36K202C5NZC","pid":1222,"client":"1","":"downstairs","session_id":"ac545a27-ae9c-4971-b2a8-23c2927da1c3"}
2582024-09-27T03:52:46.193Z{"msg":"client set_active_request while in New; waiting...","v":0,"name":"crucible","level":30,"time":"2024-09-27T03:52:45.17564884Z","hostname":"w-01J8RSHJZQ5Z54Q36K202C5NZC","pid":1222,"client":"1","":"downstairs","session_id":"ac545a27-ae9c-4971-b2a8-23c2927da1c3"}
2592024-09-27T03:52:46.193Z{"msg":"sending connect oneshot to client","v":0,"name":"crucible","level":30,"time":"2024-09-27T03:52:45.175690425Z","hostname":"w-01J8RSHJZQ5Z54Q36K202C5NZC","pid":1222,"client":"2","":"downstairs","session_id":"ac545a27-ae9c-4971-b2a8-23c2927da1c3"}
2602024-09-27T03:52:46.193Z{"msg":"client set_active_request while in New; waiting...","v":0,"name":"crucible","level":30,"time":"2024-09-27T03:52:45.175721471Z","hostname":"w-01J8RSHJZQ5Z54Q36K202C5NZC","pid":1222,"client":"2","":"downstairs","session_id":"ac545a27-ae9c-4971-b2a8-23c2927da1c3"}
2612024-09-27T03:52:46.193Z{"msg":"connecting to 127.0.0.1:8830","v":0,"name":"crucible","level":30,"time":"2024-09-27T03:52:45.175773094Z","hostname":"w-01J8RSHJZQ5Z54Q36K202C5NZC","pid":1222,"":"io task","client":"2","":"downstairs","session_id":"ac545a27-ae9c-4971-b2a8-23c2927da1c3"}
2622024-09-27T03:52:46.193Z{"msg":"connecting to 127.0.0.1:8810","v":0,"name":"crucible","level":30,"time":"2024-09-27T03:52:45.1758078Z","hostname":"w-01J8RSHJZQ5Z54Q36K202C5NZC","pid":1222,"":"io task","client":"0","":"downstairs","session_id":"ac545a27-ae9c-4971-b2a8-23c2927da1c3"}
2632024-09-27T03:52:46.193Z{"msg":"connecting to 127.0.0.1:8820","v":0,"name":"crucible","level":30,"time":"2024-09-27T03:52:45.175842396Z","hostname":"w-01J8RSHJZQ5Z54Q36K202C5NZC","pid":1222,"":"io task","client":"1","":"downstairs","session_id":"ac545a27-ae9c-4971-b2a8-23c2927da1c3"}
2642024-09-27T03:52:46.193Z{"msg":"ds_connection connected from Ok(127.0.0.1:47325)","v":0,"name":"crucible","level":30,"time":"2024-09-27T03:52:45.175877541Z","hostname":"w-01J8RSHJZQ5Z54Q36K202C5NZC","pid":1222,"":"io task","client":"0","":"downstairs","session_id":"ac545a27-ae9c-4971-b2a8-23c2927da1c3"}
2652024-09-27T03:52:46.193Z{"msg":"ds_connection connected from Ok(127.0.0.1:60960)","v":0,"name":"crucible","level":30,"time":"2024-09-27T03:52:45.175925555Z","hostname":"w-01J8RSHJZQ5Z54Q36K202C5NZC","pid":1222,"":"io task","client":"1","":"downstairs","session_id":"ac545a27-ae9c-4971-b2a8-23c2927da1c3"}
2662024-09-27T03:52:46.193Z{"msg":"ds_connection connected from Ok(127.0.0.1:41617)","v":0,"name":"crucible","level":30,"time":"2024-09-27T03:52:45.176167824Z","hostname":"w-01J8RSHJZQ5Z54Q36K202C5NZC","pid":1222,"":"io task","client":"2","":"downstairs","session_id":"ac545a27-ae9c-4971-b2a8-23c2927da1c3"}
2672024-09-27T03:52:46.193Z{"msg":"ds_transition from New to WaitActive","v":0,"name":"crucible","level":30,"time":"2024-09-27T03:52:45.176858087Z","hostname":"w-01J8RSHJZQ5Z54Q36K202C5NZC","pid":1222,"client":"1","":"downstairs","session_id":"ac545a27-ae9c-4971-b2a8-23c2927da1c3"}
2682024-09-27T03:52:46.193Z{"msg":"[1] Transition from New to WaitActive","v":0,"name":"crucible","level":30,"time":"2024-09-27T03:52:45.17690607Z","hostname":"w-01J8RSHJZQ5Z54Q36K202C5NZC","pid":1222,"client":"1","":"downstairs","session_id":"ac545a27-ae9c-4971-b2a8-23c2927da1c3"}
2692024-09-27T03:52:46.193Z{"msg":"ds_transition from New to WaitActive","v":0,"name":"crucible","level":30,"time":"2024-09-27T03:52:45.176946695Z","hostname":"w-01J8RSHJZQ5Z54Q36K202C5NZC","pid":1222,"client":"2","":"downstairs","session_id":"ac545a27-ae9c-4971-b2a8-23c2927da1c3"}
2702024-09-27T03:52:46.193Z{"msg":"[2] Transition from New to WaitActive","v":0,"name":"crucible","level":30,"time":"2024-09-27T03:52:45.176977131Z","hostname":"w-01J8RSHJZQ5Z54Q36K202C5NZC","pid":1222,"client":"2","":"downstairs","session_id":"ac545a27-ae9c-4971-b2a8-23c2927da1c3"}
2712024-09-27T03:52:46.193Z{"msg":"ds_transition from New to WaitActive","v":0,"name":"crucible","level":30,"time":"2024-09-27T03:52:45.177016436Z","hostname":"w-01J8RSHJZQ5Z54Q36K202C5NZC","pid":1222,"client":"0","":"downstairs","session_id":"ac545a27-ae9c-4971-b2a8-23c2927da1c3"}
2722024-09-27T03:52:46.193Z{"msg":"[0] Transition from New to WaitActive","v":0,"name":"crucible","level":30,"time":"2024-09-27T03:52:45.177058681Z","hostname":"w-01J8RSHJZQ5Z54Q36K202C5NZC","pid":1222,"client":"0","":"downstairs","session_id":"ac545a27-ae9c-4971-b2a8-23c2927da1c3"}
2732024-09-27T03:52:46.193Z{"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-27T03:52:45.177568756Z","hostname":"w-01J8RSHJZQ5Z54Q36K202C5NZC","pid":1222,"client":"1","":"downstairs","session_id":"ac545a27-ae9c-4971-b2a8-23c2927da1c3"}
2742024-09-27T03:52:46.193Z{"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-27T03:52:45.177606011Z","hostname":"w-01J8RSHJZQ5Z54Q36K202C5NZC","pid":1222,"client":"0","":"downstairs","session_id":"ac545a27-ae9c-4971-b2a8-23c2927da1c3"}
2752024-09-27T03:52:46.193Z{"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-27T03:52:45.177632718Z","hostname":"w-01J8RSHJZQ5Z54Q36K202C5NZC","pid":1222,"client":"2","":"downstairs","session_id":"ac545a27-ae9c-4971-b2a8-23c2927da1c3"}
2762024-09-27T03:52:46.193Z{"msg":"ds_transition from WaitActive to WaitQuorum","v":0,"name":"crucible","level":30,"time":"2024-09-27T03:52:45.177980994Z","hostname":"w-01J8RSHJZQ5Z54Q36K202C5NZC","pid":1222,"client":"2","":"downstairs","session_id":"ac545a27-ae9c-4971-b2a8-23c2927da1c3"}
2772024-09-27T03:52:46.193Z{"msg":"[2] Transition from WaitActive to WaitQuorum","v":0,"name":"crucible","level":30,"time":"2024-09-27T03:52:45.178030127Z","hostname":"w-01J8RSHJZQ5Z54Q36K202C5NZC","pid":1222,"client":"2","":"downstairs","session_id":"ac545a27-ae9c-4971-b2a8-23c2927da1c3"}
2782024-09-27T03:52:46.193Z{"msg":"Waiting for more clients to be ready","v":0,"name":"crucible","level":30,"time":"2024-09-27T03:52:45.178071232Z","hostname":"w-01J8RSHJZQ5Z54Q36K202C5NZC","pid":1222,"session_id":"ac545a27-ae9c-4971-b2a8-23c2927da1c3"}
2792024-09-27T03:52:46.193Z{"msg":"ds_transition from WaitActive to WaitQuorum","v":0,"name":"crucible","level":30,"time":"2024-09-27T03:52:45.178106658Z","hostname":"w-01J8RSHJZQ5Z54Q36K202C5NZC","pid":1222,"client":"0","":"downstairs","session_id":"ac545a27-ae9c-4971-b2a8-23c2927da1c3"}
2802024-09-27T03:52:46.193Z{"msg":"[0] Transition from WaitActive to WaitQuorum","v":0,"name":"crucible","level":30,"time":"2024-09-27T03:52:45.178141963Z","hostname":"w-01J8RSHJZQ5Z54Q36K202C5NZC","pid":1222,"client":"0","":"downstairs","session_id":"ac545a27-ae9c-4971-b2a8-23c2927da1c3"}
2812024-09-27T03:52:46.193Z{"msg":"Waiting for more clients to be ready","v":0,"name":"crucible","level":30,"time":"2024-09-27T03:52:45.178175969Z","hostname":"w-01J8RSHJZQ5Z54Q36K202C5NZC","pid":1222,"session_id":"ac545a27-ae9c-4971-b2a8-23c2927da1c3"}
2822024-09-27T03:52:46.193Z{"msg":"ds_transition from WaitActive to WaitQuorum","v":0,"name":"crucible","level":30,"time":"2024-09-27T03:52:45.178207085Z","hostname":"w-01J8RSHJZQ5Z54Q36K202C5NZC","pid":1222,"client":"1","":"downstairs","session_id":"ac545a27-ae9c-4971-b2a8-23c2927da1c3"}
2832024-09-27T03:52:46.193Z{"msg":"[1] Transition from WaitActive to WaitQuorum","v":0,"name":"crucible","level":30,"time":"2024-09-27T03:52:45.178242331Z","hostname":"w-01J8RSHJZQ5Z54Q36K202C5NZC","pid":1222,"client":"1","":"downstairs","session_id":"ac545a27-ae9c-4971-b2a8-23c2927da1c3"}
2842024-09-27T03:52:46.193Z{"msg":"[0]R flush_numbers: [1534, 1534, 1534, 1534, 1534]","v":0,"name":"crucible","level":30,"time":"2024-09-27T03:52:45.178267597Z","hostname":"w-01J8RSHJZQ5Z54Q36K202C5NZC","pid":1222,"":"downstairs","":"downstairs","session_id":"ac545a27-ae9c-4971-b2a8-23c2927da1c3"}
2852024-09-27T03:52:46.193Z{"msg":"[0]R generation: [31, 31, 31, 31, 31]","v":0,"name":"crucible","level":30,"time":"2024-09-27T03:52:45.178310832Z","hostname":"w-01J8RSHJZQ5Z54Q36K202C5NZC","pid":1222,"":"downstairs","":"downstairs","session_id":"ac545a27-ae9c-4971-b2a8-23c2927da1c3"}
2862024-09-27T03:52:46.193Z{"msg":"[0]R dirty: [false, false, false, false, false]","v":0,"name":"crucible","level":30,"time":"2024-09-27T03:52:45.178348917Z","hostname":"w-01J8RSHJZQ5Z54Q36K202C5NZC","pid":1222,"":"downstairs","":"downstairs","session_id":"ac545a27-ae9c-4971-b2a8-23c2927da1c3"}
2872024-09-27T03:52:46.193ZWait for a query_work_queue command to finish before sending IO
2882024-09-27T03:52:46.193Z{"msg":"[1]R flush_numbers: [1534, 1534, 1534, 1534, 1534]","v":0,"name":"crucible","level":30,"time":"2024-09-27T03:52:45.178394741Z","hostname":"w-01J8RSHJZQ5Z54Q36K202C5NZC","pid":1222,"":"downstairs","":"downstairs","session_id":"ac545a27-ae9c-4971-b2a8-23c2927da1c3"}
2892024-09-27T03:52:46.193Z{"msg":"[1]R generation: [31, 31, 31, 31, 31]","v":0,"name":"crucible","level":30,"time":"2024-09-27T03:52:45.178433946Z","hostname":"w-01J8RSHJZQ5Z54Q36K202C5NZC","pid":1222,"":"downstairs","":"downstairs","session_id":"ac545a27-ae9c-4971-b2a8-23c2927da1c3"}
2902024-09-27T03:52:46.193Z{"msg":"[1]R dirty: [false, false, false, false, false]","v":0,"name":"crucible","level":30,"time":"2024-09-27T03:52:45.178474751Z","hostname":"w-01J8RSHJZQ5Z54Q36K202C5NZC","pid":1222,"":"downstairs","":"downstairs","session_id":"ac545a27-ae9c-4971-b2a8-23c2927da1c3"}
2912024-09-27T03:52:46.193Z{"msg":"[2]R flush_numbers: [1534, 1534, 1534, 1534, 1534]","v":0,"name":"crucible","level":30,"time":"2024-09-27T03:52:45.178515696Z","hostname":"w-01J8RSHJZQ5Z54Q36K202C5NZC","pid":1222,"":"downstairs","":"downstairs","session_id":"ac545a27-ae9c-4971-b2a8-23c2927da1c3"}
2922024-09-27T03:52:46.194Z{"msg":"[2]R generation: [31, 31, 31, 31, 31]","v":0,"name":"crucible","level":30,"time":"2024-09-27T03:52:45.178555041Z","hostname":"w-01J8RSHJZQ5Z54Q36K202C5NZC","pid":1222,"":"downstairs","":"downstairs","session_id":"ac545a27-ae9c-4971-b2a8-23c2927da1c3"}
2932024-09-27T03:52:46.194Zregion info:
2942024-09-27T03:52:46.194Z{ block size: 4096 bytes
2952024-09-27T03:52:46.194Z"msg":" sub_volume 0 blocks / extent: 10
2962024-09-27T03:52:46.194Z[2]R dirty: [false, false, false, false, false]","v":0,"name":"crucible","level":30,"time":"2024-09-27T03:52:45.178600505Z","hostname":"w-01J8RSHJZQ5Z54Q36K202C5NZC","pid":1222,"":"downstairs","":"downstairs","session_id":"ac545a27-ae9c-4971-b2a8-23c2927da1c3"}
2972024-09-27T03:52:46.194Z{"msg":"Max found gen is 32","v":0,"name":"crucible","level":30,"time":"2024-09-27T03:52:45.178627631Z","hostname":"w-01J8RSHJZQ5Z54Q36K202C5NZC","pid":1222,"":"downstairs","":"downstairs","session_id":"ac545a27-ae9c-4971-b2a8-23c2927da1c3"}
2982024-09-27T03:52:46.194Z{"msg":"Generation requested: 32 >= found:32","v":0,"name":"crucible","level":30,"time":"2024-09-27T03:52:45.17864199Z","hostname":"w-01J8RSHJZQ5Z54Q36K202C5NZC","pid":1222,"":"downstairs","":"downstairs","session_id":"ac545a27-ae9c-4971-b2a8-23c2927da1c3"}
2992024-09-27T03:52:46.194Z sub_volume 0 extent size: 40 KiB
3002024-09-27T03:52:46.194Z{ sub_volume 0 extent count: 5
3012024-09-27T03:52:46.194Z" total blocks: 50
3022024-09-27T03:52:46.194Zmsg":"Next flush: 1535","v":0,"name":"crucible","level":30 total size: 200 KiB
3032024-09-27T03:52:46.194Z encryption: no
3042024-09-27T03:52:46.194Z,"time":"2024-09-27T03:52:45.178665717Z","hostname":"w-01J8RSHJZQ5Z54Q36K202C5NZC","pid":1222,"":"downstairs","":"downstairs","session_id":"ac545a27-ae9c-4971-b2a8-23c2927da1c3"}
3052024-09-27T03:52:46.194Z{"msg":"All extents match","v":0,"name":"crucible","level":30,"time":"2024-09-27T03:52:45.178679575Z","hostname":"w-01J8RSHJZQ5Z54Q36K202C5NZC","pid":1222,"":"downstairs","":"downstairs","session_id":"ac545a27-ae9c-4971-b2a8-23c2927da1c3"}
3062024-09-27T03:52:46.194Z{"msg":"No downstairs reconciliation required","v":0,"name":"crucible","level":30,"time":"2024-09-27T03:52:45.178693313Z","hostname":"w-01J8RSHJZQ5Z54Q36K202C5NZC","pid":1222,"session_id":"ac545a27-ae9c-4971-b2a8-23c2927da1c3"}
3072024-09-27T03:52:46.194Z{"msg":"Transition from WaitQuorum to Active","v":0,"name":"crucible","level":30,"time":"2024-09-27T03:52:45.178705432Z","hostname":"w-01J8RSHJZQ5Z54Q36K202C5NZC","pid":1222,"client":"0","":"downstairs","session_id":"ac545a27-ae9c-4971-b2a8-23c2927da1c3"}
3082024-09-27T03:52:46.194Z{"msg":"Transition from WaitQuorum to Active","v":0,"name":"crucible","level":30,"time":"2024-09-27T03:52:45.178725849Z","hostname":"w-01J8RSHJZQ5Z54Q36K202C5NZC","pid":1222,"client":"1","":"downstairs","session_id":"ac545a27-ae9c-4971-b2a8-23c2927da1c3"}
3092024-09-27T03:52:46.194Z{"msg":"Transition from WaitQuorum to Active","v":0,"name":"crucible","level":30,"time":"2024-09-27T03:52:45.178739317Z","hostname":"w-01J8RSHJZQ5Z54Q36K202C5NZC","pid":1222,"client":"2","":"downstairs","session_id":"ac545a27-ae9c-4971-b2a8-23c2927da1c3"}
3102024-09-27T03:52:46.194Z{"msg":"All required reconciliation work is completed","v":0,"name":"crucible","level":30,"time":"2024-09-27T03:52:45.178758855Z","hostname":"w-01J8RSHJZQ5Z54Q36K202C5NZC","pid":1222,"session_id":"ac545a27-ae9c-4971-b2a8-23c2927da1c3"}
3112024-09-27T03:52:46.194Z{"msg":"Set Downstairs and Upstairs active after reconciliation","v":0,"name":"crucible","level":30,"time":"2024-09-27T03:52:45.178771283Z","hostname":"w-01J8RSHJZQ5Z54Q36K202C5NZC","pid":1222,"session_id":"ac545a27-ae9c-4971-b2a8-23c2927da1c3"}
3122024-09-27T03:52:46.194Z{"msg":"15f483d7-34dd-4b38-ad3b-1d0142b0e5ee is now active with session: ac545a27-ae9c-4971-b2a8-23c2927da1c3","v":0,"name":"crucible","level":30,"time":"2024-09-27T03:52:45.178790781Z","hostname":"w-01J8RSHJZQ5Z54Q36K202C5NZC","pid":1222,"session_id":"ac545a27-ae9c-4971-b2a8-23c2927da1c3"}
3132024-09-27T03:52:46.194Z{"msg":"Set Active after no reconciliation","v":0,"name":"crucible","level":30,"time":"2024-09-27T03:52:45.178803289Z","hostname":"w-01J8RSHJZQ5Z54Q36K202C5NZC","pid":1222,"session_id":"ac545a27-ae9c-4971-b2a8-23c2927da1c3"}
3142024-09-27T03:52:46.194Z{"msg":"The guest has finished waiting for activation with:32","v":0,"name":"crucible","level":30,"time":"2024-09-27T03:52:45.178821927Z","hostname":"w-01J8RSHJZQ5Z54Q36K202C5NZC","pid":1222}
3152024-09-27T03:52:46.194ZLoading write count information from file "/var/tmp/test_up-build/verify_file"
3162024-09-27T03:52:46.194ZRun Repair workload
3172024-09-27T03:52:46.194Z01/10 Write block 14 len 20480 data: 2 2 2 2 2
3182024-09-27T03:52:46.197Z02/10 Write block 40 len 16384 data: 2 2 2 2
3192024-09-27T03:52:46.197Z03/10 Write block 23 len 12288 data: 2 2 2
3202024-09-27T03:52:46.197Z04/10 Write block 17 len 24576 data: 3 3 2 2 2 2
3212024-09-27T03:52:46.197Z05/10 Read block 24 len 36864
3222024-09-27T03:52:46.197Z06/10 Read block 19 len 40960
3232024-09-27T03:52:46.199Z07/10 Read block 8 len 12288
3242024-09-27T03:52:46.199Z08/10 Read block 46 len 12288
3252024-09-27T03:52:46.199Z09/10 Read block 9 len 32768
3262024-09-27T03:52:46.202Z10/10 Write block 0 len 40960 data: 2 2 2 2 2 2 2 2 2 2
3272024-09-27T03:52:46.202Z----------------------------------------------------------------
3282024-09-27T03:52:46.202Z Crucible gen:32 GIO:true work queues: Upstairs:0 downstairs:10
3292024-09-27T03:52:46.202ZStates: Active Active Active
3302024-09-27T03:52:46.203ZGW_ID ACK DSID TYPE BKS/EXT DS:0 DS:1 DS:2 REPLAY
3312024-09-27T03:52:46.203Z 1 Acked 1000 Write 5 Done Done Done false
3322024-09-27T03:52:46.203Z 2 Acked 1001 Write 4 Done Done Done false
3332024-09-27T03:52:46.203Z 3 Acked 1002 Write 3 Done Done Done false
3342024-09-27T03:52:46.203Z 4 Acked 1003 Write 6 Done Done Done false
3352024-09-27T03:52:46.203Z 5 Acked 1004 Read 9 Done Done Done false
3362024-09-27T03:52:46.203Z 6 Acked 1005 Read 10 Done Done Done false
3372024-09-27T03:52:46.203Z 7 Acked 1006 Read 3 Done Done Done false
3382024-09-27T03:52:46.203Z 8 Acked 1007 Read 3 Done Done Done false
3392024-09-27T03:52:46.203Z 9 Acked 1008 Read 8 Done Done Done false
3402024-09-27T03:52:46.203Z 10 Acked 1009 Write 10 Sent Sent Sent false
3412024-09-27T03:52:46.203Z STATES DS:0 DS:1 DS:2 TOTAL
3422024-09-27T03:52:46.203Z Sent 1 1 1 3
3432024-09-27T03:52:46.203Z Done 9 9 9 27
3442024-09-27T03:52:46.203Z Skipped 0 0 0 0
3452024-09-27T03:52:46.203Z Error 0 0 0 0
3462024-09-27T03:52:46.203ZLast Flush: 0 0 0
3472024-09-27T03:52:46.203ZDownstairs last five completed:
3482024-09-27T03:52:46.203ZUpstairs last five completed: 10 9 8 7 6
3492024-09-27T03:52:46.203Z{"msg":"Guest handle has been dropped","v":0,"name":"crucible","level":40,"time":"2024-09-27T03:52:45.188365753Z","hostname":"w-01J8RSHJZQ5Z54Q36K202C5NZC","pid":1222}
3502024-09-27T03:52:46.203ZWrote out file "/var/tmp/test_up-build/verify_file"
3512024-09-27T03:52:46.209ZRepair part 1 passed
3522024-09-27T03:52:46.211Z
3532024-09-27T03:52:46.211ZKill the current downstairs
3542024-09-27T03:52:46.321Zrm -rf /var/tmp/test_up-build/8830
3552024-09-27T03:52:46.321ZNow put back the original so we have a mismatch
3562024-09-27T03:52:46.321Zmv /var/tmp/test_up-build/previous /var/tmp/test_up-build/8830
3572024-09-27T03:52:46.325ZRestart downstairs with old directory
3582024-09-27T03:52:46.385Z/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
3592024-09-27T03:52:46.404ZEXT BLOCKS GEN0 GEN1 GEN2 FL0 FL1 FL2 D0 D1 D2 DIFF
3602024-09-27T03:52:46.406Z 0 000-009 31 31 31 1534 1534 1534 T T F <---
3612024-09-27T03:52:46.406Z 1 010-019 31 31 31 1534 1534 1534 T T F <---
3622024-09-27T03:52:46.406Z 2 020-029 31 31 31 1534 1534 1534 T T F <---
3632024-09-27T03:52:46.406Z 3 030-039 31 31 31 1534 1534 1534 F F F
3642024-09-27T03:52:46.406Z 4 040-049 31 31 31 1534 1534 1534 T T F <---
3652024-09-27T03:52:46.406ZMax gen: 31, Max flush: 1534
3662024-09-27T03:52:46.406ZError: Difference in extent metadata found!
3672024-09-27T03:52:46.410Zdump test found error as expected
3682024-09-27T03:52:46.412Z
3692024-09-27T03:52:46.412Z
3702024-09-27T03:52:46.412Z/var/tmp/bins/crutest verify --range -g 33 -q --dsc 127.0.0.1:9998 --verify-out /var/tmp/test_up-build/verify_file --verify-in /var/tmp/test_up-build/verify_file
3712024-09-27T03:52:46.472Z{"msg":"use region info: RegionExtentInfo { block_size: 4096, blocks_per_extent: 10, extent_count: 5 }","v":0,"name":"crucible","level":30,"time":"2024-09-27T03:52:45.459294973Z","hostname":"w-01J8RSHJZQ5Z54Q36K202C5NZC","pid":1229,"task":"crutest"}
3722024-09-27T03:52:46.475Z{"msg":"dsc has 3 regions. This means 1 sub_volumes","v":0,"name":"crucible","level":30,"time":"2024-09-27T03:52:45.45994638Z","hostname":"w-01J8RSHJZQ5Z54Q36K202C5NZC","pid":1229,"task":"crutest"}
3732024-09-27T03:52:46.475Z{"msg":"SV 0 has targets: [127.0.0.1:8810, 127.0.0.1:8820, 127.0.0.1:8830]","v":0,"name":"crucible","level":30,"time":"2024-09-27T03:52:45.461720804Z","hostname":"w-01J8RSHJZQ5Z54Q36K202C5NZC","pid":1229,"task":"crutest"}
3742024-09-27T03:52:46.475Z{"msg":"Upstairs starts","v":0,"name":"crucible","level":30,"time":"2024-09-27T03:52:45.461953685Z","hostname":"w-01J8RSHJZQ5Z54Q36K202C5NZC","pid":1229}
3752024-09-27T03:52:46.475Z{"msg":"Crucible Version: BuildInfo {\n version: \"0.0.1\",\n git_sha: \"6901b9ee7172d672adc2780a2da758752eb0a2a4\",\n git_commit_timestamp: \"2024-09-27T03:30:33.000000000Z\",\n git_branch: \"alan/more-dsc-for-tests\",\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-27T03:52:45.461994239Z","hostname":"w-01J8RSHJZQ5Z54Q36K202C5NZC","pid":1229}
3762024-09-27T03:52:46.475Z{"msg":"Upstairs <-> Downstairs Message Version: 11","v":0,"name":"crucible","level":30,"time":"2024-09-27T03:52:45.462016706Z","hostname":"w-01J8RSHJZQ5Z54Q36K202C5NZC","pid":1229}
3772024-09-27T03:52:46.475Z{"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: false, database_read_version: 1, database_write_version: 1 }","v":0,"name":"crucible","level":30,"time":"2024-09-27T03:52:45.462032175Z","hostname":"w-01J8RSHJZQ5Z54Q36K202C5NZC","pid":1229}
3782024-09-27T03:52:46.477Z{"msg":"Crucible 3b8f19fc-ae3a-478b-9cc9-5f4f66ba8fc4 has session id: 75c0babe-c6b9-4052-917c-05db6726495d","v":0,"name":"crucible","level":30,"time":"2024-09-27T03:52:45.462506284Z","hostname":"w-01J8RSHJZQ5Z54Q36K202C5NZC","pid":1229,"session_id":"75c0babe-c6b9-4052-917c-05db6726495d"}
3792024-09-27T03:52:46.477Z{"msg":"Upstairs opts: Upstairs UUID: 3b8f19fc-ae3a-478b-9cc9-5f4f66ba8fc4, Targets: [127.0.0.1:8810, 127.0.0.1:8820, 127.0.0.1:8830], lossy: false, flush_timeout: None, key populated: false, 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-27T03:52:45.462557458Z","hostname":"w-01J8RSHJZQ5Z54Q36K202C5NZC","pid":1229,"session_id":"75c0babe-c6b9-4052-917c-05db6726495d"}
3802024-09-27T03:52:46.477Z{"msg":"Crucible stats registered with UUID: 3b8f19fc-ae3a-478b-9cc9-5f4f66ba8fc4","v":0,"name":"crucible","level":30,"time":"2024-09-27T03:52:45.462595603Z","hostname":"w-01J8RSHJZQ5Z54Q36K202C5NZC","pid":1229,"session_id":"75c0babe-c6b9-4052-917c-05db6726495d"}
3812024-09-27T03:52:46.511Z{"msg":"The guest has requested activation with gen:33","v":0,"name":"crucible","level":30,"time":"2024-09-27T03:52:45.498614171Z","hostname":"w-01J8RSHJZQ5Z54Q36K202C5NZC","pid":1229}
3822024-09-27T03:52:46.511Z{"msg":"3b8f19fc-ae3a-478b-9cc9-5f4f66ba8fc4 active request set","v":0,"name":"crucible","level":30,"time":"2024-09-27T03:52:45.49870214Z","hostname":"w-01J8RSHJZQ5Z54Q36K202C5NZC","pid":1229,"session_id":"75c0babe-c6b9-4052-917c-05db6726495d"}
3832024-09-27T03:52:46.511Z{"msg":"sending connect oneshot to client","v":0,"name":"crucible","level":30,"time":"2024-09-27T03:52:45.498739986Z","hostname":"w-01J8RSHJZQ5Z54Q36K202C5NZC","pid":1229,"client":"0","":"downstairs","session_id":"75c0babe-c6b9-4052-917c-05db6726495d"}
3842024-09-27T03:52:46.511Z{"msg":"client set_active_request while in New; waiting...","v":0,"name":"crucible","level":30,"time":"2024-09-27T03:52:45.498810786Z","hostname":"w-01J8RSHJZQ5Z54Q36K202C5NZC","pid":1229,"client":"0","":"downstairs","session_id":"75c0babe-c6b9-4052-917c-05db6726495d"}
3852024-09-27T03:52:46.514Z{"msg":"sending connect oneshot to client","v":0,"name":"crucible","level":30,"time":"2024-09-27T03:52:45.498846702Z","hostname":"w-01J8RSHJZQ5Z54Q36K202C5NZC","pid":1229,"client":"1","":"downstairs","session_id":"75c0babe-c6b9-4052-917c-05db6726495d"}
3862024-09-27T03:52:46.514Z{"msg":"client set_active_request while in New; waiting...","v":0,"name":"crucible","level":30,"time":"2024-09-27T03:52:45.498881118Z","hostname":"w-01J8RSHJZQ5Z54Q36K202C5NZC","pid":1229,"client":"1","":"downstairs","session_id":"75c0babe-c6b9-4052-917c-05db6726495d"}
3872024-09-27T03:52:46.514Z{"msg":"sending connect oneshot to client","v":0,"name":"crucible","level":30,"time":"2024-09-27T03:52:45.498925182Z","hostname":"w-01J8RSHJZQ5Z54Q36K202C5NZC","pid":1229,"client":"2","":"downstairs","session_id":"75c0babe-c6b9-4052-917c-05db6726495d"}
3882024-09-27T03:52:46.514Z{"msg":"client set_active_request while in New; waiting...","v":0,"name":"crucible","level":30,"time":"2024-09-27T03:52:45.498953908Z","hostname":"w-01J8RSHJZQ5Z54Q36K202C5NZC","pid":1229,"client":"2","":"downstairs","session_id":"75c0babe-c6b9-4052-917c-05db6726495d"}
3892024-09-27T03:52:46.514Z{"msg":"connecting to 127.0.0.1:8830","v":0,"name":"crucible","level":30,"time":"2024-09-27T03:52:45.498993123Z","hostname":"w-01J8RSHJZQ5Z54Q36K202C5NZC","pid":1229,"":"io task","client":"2","":"downstairs","session_id":"75c0babe-c6b9-4052-917c-05db6726495d"}
3902024-09-27T03:52:46.514Z{"msg":"connecting to 127.0.0.1:8820","v":0,"name":"crucible","level":30,"time":"2024-09-27T03:52:45.49902299Z","hostname":"w-01J8RSHJZQ5Z54Q36K202C5NZC","pid":1229,"":"io task","client":"1","":"downstairs","session_id":"75c0babe-c6b9-4052-917c-05db6726495d"}
3912024-09-27T03:52:46.514Z{"msg":"connecting to 127.0.0.1:8810","v":0,"name":"crucible","level":30,"time":"2024-09-27T03:52:45.499052486Z","hostname":"w-01J8RSHJZQ5Z54Q36K202C5NZC","pid":1229,"":"io task","client":"0","":"downstairs","session_id":"75c0babe-c6b9-4052-917c-05db6726495d"}
3922024-09-27T03:52:46.514Z{"msg":"ds_connection connected from Ok(127.0.0.1:59421)","v":0,"name":"crucible","level":30,"time":"2024-09-27T03:52:45.499085802Z","hostname":"w-01J8RSHJZQ5Z54Q36K202C5NZC","pid":1229,"":"io task","client":"0","":"downstairs","session_id":"75c0babe-c6b9-4052-917c-05db6726495d"}
3932024-09-27T03:52:46.514Z{"msg":"ds_connection connected from Ok(127.0.0.1:50496)","v":0,"name":"crucible","level":30,"time":"2024-09-27T03:52:45.499133905Z","hostname":"w-01J8RSHJZQ5Z54Q36K202C5NZC","pid":1229,"":"io task","client":"1","":"downstairs","session_id":"75c0babe-c6b9-4052-917c-05db6726495d"}
3942024-09-27T03:52:46.514Z{"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-27T03:52:45.499271008Z","hostname":"w-01J8RSHJZQ5Z54Q36K202C5NZC","pid":1229,"":"io task","client":"2","":"downstairs","session_id":"75c0babe-c6b9-4052-917c-05db6726495d"}
3952024-09-27T03:52:46.514Z{"msg":"client task is sending Done(ConnectionFailed(Os { code: 146, kind: ConnectionRefused, message: \"Connection refused\" }))","v":0,"name":"crucible","level":40,"time":"2024-09-27T03:52:45.499328261Z","hostname":"w-01J8RSHJZQ5Z54Q36K202C5NZC","pid":1229,"":"io task","client":"2","":"downstairs","session_id":"75c0babe-c6b9-4052-917c-05db6726495d"}
3962024-09-27T03:52:46.514Z{"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-27T03:52:45.499448425Z","hostname":"w-01J8RSHJZQ5Z54Q36K202C5NZC","pid":1229,"session_id":"75c0babe-c6b9-4052-917c-05db6726495d"}
3972024-09-27T03:52:46.514Z{"msg":"Gone missing, transition from New to Disconnected","v":0,"name":"crucible","level":30,"time":"2024-09-27T03:52:45.499482021Z","hostname":"w-01J8RSHJZQ5Z54Q36K202C5NZC","pid":1229,"client":"2","":"downstairs","session_id":"75c0babe-c6b9-4052-917c-05db6726495d"}
3982024-09-27T03:52:46.515Z{"msg":"Disconnected -> New","v":0,"name":"crucible","level":30,"time":"2024-09-27T03:52:45.499501039Z","hostname":"w-01J8RSHJZQ5Z54Q36K202C5NZC","pid":1229,"client":"2","":"downstairs","session_id":"75c0babe-c6b9-4052-917c-05db6726495d"}
3992024-09-27T03:52:46.515Z{"msg":"client task is exiting","v":0,"name":"crucible","level":30,"time":"2024-09-27T03:52:45.499588088Z","hostname":"w-01J8RSHJZQ5Z54Q36K202C5NZC","pid":1229,"":"io task","client":"2","":"downstairs","session_id":"75c0babe-c6b9-4052-917c-05db6726495d"}
4002024-09-27T03:52:46.515Z{"msg":"ds_transition from New to WaitActive","v":0,"name":"crucible","level":30,"time":"2024-09-27T03:52:45.499877231Z","hostname":"w-01J8RSHJZQ5Z54Q36K202C5NZC","pid":1229,"client":"0","":"downstairs","session_id":"75c0babe-c6b9-4052-917c-05db6726495d"}
4012024-09-27T03:52:46.515Z{"msg":"[0] Transition from New to WaitActive","v":0,"name":"crucible","level":30,"time":"2024-09-27T03:52:45.499911906Z","hostname":"w-01J8RSHJZQ5Z54Q36K202C5NZC","pid":1229,"client":"0","":"downstairs","session_id":"75c0babe-c6b9-4052-917c-05db6726495d"}
4022024-09-27T03:52:46.515Z{"msg":"ds_transition from New to WaitActive","v":0,"name":"crucible","level":30,"time":"2024-09-27T03:52:45.500024282Z","hostname":"w-01J8RSHJZQ5Z54Q36K202C5NZC","pid":1229,"client":"1","":"downstairs","session_id":"75c0babe-c6b9-4052-917c-05db6726495d"}
4032024-09-27T03:52:46.515Z{"msg":"[1] Transition from New to WaitActive","v":0,"name":"crucible","level":30,"time":"2024-09-27T03:52:45.500073546Z","hostname":"w-01J8RSHJZQ5Z54Q36K202C5NZC","pid":1229,"client":"1","":"downstairs","session_id":"75c0babe-c6b9-4052-917c-05db6726495d"}
4042024-09-27T03:52:46.515Z{"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-27T03:52:45.500394875Z","hostname":"w-01J8RSHJZQ5Z54Q36K202C5NZC","pid":1229,"client":"0","":"downstairs","session_id":"75c0babe-c6b9-4052-917c-05db6726495d"}
4052024-09-27T03:52:46.515Z{"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-27T03:52:45.500539717Z","hostname":"w-01J8RSHJZQ5Z54Q36K202C5NZC","pid":1229,"client":"1","":"downstairs","session_id":"75c0babe-c6b9-4052-917c-05db6726495d"}
4062024-09-27T03:52:46.515Z{"msg":"ds_transition from WaitActive to WaitQuorum","v":0,"name":"crucible","level":30,"time":"2024-09-27T03:52:45.500720914Z","hostname":"w-01J8RSHJZQ5Z54Q36K202C5NZC","pid":1229,"client":"0","":"downstairs","session_id":"75c0babe-c6b9-4052-917c-05db6726495d"}
4072024-09-27T03:52:46.515Z{"msg":"[0] Transition from WaitActive to WaitQuorum","v":0,"name":"crucible","level":30,"time":"2024-09-27T03:52:45.50075201Z","hostname":"w-01J8RSHJZQ5Z54Q36K202C5NZC","pid":1229,"client":"0","":"downstairs","session_id":"75c0babe-c6b9-4052-917c-05db6726495d"}
4082024-09-27T03:52:46.515Z{"msg":"Waiting for more clients to be ready","v":0,"name":"crucible","level":30,"time":"2024-09-27T03:52:45.500766928Z","hostname":"w-01J8RSHJZQ5Z54Q36K202C5NZC","pid":1229,"session_id":"75c0babe-c6b9-4052-917c-05db6726495d"}
4092024-09-27T03:52:46.515Z{"msg":"ds_transition from WaitActive to WaitQuorum","v":0,"name":"crucible","level":30,"time":"2024-09-27T03:52:45.500846298Z","hostname":"w-01J8RSHJZQ5Z54Q36K202C5NZC","pid":1229,"client":"1","":"downstairs","session_id":"75c0babe-c6b9-4052-917c-05db6726495d"}
4102024-09-27T03:52:46.515Z{"msg":"[1] Transition from WaitActive to WaitQuorum","v":0,"name":"crucible","level":30,"time":"2024-09-27T03:52:45.500872124Z","hostname":"w-01J8RSHJZQ5Z54Q36K202C5NZC","pid":1229,"client":"1","":"downstairs","session_id":"75c0babe-c6b9-4052-917c-05db6726495d"}
4112024-09-27T03:52:46.515Z{"msg":"Waiting for more clients to be ready","v":0,"name":"crucible","level":30,"time":"2024-09-27T03:52:45.500886913Z","hostname":"w-01J8RSHJZQ5Z54Q36K202C5NZC","pid":1229,"session_id":"75c0babe-c6b9-4052-917c-05db6726495d"}
4122024-09-27T03:52:56.514Z{"msg":"connecting to 127.0.0.1:8830","v":0,"name":"crucible","level":30,"time":"2024-09-27T03:52:55.500211609Z","hostname":"w-01J8RSHJZQ5Z54Q36K202C5NZC","pid":1229,"":"io task","client":"2","":"downstairs","session_id":"75c0babe-c6b9-4052-917c-05db6726495d"}
4132024-09-27T03:52:56.517Z{"msg":"ds_connection connected from Ok(127.0.0.1:62915)","v":0,"name":"crucible","level":30,"time":"2024-09-27T03:52:55.500333203Z","hostname":"w-01J8RSHJZQ5Z54Q36K202C5NZC","pid":1229,"":"io task","client":"2","":"downstairs","session_id":"75c0babe-c6b9-4052-917c-05db6726495d"}
4142024-09-27T03:52:56.517Z{"msg":"ds_transition from New to WaitActive","v":0,"name":"crucible","level":30,"time":"2024-09-27T03:52:55.501568316Z","hostname":"w-01J8RSHJZQ5Z54Q36K202C5NZC","pid":1229,"client":"2","":"downstairs","session_id":"75c0babe-c6b9-4052-917c-05db6726495d"}
4152024-09-27T03:52:56.517Z{"msg":"[2] Transition from New to WaitActive","v":0,"name":"crucible","level":30,"time":"2024-09-27T03:52:55.501601982Z","hostname":"w-01J8RSHJZQ5Z54Q36K202C5NZC","pid":1229,"client":"2","":"downstairs","session_id":"75c0babe-c6b9-4052-917c-05db6726495d"}
4162024-09-27T03:52:56.517Z{"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-27T03:52:55.502226472Z","hostname":"w-01J8RSHJZQ5Z54Q36K202C5NZC","pid":1229,"client":"2","":"downstairs","session_id":"75c0babe-c6b9-4052-917c-05db6726495d"}
4172024-09-27T03:52:56.517Z{"msg":"ds_transition from WaitActive to WaitQuorum","v":0,"name":"crucible","level":30,"time":"2024-09-27T03:52:55.502614923Z","hostname":"w-01J8RSHJZQ5Z54Q36K202C5NZC","pid":1229,"client":"2","":"downstairs","session_id":"75c0babe-c6b9-4052-917c-05db6726495d"}
4182024-09-27T03:52:56.517Z{"msg":"[2] Transition from WaitActive to WaitQuorum","v":0,"name":"crucible","level":30,"time":"2024-09-27T03:52:55.502645699Z","hostname":"w-01J8RSHJZQ5Z54Q36K202C5NZC","pid":1229,"client":"2","":"downstairs","session_id":"75c0babe-c6b9-4052-917c-05db6726495d"}
4192024-09-27T03:52:56.517Z{"msg":"[0]R flush_numbers: [1534, 1534, 1534, 1534, 1534]","v":0,"name":"crucible","level":30,"time":"2024-09-27T03:52:55.502660847Z","hostname":"w-01J8RSHJZQ5Z54Q36K202C5NZC","pid":1229,"":"downstairs","":"downstairs","session_id":"75c0babe-c6b9-4052-917c-05db6726495d"}
4202024-09-27T03:52:56.517Z{"msg":"[0]R generation: [31, 31, 31, 31, 31]","v":0,"name":"crucible","level":30,"time":"2024-09-27T03:52:55.502693343Z","hostname":"w-01J8RSHJZQ5Z54Q36K202C5NZC","pid":1229,"":"downstairs","":"downstairs","session_id":"75c0babe-c6b9-4052-917c-05db6726495d"}
4212024-09-27T03:52:56.517Z{"msg":"[0]R dirty: [true, true, true, false, true]","v":0,"name":"crucible","level":30,"time":"2024-09-27T03:52:55.502726999Z","hostname":"w-01J8RSHJZQ5Z54Q36K202C5NZC","pid":1229,"":"downstairs","":"downstairs","session_id":"75c0babe-c6b9-4052-917c-05db6726495d"}
4222024-09-27T03:52:56.517Z{"msg":"[1]R flush_numbers: [1534, 1534, 1534, 1534, 1534]","v":0,"name":"crucible","level":30,"time":"2024-09-27T03:52:55.502761054Z","hostname":"w-01J8RSHJZQ5Z54Q36K202C5NZC","pid":1229,"":"downstairs","":"downstairs","session_id":"75c0babe-c6b9-4052-917c-05db6726495d"}
4232024-09-27T03:52:56.517Z{"msg":"[1]R generation: [31, 31, 31, 31, 31]","v":0,"name":"crucible","level":30,"time":"2024-09-27T03:52:55.50279335Z","hostname":"w-01J8RSHJZQ5Z54Q36K202C5NZC","pid":1229,"":"downstairs","":"downstairs","session_id":"75c0babe-c6b9-4052-917c-05db6726495d"}
4242024-09-27T03:52:56.517Z{"msg":"[1]R dirty: [true, true, true, false, true]","v":0,"name":"crucible","level":30,"time":"2024-09-27T03:52:55.502818537Z","hostname":"w-01J8RSHJZQ5Z54Q36K202C5NZC","pid":1229,"":"downstairs","":"downstairs","session_id":"75c0babe-c6b9-4052-917c-05db6726495d"}
4252024-09-27T03:52:56.517Z{"msg":"[2]R flush_numbers: [1534, 1534, 1534, 1534, 1534]","v":0,"name":"crucible","level":30,"time":"2024-09-27T03:52:55.502849803Z","hostname":"w-01J8RSHJZQ5Z54Q36K202C5NZC","pid":1229,"":"downstairs","":"downstairs","session_id":"75c0babe-c6b9-4052-917c-05db6726495d"}
4262024-09-27T03:52:56.517Z{"msg":"[2]R generation: [31, 31, 31, 31, 31]","v":0,"name":"crucible","level":30,"time":"2024-09-27T03:52:55.502880749Z","hostname":"w-01J8RSHJZQ5Z54Q36K202C5NZC","pid":1229,"":"downstairs","":"downstairs","session_id":"75c0babe-c6b9-4052-917c-05db6726495d"}
4272024-09-27T03:52:56.521Z{"msg":"[2]R dirty: [false, false, false, false, false]","v":0,"name":"crucible","level":30,"time":"2024-09-27T03:52:55.502899507Z","hostname":"w-01J8RSHJZQ5Z54Q36K202C5NZC","pid":1229,"":"downstairs","":"downstairs","session_id":"75c0babe-c6b9-4052-917c-05db6726495d"}
4282024-09-27T03:52:56.521Z{"msg":"Max found gen is 32","v":0,"name":"crucible","level":30,"time":"2024-09-27T03:52:55.502928843Z","hostname":"w-01J8RSHJZQ5Z54Q36K202C5NZC","pid":1229,"":"downstairs","":"downstairs","session_id":"75c0babe-c6b9-4052-917c-05db6726495d"}
4292024-09-27T03:52:56.521Z{"msg":"Generation requested: 33 >= found:32","v":0,"name":"crucible","level":30,"time":"2024-09-27T03:52:55.50295038Z","hostname":"w-01J8RSHJZQ5Z54Q36K202C5NZC","pid":1229,"":"downstairs","":"downstairs","session_id":"75c0babe-c6b9-4052-917c-05db6726495d"}
4302024-09-27T03:52:56.521Z{"msg":"Next flush: 1535","v":0,"name":"crucible","level":30,"time":"2024-09-27T03:52:55.502981586Z","hostname":"w-01J8RSHJZQ5Z54Q36K202C5NZC","pid":1229,"":"downstairs","":"downstairs","session_id":"75c0babe-c6b9-4052-917c-05db6726495d"}
4312024-09-27T03:52:56.521Z{"msg":"Extents 0 dirty","v":0,"name":"crucible","level":30,"time":"2024-09-27T03:52:55.503000244Z","hostname":"w-01J8RSHJZQ5Z54Q36K202C5NZC","pid":1229,"":"mend","":"downstairs","":"downstairs","session_id":"75c0babe-c6b9-4052-917c-05db6726495d"}
4322024-09-27T03:52:56.521Z{"msg":"First source client ID for extent 0","v":0,"name":"crucible","level":30,"time":"2024-09-27T03:52:55.50303157Z","hostname":"w-01J8RSHJZQ5Z54Q36K202C5NZC","pid":1229,"mrl":"dirty","":"mend","":"downstairs","":"downstairs","session_id":"75c0babe-c6b9-4052-917c-05db6726495d"}
4332024-09-27T03:52:56.521Z{"msg":"extent:0 gens: 31 31 31","v":0,"name":"crucible","level":30,"time":"2024-09-27T03:52:55.503052617Z","hostname":"w-01J8RSHJZQ5Z54Q36K202C5NZC","pid":1229,"mrl":"dirty","":"mend","":"downstairs","":"downstairs","session_id":"75c0babe-c6b9-4052-917c-05db6726495d"}
4342024-09-27T03:52:56.521Z{"msg":"extent:0 flush: 1534 1534 1534 scs: [ClientId(0), ClientId(1), ClientId(2)]","v":0,"name":"crucible","level":30,"time":"2024-09-27T03:52:55.503083993Z","hostname":"w-01J8RSHJZQ5Z54Q36K202C5NZC","pid":1229,"mrl":"dirty","":"mend","":"downstairs","":"downstairs","session_id":"75c0babe-c6b9-4052-917c-05db6726495d"}
4352024-09-27T03:52:56.521Z{"msg":"max_flush now has: [ClientId(0), ClientId(1), ClientId(2)]","v":0,"name":"crucible","level":30,"time":"2024-09-27T03:52:55.503120739Z","hostname":"w-01J8RSHJZQ5Z54Q36K202C5NZC","pid":1229,"mrl":"dirty","":"mend","":"downstairs","":"downstairs","session_id":"75c0babe-c6b9-4052-917c-05db6726495d"}
4362024-09-27T03:52:56.521Z{"msg":"extent:0 dirty: true true false","v":0,"name":"crucible","level":30,"time":"2024-09-27T03:52:55.503146345Z","hostname":"w-01J8RSHJZQ5Z54Q36K202C5NZC","pid":1229,"mrl":"dirty","":"mend","":"downstairs","":"downstairs","session_id":"75c0babe-c6b9-4052-917c-05db6726495d"}
4372024-09-27T03:52:56.521Z{"msg":"find dest for source 0 for extent at index 0","v":0,"name":"crucible","level":30,"time":"2024-09-27T03:52:55.503181631Z","hostname":"w-01J8RSHJZQ5Z54Q36K202C5NZC","pid":1229,"mrl":"dirty","":"mend","":"downstairs","":"downstairs","session_id":"75c0babe-c6b9-4052-917c-05db6726495d"}
4382024-09-27T03:52:56.521Z{"msg":"source 0, add dest 1 source flush","v":0,"name":"crucible","level":30,"time":"2024-09-27T03:52:55.503209957Z","hostname":"w-01J8RSHJZQ5Z54Q36K202C5NZC","pid":1229,"mrl":"dirty","":"mend","":"downstairs","":"downstairs","session_id":"75c0babe-c6b9-4052-917c-05db6726495d"}
4392024-09-27T03:52:56.521Z{"msg":"source 0, add dest 2 source flush","v":0,"name":"crucible","level":30,"time":"2024-09-27T03:52:55.503253202Z","hostname":"w-01J8RSHJZQ5Z54Q36K202C5NZC","pid":1229,"mrl":"dirty","":"mend","":"downstairs","":"downstairs","session_id":"75c0babe-c6b9-4052-917c-05db6726495d"}
4402024-09-27T03:52:56.522Z{"msg":"Extents 1 dirty","v":0,"name":"crucible","level":30,"time":"2024-09-27T03:52:55.503294737Z","hostname":"w-01J8RSHJZQ5Z54Q36K202C5NZC","pid":1229,"":"mend","":"downstairs","":"downstairs","session_id":"75c0babe-c6b9-4052-917c-05db6726495d"}
4412024-09-27T03:52:56.522Z{"msg":"First source client ID for extent 1","v":0,"name":"crucible","level":30,"time":"2024-09-27T03:52:55.503325522Z","hostname":"w-01J8RSHJZQ5Z54Q36K202C5NZC","pid":1229,"mrl":"dirty","":"mend","":"downstairs","":"downstairs","session_id":"75c0babe-c6b9-4052-917c-05db6726495d"}
4422024-09-27T03:52:56.522Z{"msg":"extent:1 gens: 31 31 31","v":0,"name":"crucible","level":30,"time":"2024-09-27T03:52:55.503350679Z","hostname":"w-01J8RSHJZQ5Z54Q36K202C5NZC","pid":1229,"mrl":"dirty","":"mend","":"downstairs","":"downstairs","session_id":"75c0babe-c6b9-4052-917c-05db6726495d"}
4432024-09-27T03:52:56.522Z{"msg":"extent:1 flush: 1534 1534 1534 scs: [ClientId(0), ClientId(1), ClientId(2)]","v":0,"name":"crucible","level":30,"time":"2024-09-27T03:52:55.503384095Z","hostname":"w-01J8RSHJZQ5Z54Q36K202C5NZC","pid":1229,"mrl":"dirty","":"mend","":"downstairs","":"downstairs","session_id":"75c0babe-c6b9-4052-917c-05db6726495d"}
4442024-09-27T03:52:56.522Z{"msg":"max_flush now has: [ClientId(0), ClientId(1), ClientId(2)]","v":0,"name":"crucible","level":30,"time":"2024-09-27T03:52:55.503411362Z","hostname":"w-01J8RSHJZQ5Z54Q36K202C5NZC","pid":1229,"mrl":"dirty","":"mend","":"downstairs","":"downstairs","session_id":"75c0babe-c6b9-4052-917c-05db6726495d"}
4452024-09-27T03:52:56.522Z{"msg":"extent:1 dirty: true true false","v":0,"name":"crucible","level":30,"time":"2024-09-27T03:52:55.503444247Z","hostname":"w-01J8RSHJZQ5Z54Q36K202C5NZC","pid":1229,"mrl":"dirty","":"mend","":"downstairs","":"downstairs","session_id":"75c0babe-c6b9-4052-917c-05db6726495d"}
4462024-09-27T03:52:56.522Z{"msg":"find dest for source 0 for extent at index 1","v":0,"name":"crucible","level":30,"time":"2024-09-27T03:52:55.503470104Z","hostname":"w-01J8RSHJZQ5Z54Q36K202C5NZC","pid":1229,"mrl":"dirty","":"mend","":"downstairs","":"downstairs","session_id":"75c0babe-c6b9-4052-917c-05db6726495d"}
4472024-09-27T03:52:56.522Z{"msg":"source 0, add dest 1 source flush","v":0,"name":"crucible","level":30,"time":"2024-09-27T03:52:55.50349934Z","hostname":"w-01J8RSHJZQ5Z54Q36K202C5NZC","pid":1229,"mrl":"dirty","":"mend","":"downstairs","":"downstairs","session_id":"75c0babe-c6b9-4052-917c-05db6726495d"}
4482024-09-27T03:52:56.522Z{"msg":"source 0, add dest 2 source flush","v":0,"name":"crucible","level":30,"time":"2024-09-27T03:52:55.503526117Z","hostname":"w-01J8RSHJZQ5Z54Q36K202C5NZC","pid":1229,"mrl":"dirty","":"mend","":"downstairs","":"downstairs","session_id":"75c0babe-c6b9-4052-917c-05db6726495d"}
4492024-09-27T03:52:56.522Z{"msg":"Extents 2 dirty","v":0,"name":"crucible","level":30,"time":"2024-09-27T03:52:55.503552424Z","hostname":"w-01J8RSHJZQ5Z54Q36K202C5NZC","pid":1229,"":"mend","":"downstairs","":"downstairs","session_id":"75c0babe-c6b9-4052-917c-05db6726495d"}
4502024-09-27T03:52:56.522Z{"msg":"First source client ID for extent 2","v":0,"name":"crucible","level":30,"time":"2024-09-27T03:52:55.503588049Z","hostname":"w-01J8RSHJZQ5Z54Q36K202C5NZC","pid":1229,"mrl":"dirty","":"mend","":"downstairs","":"downstairs","session_id":"75c0babe-c6b9-4052-917c-05db6726495d"}
4512024-09-27T03:52:56.522Z{"msg":"extent:2 gens: 31 31 31","v":0,"name":"crucible","level":30,"time":"2024-09-27T03:52:55.503613566Z","hostname":"w-01J8RSHJZQ5Z54Q36K202C5NZC","pid":1229,"mrl":"dirty","":"mend","":"downstairs","":"downstairs","session_id":"75c0babe-c6b9-4052-917c-05db6726495d"}
4522024-09-27T03:52:56.522Z{"msg":"extent:2 flush: 1534 1534 1534 scs: [ClientId(0), ClientId(1), ClientId(2)]","v":0,"name":"crucible","level":30,"time":"2024-09-27T03:52:55.503639113Z","hostname":"w-01J8RSHJZQ5Z54Q36K202C5NZC","pid":1229,"mrl":"dirty","":"mend","":"downstairs","":"downstairs","session_id":"75c0babe-c6b9-4052-917c-05db6726495d"}
4532024-09-27T03:52:56.522Z{"msg":"max_flush now has: [ClientId(0), ClientId(1), ClientId(2)]","v":0,"name":"crucible","level":30,"time":"2024-09-27T03:52:55.503664499Z","hostname":"w-01J8RSHJZQ5Z54Q36K202C5NZC","pid":1229,"mrl":"dirty","":"mend","":"downstairs","":"downstairs","session_id":"75c0babe-c6b9-4052-917c-05db6726495d"}
4542024-09-27T03:52:56.522Z{"msg":"extent:2 dirty: true true false","v":0,"name":"crucible","level":30,"time":"2024-09-27T03:52:55.503695986Z","hostname":"w-01J8RSHJZQ5Z54Q36K202C5NZC","pid":1229,"mrl":"dirty","":"mend","":"downstairs","":"downstairs","session_id":"75c0babe-c6b9-4052-917c-05db6726495d"}
4552024-09-27T03:52:56.522Z{"msg":"find dest for source 0 for extent at index 2","v":0,"name":"crucible","level":30,"time":"2024-09-27T03:52:55.503723862Z","hostname":"w-01J8RSHJZQ5Z54Q36K202C5NZC","pid":1229,"mrl":"dirty","":"mend","":"downstairs","":"downstairs","session_id":"75c0babe-c6b9-4052-917c-05db6726495d"}
4562024-09-27T03:52:56.522Z{"msg":"source 0, add dest 1 source flush","v":0,"name":"crucible","level":30,"time":"2024-09-27T03:52:55.503753978Z","hostname":"w-01J8RSHJZQ5Z54Q36K202C5NZC","pid":1229,"mrl":"dirty","":"mend","":"downstairs","":"downstairs","session_id":"75c0babe-c6b9-4052-917c-05db6726495d"}
4572024-09-27T03:52:56.522Z{"msg":"source 0, add dest 2 source flush","v":0,"name":"crucible","level":30,"time":"2024-09-27T03:52:55.503779095Z","hostname":"w-01J8RSHJZQ5Z54Q36K202C5NZC","pid":1229,"mrl":"dirty","":"mend","":"downstairs","":"downstairs","session_id":"75c0babe-c6b9-4052-917c-05db6726495d"}
4582024-09-27T03:52:56.522Z{"msg":"Extents 4 dirty","v":0,"name":"crucible","level":30,"time":"2024-09-27T03:52:55.503812531Z","hostname":"w-01J8RSHJZQ5Z54Q36K202C5NZC","pid":1229,"":"mend","":"downstairs","":"downstairs","session_id":"75c0babe-c6b9-4052-917c-05db6726495d"}
4592024-09-27T03:52:56.522Z{"msg":"First source client ID for extent 4","v":0,"name":"crucible","level":30,"time":"2024-09-27T03:52:55.503837977Z","hostname":"w-01J8RSHJZQ5Z54Q36K202C5NZC","pid":1229,"mrl":"dirty","":"mend","":"downstairs","":"downstairs","session_id":"75c0babe-c6b9-4052-917c-05db6726495d"}
4602024-09-27T03:52:56.522Z{"msg":"extent:4 gens: 31 31 31","v":0,"name":"crucible","level":30,"time":"2024-09-27T03:52:55.503866194Z","hostname":"w-01J8RSHJZQ5Z54Q36K202C5NZC","pid":1229,"mrl":"dirty","":"mend","":"downstairs","":"downstairs","session_id":"75c0babe-c6b9-4052-917c-05db6726495d"}
4612024-09-27T03:52:56.522Z{"msg":"extent:4 flush: 1534 1534 1534 scs: [ClientId(0), ClientId(1), ClientId(2)]","v":0,"name":"crucible","level":30,"time":"2024-09-27T03:52:55.50389209Z","hostname":"w-01J8RSHJZQ5Z54Q36K202C5NZC","pid":1229,"mrl":"dirty","":"mend","":"downstairs","":"downstairs","session_id":"75c0babe-c6b9-4052-917c-05db6726495d"}
4622024-09-27T03:52:56.522Z{"msg":"max_flush now has: [ClientId(0), ClientId(1), ClientId(2)]","v":0,"name":"crucible","level":30,"time":"2024-09-27T03:52:55.503920117Z","hostname":"w-01J8RSHJZQ5Z54Q36K202C5NZC","pid":1229,"mrl":"dirty","":"mend","":"downstairs","":"downstairs","session_id":"75c0babe-c6b9-4052-917c-05db6726495d"}
4632024-09-27T03:52:56.522Z{"msg":"extent:4 dirty: true true false","v":0,"name":"crucible","level":30,"time":"2024-09-27T03:52:55.503944944Z","hostname":"w-01J8RSHJZQ5Z54Q36K202C5NZC","pid":1229,"mrl":"dirty","":"mend","":"downstairs","":"downstairs","session_id":"75c0babe-c6b9-4052-917c-05db6726495d"}
4642024-09-27T03:52:56.522Z{"msg":"find dest for source 0 for extent at index 4","v":0,"name":"crucible","level":30,"time":"2024-09-27T03:52:55.50397237Z","hostname":"w-01J8RSHJZQ5Z54Q36K202C5NZC","pid":1229,"mrl":"dirty","":"mend","":"downstairs","":"downstairs","session_id":"75c0babe-c6b9-4052-917c-05db6726495d"}
4652024-09-27T03:52:56.522Z{"msg":"source 0, add dest 1 source flush","v":0,"name":"crucible","level":30,"time":"2024-09-27T03:52:55.503998457Z","hostname":"w-01J8RSHJZQ5Z54Q36K202C5NZC","pid":1229,"mrl":"dirty","":"mend","":"downstairs","":"downstairs","session_id":"75c0babe-c6b9-4052-917c-05db6726495d"}
4662024-09-27T03:52:56.522Z{"msg":"source 0, add dest 2 source flush","v":0,"name":"crucible","level":30,"time":"2024-09-27T03:52:55.504031703Z","hostname":"w-01J8RSHJZQ5Z54Q36K202C5NZC","pid":1229,"mrl":"dirty","":"mend","":"downstairs","":"downstairs","session_id":"75c0babe-c6b9-4052-917c-05db6726495d"}
4672024-09-27T03:52:56.522Z{"msg":"Transition from WaitQuorum to Reconcile","v":0,"name":"crucible","level":30,"time":"2024-09-27T03:52:55.504067628Z","hostname":"w-01J8RSHJZQ5Z54Q36K202C5NZC","pid":1229,"client":"0","":"downstairs","session_id":"75c0babe-c6b9-4052-917c-05db6726495d"}
4682024-09-27T03:52:56.522Z{"msg":"Transition from WaitQuorum to Reconcile","v":0,"name":"crucible","level":30,"time":"2024-09-27T03:52:55.504099924Z","hostname":"w-01J8RSHJZQ5Z54Q36K202C5NZC","pid":1229,"client":"1","":"downstairs","session_id":"75c0babe-c6b9-4052-917c-05db6726495d"}
4692024-09-27T03:52:56.522Z{"msg":"Transition from WaitQuorum to Reconcile","v":0,"name":"crucible","level":30,"time":"2024-09-27T03:52:55.504126621Z","hostname":"w-01J8RSHJZQ5Z54Q36K202C5NZC","pid":1229,"client":"2","":"downstairs","session_id":"75c0babe-c6b9-4052-917c-05db6726495d"}
4702024-09-27T03:52:56.522Z{"msg":"starting reconciliation 06ac64bd-d7be-4039-a96f-70518a369452: found 4 extents that need repair","v":0,"name":"crucible","level":30,"time":"2024-09-27T03:52:55.504158097Z","hostname":"w-01J8RSHJZQ5Z54Q36K202C5NZC","pid":1229,"":"downstairs","":"downstairs","session_id":"75c0babe-c6b9-4052-917c-05db6726495d"}
4712024-09-27T03:52:56.522Z{"msg":"Full repair list: {ExtentId(0): ExtentFix { source: ClientId(0), dest: [ClientId(1), ClientId(2)] }, ExtentId(2): ExtentFix { source: ClientId(0), dest: [ClientId(1), ClientId(2)] }, ExtentId(4): ExtentFix { source: ClientId(0), dest: [ClientId(1), ClientId(2)] }, ExtentId(1): ExtentFix { source: ClientId(0), dest: [ClientId(1), ClientId(2)] }}","v":0,"name":"crucible","level":30,"time":"2024-09-27T03:52:55.504190612Z","hostname":"w-01J8RSHJZQ5Z54Q36K202C5NZC","pid":1229,"":"downstairs","":"downstairs","session_id":"75c0babe-c6b9-4052-917c-05db6726495d"}
4722024-09-27T03:52:56.522Z{"msg":"Task list: [ReconcileIO { id: ReconciliationId(0), op: ExtentFlush { repair_id: ReconciliationId(0), extent_id: ExtentId(0), client_id: ClientId(0), flush_number: 1535, gen_number: 32 }, state: ClientData([New, New, New]) }, ReconcileIO { id: ReconciliationId(1), op: ExtentClose { repair_id: ReconciliationId(1), extent_id: ExtentId(0) }, state: ClientData([New, New, New]) }, ReconcileIO { id: ReconciliationId(2), op: ExtentRepair { repair_id: ReconciliationId(2), extent_id: ExtentId(0), source_client_id: ClientId(0), source_repair_address: 0.0.0.0:12810, dest_clients: [ClientId(1), ClientId(2)] }, state: ClientData([New, New, New]) }, ReconcileIO { id: ReconciliationId(3), op: ExtentReopen { repair_id: ReconciliationId(3), extent_id: ExtentId(0) }, state: ClientData([New, New, New]) }, ReconcileIO { id: ReconciliationId(4), op: ExtentFlush { repair_id: ReconciliationId(4), extent_id: ExtentId(2), client_id: ClientId(0), flush_number: 1535, gen_number: 32 }, state: ClientData([New, New, New]) }, ReconcileIO { id: ReconciliationId(5), op: ExtentClose { repair_id: ReconciliationId(5), extent_id: ExtentId(2) }, state: ClientData([New, New, New]) }, ReconcileIO { id: ReconciliationId(6), op: ExtentRepair { repair_id: ReconciliationId(6), extent_id: ExtentId(2), source_client_id: ClientId(0), source_repair_address: 0.0.0.0:12810, dest_clients: [ClientId(1), ClientId(2)] }, state: ClientData([New, New, New]) }, ReconcileIO { id: ReconciliationId(7), op: ExtentReopen { repair_id: ReconciliationId(7), extent_id: ExtentId(2) }, state: ClientData([New, New, New]) }, ReconcileIO { id: ReconciliationId(8), op: ExtentFlush { repair_id: ReconciliationId(8), extent_id: ExtentId(4), client_id: ClientId(0), flush_number: 1535, 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]) }, ReconcileIO { id: ReconciliationId(12), op: ExtentFlush { repair_id: ReconciliationId(12), extent_id: ExtentId(1), client_id: ClientId(0), flush_number: 1535, gen_number: 32 }, state: ClientData([New, New, New]) }, ReconcileIO { id: ReconciliationId(13), op: ExtentClose { repair_id: ReconciliationId(13), extent_id: ExtentId(1) }, state: ClientData([New, New, New]) }, ReconcileIO { id: ReconciliationId(14), op: ExtentRepair { repair_id: ReconciliationId(14), extent_id: ExtentId(1), source_client_id: ClientId(0), source_repair_address: 0.0.0.0:12810, dest_clients: [ClientId(1), ClientId(2)] }, state: ClientData([New, New, New]) }, ReconcileIO { id: ReconciliationId(15), op: ExtentReopen { repair_id: ReconciliationId(15), extent_id: ExtentId(1) }, state: ClientData([New, New, New]) }]","v":0,"name":"crucible","level":30,"time":"2024-09-27T03:52:55.504316767Z","hostname":"w-01J8RSHJZQ5Z54Q36K202C5NZC","pid":1229,"":"downstairs","":"downstairs","session_id":"75c0babe-c6b9-4052-917c-05db6726495d"}
4732024-09-27T03:52:56.522Z{"msg":"no Nexus client from DNS, aborting start notification","v":0,"name":"crucible","level":50,"time":"2024-09-27T03:52:55.504349962Z","hostname":"w-01J8RSHJZQ5Z54Q36K202C5NZC","pid":1229,"reconcile":"06ac64bd-d7be-4039-a96f-70518a369452","":"downstairs","":"downstairs","session_id":"75c0babe-c6b9-4052-917c-05db6726495d"}
4742024-09-27T03:52:56.522Z{"msg":"no Nexus client from DNS, aborting progress notification","v":0,"name":"crucible","level":50,"time":"2024-09-27T03:52:55.504379679Z","hostname":"w-01J8RSHJZQ5Z54Q36K202C5NZC","pid":1229,"reconcile":"06ac64bd-d7be-4039-a96f-70518a369452","":"downstairs","":"downstairs","session_id":"75c0babe-c6b9-4052-917c-05db6726495d"}
4752024-09-27T03:52:56.522Z{"msg":"no Nexus client from DNS, aborting progress notification","v":0,"name":"crucible","level":50,"time":"2024-09-27T03:52:55.504429122Z","hostname":"w-01J8RSHJZQ5Z54Q36K202C5NZC","pid":1229,"reconcile":"06ac64bd-d7be-4039-a96f-70518a369452","":"downstairs","":"downstairs","session_id":"75c0babe-c6b9-4052-917c-05db6726495d"}
4762024-09-27T03:52:56.522Z{"msg":"sending reconcile request ReconciliationId(2)","v":0,"name":"crucible","level":30,"time":"2024-09-27T03:52:55.504750741Z","hostname":"w-01J8RSHJZQ5Z54Q36K202C5NZC","pid":1229,"client":"1","":"downstairs","session_id":"75c0babe-c6b9-4052-917c-05db6726495d"}
4772024-09-27T03:52:56.523Z{"msg":"sending reconcile request ReconciliationId(2)","v":0,"name":"crucible","level":30,"time":"2024-09-27T03:52:55.504780528Z","hostname":"w-01J8RSHJZQ5Z54Q36K202C5NZC","pid":1229,"client":"2","":"downstairs","session_id":"75c0babe-c6b9-4052-917c-05db6726495d"}
4782024-09-27T03:52:56.523Z{"msg":"no Nexus client from DNS, aborting progress notification","v":0,"name":"crucible","level":50,"time":"2024-09-27T03:52:55.504796985Z","hostname":"w-01J8RSHJZQ5Z54Q36K202C5NZC","pid":1229,"reconcile":"06ac64bd-d7be-4039-a96f-70518a369452","":"downstairs","":"downstairs","session_id":"75c0babe-c6b9-4052-917c-05db6726495d"}
4792024-09-27T03:52:56.533Z{"msg":"no Nexus client from DNS, aborting progress notification","v":0,"name":"crucible","level":50,"time":"2024-09-27T03:52:55.518843439Z","hostname":"w-01J8RSHJZQ5Z54Q36K202C5NZC","pid":1229,"reconcile":"06ac64bd-d7be-4039-a96f-70518a369452","":"downstairs","":"downstairs","session_id":"75c0babe-c6b9-4052-917c-05db6726495d"}
4802024-09-27T03:52:56.535Z{"msg":"no Nexus client from DNS, aborting progress notification","v":0,"name":"crucible","level":50,"time":"2024-09-27T03:52:55.519274754Z","hostname":"w-01J8RSHJZQ5Z54Q36K202C5NZC","pid":1229,"reconcile":"06ac64bd-d7be-4039-a96f-70518a369452","":"downstairs","":"downstairs","session_id":"75c0babe-c6b9-4052-917c-05db6726495d"}
4812024-09-27T03:52:56.535Z{"msg":"no Nexus client from DNS, aborting progress notification","v":0,"name":"crucible","level":50,"time":"2024-09-27T03:52:55.520413889Z","hostname":"w-01J8RSHJZQ5Z54Q36K202C5NZC","pid":1229,"reconcile":"06ac64bd-d7be-4039-a96f-70518a369452","":"downstairs","":"downstairs","session_id":"75c0babe-c6b9-4052-917c-05db6726495d"}
4822024-09-27T03:52:56.536Z{"msg":"sending reconcile request ReconciliationId(6)","v":0,"name":"crucible","level":30,"time":"2024-09-27T03:52:55.520738068Z","hostname":"w-01J8RSHJZQ5Z54Q36K202C5NZC","pid":1229,"client":"1","":"downstairs","session_id":"75c0babe-c6b9-4052-917c-05db6726495d"}
4832024-09-27T03:52:56.536Z{"msg":"sending reconcile request ReconciliationId(6)","v":0,"name":"crucible","level":30,"time":"2024-09-27T03:52:55.520778133Z","hostname":"w-01J8RSHJZQ5Z54Q36K202C5NZC","pid":1229,"client":"2","":"downstairs","session_id":"75c0babe-c6b9-4052-917c-05db6726495d"}
4842024-09-27T03:52:56.536Z{"msg":"no Nexus client from DNS, aborting progress notification","v":0,"name":"crucible","level":50,"time":"2024-09-27T03:52:55.52079546Z","hostname":"w-01J8RSHJZQ5Z54Q36K202C5NZC","pid":1229,"reconcile":"06ac64bd-d7be-4039-a96f-70518a369452","":"downstairs","":"downstairs","session_id":"75c0babe-c6b9-4052-917c-05db6726495d"}
4852024-09-27T03:52:56.544Z{"msg":"no Nexus client from DNS, aborting progress notification","v":0,"name":"crucible","level":50,"time":"2024-09-27T03:52:55.53000078Z","hostname":"w-01J8RSHJZQ5Z54Q36K202C5NZC","pid":1229,"reconcile":"06ac64bd-d7be-4039-a96f-70518a369452","":"downstairs","":"downstairs","session_id":"75c0babe-c6b9-4052-917c-05db6726495d"}
4862024-09-27T03:52:56.546Z{"msg":"no Nexus client from DNS, aborting progress notification","v":0,"name":"crucible","level":50,"time":"2024-09-27T03:52:55.530447953Z","hostname":"w-01J8RSHJZQ5Z54Q36K202C5NZC","pid":1229,"reconcile":"06ac64bd-d7be-4039-a96f-70518a369452","":"downstairs","":"downstairs","session_id":"75c0babe-c6b9-4052-917c-05db6726495d"}
4872024-09-27T03:52:56.546Z{"msg":"no Nexus client from DNS, aborting progress notification","v":0,"name":"crucible","level":50,"time":"2024-09-27T03:52:55.531975138Z","hostname":"w-01J8RSHJZQ5Z54Q36K202C5NZC","pid":1229,"reconcile":"06ac64bd-d7be-4039-a96f-70518a369452","":"downstairs","":"downstairs","session_id":"75c0babe-c6b9-4052-917c-05db6726495d"}
4882024-09-27T03:52:56.546Z{"msg":"sending reconcile request ReconciliationId(10)","v":0,"name":"crucible","level":30,"time":"2024-09-27T03:52:55.532327564Z","hostname":"w-01J8RSHJZQ5Z54Q36K202C5NZC","pid":1229,"client":"1","":"downstairs","session_id":"75c0babe-c6b9-4052-917c-05db6726495d"}
4892024-09-27T03:52:56.546Z{"msg":"sending reconcile request ReconciliationId(10)","v":0,"name":"crucible","level":30,"time":"2024-09-27T03:52:55.532360709Z","hostname":"w-01J8RSHJZQ5Z54Q36K202C5NZC","pid":1229,"client":"2","":"downstairs","session_id":"75c0babe-c6b9-4052-917c-05db6726495d"}
4902024-09-27T03:52:56.546Z{"msg":"no Nexus client from DNS, aborting progress notification","v":0,"name":"crucible","level":50,"time":"2024-09-27T03:52:55.532412933Z","hostname":"w-01J8RSHJZQ5Z54Q36K202C5NZC","pid":1229,"reconcile":"06ac64bd-d7be-4039-a96f-70518a369452","":"downstairs","":"downstairs","session_id":"75c0babe-c6b9-4052-917c-05db6726495d"}
4912024-09-27T03:52:56.555Z{"msg":"no Nexus client from DNS, aborting progress notification","v":0,"name":"crucible","level":50,"time":"2024-09-27T03:52:55.540707718Z","hostname":"w-01J8RSHJZQ5Z54Q36K202C5NZC","pid":1229,"reconcile":"06ac64bd-d7be-4039-a96f-70518a369452","":"downstairs","":"downstairs","session_id":"75c0babe-c6b9-4052-917c-05db6726495d"}
4922024-09-27T03:52:56.557Z{"msg":"no Nexus client from DNS, aborting progress notification","v":0,"name":"crucible","level":50,"time":"2024-09-27T03:52:55.541120155Z","hostname":"w-01J8RSHJZQ5Z54Q36K202C5NZC","pid":1229,"reconcile":"06ac64bd-d7be-4039-a96f-70518a369452","":"downstairs","":"downstairs","session_id":"75c0babe-c6b9-4052-917c-05db6726495d"}
4932024-09-27T03:52:56.557Z{"msg":"no Nexus client from DNS, aborting progress notification","v":0,"name":"crucible","level":50,"time":"2024-09-27T03:52:55.542144105Z","hostname":"w-01J8RSHJZQ5Z54Q36K202C5NZC","pid":1229,"reconcile":"06ac64bd-d7be-4039-a96f-70518a369452","":"downstairs","":"downstairs","session_id":"75c0babe-c6b9-4052-917c-05db6726495d"}
4942024-09-27T03:52:56.557Z{"msg":"sending reconcile request ReconciliationId(14)","v":0,"name":"crucible","level":30,"time":"2024-09-27T03:52:55.54249884Z","hostname":"w-01J8RSHJZQ5Z54Q36K202C5NZC","pid":1229,"client":"1","":"downstairs","session_id":"75c0babe-c6b9-4052-917c-05db6726495d"}
4952024-09-27T03:52:56.557Z{"msg":"sending reconcile request ReconciliationId(14)","v":0,"name":"crucible","level":30,"time":"2024-09-27T03:52:55.542547114Z","hostname":"w-01J8RSHJZQ5Z54Q36K202C5NZC","pid":1229,"client":"2","":"downstairs","session_id":"75c0babe-c6b9-4052-917c-05db6726495d"}
4962024-09-27T03:52:56.557Z{"msg":"no Nexus client from DNS, aborting progress notification","v":0,"name":"crucible","level":50,"time":"2024-09-27T03:52:55.542601767Z","hostname":"w-01J8RSHJZQ5Z54Q36K202C5NZC","pid":1229,"reconcile":"06ac64bd-d7be-4039-a96f-70518a369452","":"downstairs","":"downstairs","session_id":"75c0babe-c6b9-4052-917c-05db6726495d"}
4972024-09-27T03:52:56.565Z{"msg":"no Nexus client from DNS, aborting progress notification","v":0,"name":"crucible","level":50,"time":"2024-09-27T03:52:55.551109265Z","hostname":"w-01J8RSHJZQ5Z54Q36K202C5NZC","pid":1229,"reconcile":"06ac64bd-d7be-4039-a96f-70518a369452","":"downstairs","":"downstairs","session_id":"75c0babe-c6b9-4052-917c-05db6726495d"}
4982024-09-27T03:52:56.567Z{"msg":"done with reconciliation","v":0,"name":"crucible","level":30,"time":"2024-09-27T03:52:55.551471739Z","hostname":"w-01J8RSHJZQ5Z54Q36K202C5NZC","pid":1229,"":"downstairs","":"downstairs","session_id":"75c0babe-c6b9-4052-917c-05db6726495d"}
4992024-09-27T03:52:56.567Z{"msg":"Transition from Reconcile to Active","v":0,"name":"crucible","level":30,"time":"2024-09-27T03:52:55.551506894Z","hostname":"w-01J8RSHJZQ5Z54Q36K202C5NZC","pid":1229,"client":"0","":"downstairs","session_id":"75c0babe-c6b9-4052-917c-05db6726495d"}
5002024-09-27T03:52:56.567Z{"msg":"Transition from Reconcile to Active","v":0,"name":"crucible","level":30,"time":"2024-09-27T03:52:55.551522642Z","hostname":"w-01J8RSHJZQ5Z54Q36K202C5NZC","pid":1229,"client":"1","":"downstairs","session_id":"75c0babe-c6b9-4052-917c-05db6726495d"}
5012024-09-27T03:52:56.567Z{"msg":"Transition from Reconcile to Active","v":0,"name":"crucible","level":30,"time":"2024-09-27T03:52:55.55154408Z","hostname":"w-01J8RSHJZQ5Z54Q36K202C5NZC","pid":1229,"client":"2","":"downstairs","session_id":"75c0babe-c6b9-4052-917c-05db6726495d"}
5022024-09-27T03:52:56.567Z{"msg":"All required reconciliation work is completed","v":0,"name":"crucible","level":30,"time":"2024-09-27T03:52:55.551571106Z","hostname":"w-01J8RSHJZQ5Z54Q36K202C5NZC","pid":1229,"session_id":"75c0babe-c6b9-4052-917c-05db6726495d"}
5032024-09-27T03:52:56.567Z{"msg":"Set Downstairs and Upstairs active after reconciliation","v":0,"name":"crucible","level":30,"time":"2024-09-27T03:52:55.551585744Z","hostname":"w-01J8RSHJZQ5Z54Q36K202C5NZC","pid":1229,"session_id":"75c0babe-c6b9-4052-917c-05db6726495d"}
5042024-09-27T03:52:56.567Z{"msg":"3b8f19fc-ae3a-478b-9cc9-5f4f66ba8fc4 is now active with session: 75c0babe-c6b9-4052-917c-05db6726495d","v":0,"name":"crucible","level":30,"time":"2024-09-27T03:52:55.551606541Z","hostname":"w-01J8RSHJZQ5Z54Q36K202C5NZC","pid":1229,"session_id":"75c0babe-c6b9-4052-917c-05db6726495d"}
5052024-09-27T03:52:56.567Z{"msg":"The guest has finished waiting for activation with:33","v":0,"name":"crucible","level":30,"time":"2024-09-27T03:52:55.55161988Z","hostname":"w-01J8RSHJZQ5Z54Q36K202C5NZC","pid":1229}
5062024-09-27T03:52:56.567ZWait for a query_work_queue command to finish before sending IO
5072024-09-27T03:52:56.567Z{"msg":"no Nexus client from DNS, aborting finish notification","v":0,"name":"crucible","level":50,"time":"2024-09-27T03:52:55.551735115Z","hostname":"w-01J8RSHJZQ5Z54Q36K202C5NZC","pid":1229,"reconcile":"06ac64bd-d7be-4039-a96f-70518a369452","":"downstairs","":"downstairs","session_id":"75c0babe-c6b9-4052-917c-05db6726495d"}
5082024-09-27T03:52:56.567Zregion info:
5092024-09-27T03:52:56.567Z block size: 4096 bytes
5102024-09-27T03:52:56.568Z sub_volume 0 blocks / extent: 10
5112024-09-27T03:52:56.568Z sub_volume 0 extent size: 40 KiB
5122024-09-27T03:52:56.568Z sub_volume 0 extent count: 5
5132024-09-27T03:52:56.568Z total blocks: 50
5142024-09-27T03:52:56.568Z total size: 200 KiB
5152024-09-27T03:52:56.568Z encryption: no
5162024-09-27T03:52:56.568ZLoading write count information from file "/var/tmp/test_up-build/verify_file"
5172024-09-27T03:52:56.568ZRead and Verify all blocks (0..50 range:true)
5182024-09-27T03:52:56.573ZWrote out file "/var/tmp/test_up-build/verify_file"
5192024-09-27T03:52:56.573ZVerify test completed
5202024-09-27T03:52:56.575ZWrote out file "/var/tmp/test_up-build/verify_file"
5212024-09-27T03:52:56.575ZCLIENT: Tests done. All submitted work has been ACK'd
5222024-09-27T03:52:56.575Z----------------------------------------------------------------
5232024-09-27T03:52:56.575Z Crucible gen:33 GIO:true work queues: Upstairs:0 downstairs:1
5242024-09-27T03:52:56.575ZStates: Active Active Active
5252024-09-27T03:52:56.575ZGW_ID ACK DSID TYPE BKS/EXT DS:0 DS:1 DS:2 REPLAY
5262024-09-27T03:52:56.575Z 1 Acked 1000 Read 50 Done Done Done false
5272024-09-27T03:52:56.575Z STATES DS:0 DS:1 DS:2 TOTAL
5282024-09-27T03:52:56.575Z Sent 0 0 0 0
5292024-09-27T03:52:56.576Z Done 1 1 1 3
5302024-09-27T03:52:56.576Z Skipped 0 0 0 0
5312024-09-27T03:52:56.576Z Error 0 0 0 0
5322024-09-27T03:52:56.576ZLast Flush: 0 0 0
5332024-09-27T03:52:56.576ZDownstairs last five completed:
5342024-09-27T03:52:56.576ZUpstairs last five completed: 1
5352024-09-27T03:52:56.576ZCLIENT: Up:0 ds:1 act:3
5362024-09-27T03:53:00.576Z----------------------------------------------------------------
5372024-09-27T03:53:00.576Z Crucible gen:33 GIO:true work queues: Upstairs:0 downstairs:0
5382024-09-27T03:53:00.576ZDownstairs last five completed: 1001 1000
5392024-09-27T03:53:00.576ZUpstairs last five completed: 2 1
5402024-09-27T03:53:00.577ZCLIENT: Up:0 ds:0 act:3
5412024-09-27T03:53:00.577ZCLIENT: All crucible jobs finished, exiting program
5422024-09-27T03:53:00.579Z{"msg":"Guest handle has been dropped","v":0,"name":"crucible","level":40,"time":"2024-09-27T03:52:59.561538137Z","hostname":"w-01J8RSHJZQ5Z54Q36K202C5NZC","pid":1229}
5432024-09-27T03:53:00.584ZRepair part 2 passed
5442024-09-27T03:53:00.605Z/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
5452024-09-27T03:53:00.605ZEXT BLOCKS GEN0 GEN1 GEN2 FL0 FL1 FL2 D0 D1 D2 DIFF
5462024-09-27T03:53:00.605Z 0 000-009 32 32 32 1535 1535 1535 F F F
5472024-09-27T03:53:00.605Z 1 010-019 32 32 32 1535 1535 1535 F F F
5482024-09-27T03:53:00.605Z 2 020-029 32 32 32 1535 1535 1535 F F F
5492024-09-27T03:53:00.605Z 3 030-039 31 31 31 1534 1534 1534 F F F
5502024-09-27T03:53:00.605Z 4 040-049 32 32 32 1535 1535 1535 F F F
5512024-09-27T03:53:00.605ZMax gen: 32, Max flush: 1535
5522024-09-27T03:53:00.605Zdump test passed
5532024-09-27T03:53:00.605Z/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
5542024-09-27T03:53:00.619Z Extent 1
5552024-09-27T03:53:00.619ZGEN 32 32 32
5562024-09-27T03:53:00.619ZFLUSH_ID 1535 1535 1535
5572024-09-27T03:53:00.619ZDIRTY
5582024-09-27T03:53:00.619Z
5592024-09-27T03:53:00.627ZBLOCK D0 D1 D2 C0 C1 C2 DIFF
5602024-09-27T03:53:00.627Z010 A A A A A A
5612024-09-27T03:53:00.627Z011 A A A A A A
5622024-09-27T03:53:00.627Z012 A A A A A A
5632024-09-27T03:53:00.627Z013 A A A A A A
5642024-09-27T03:53:00.627Z014 A A A A A A
5652024-09-27T03:53:00.628Z015 A A A A A A
5662024-09-27T03:53:00.651Z016 A A A A A A
5672024-09-27T03:53:00.651Z017 A A A A A A
5682024-09-27T03:53:00.651Z018 A A A A A A
5692024-09-27T03:53:00.651Z019 A A A A A A
5702024-09-27T03:53:00.651Zdump extent test passed
5712024-09-27T03:53:00.651Z/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
5722024-09-27T03:53:00.651ZExtent 2 Block in extent 0 Actual block 20
5732024-09-27T03:53:00.651Z
5742024-09-27T03:53:00.651Z DATA SHA256 VER
5752024-09-27T03:53:00.651Z------ ---------------------------------------------------------------- ---
5762024-09-27T03:53:00.654Z 0 ad3d0e88276af7eb1f904413516e1a8c1f9c2fa8b17b86b2d842d08303e90aa2 A
5772024-09-27T03:53:00.654Z 1 ad3d0e88276af7eb1f904413516e1a8c1f9c2fa8b17b86b2d842d08303e90aa2 A
5782024-09-27T03:53:00.654Z 2 ad3d0e88276af7eb1f904413516e1a8c1f9c2fa8b17b86b2d842d08303e90aa2 A
5792024-09-27T03:53:00.655Z
5802024-09-27T03:53:00.655ZNONCES 0 1 2 DIFF
5812024-09-27T03:53:00.655Z------ ------------------------ ------------------------ ------------------------ -----
5822024-09-27T03:53:00.655Z
5832024-09-27T03:53:00.655Z TAGS 0 1 2 DIFF
5842024-09-27T03:53:00.655Z------ -------------------------------- -------------------------------- -------------------------------- -----
5852024-09-27T03:53:00.655Z
5862024-09-27T03:53:00.655ZHASHES 0 1 2 DIFF
5872024-09-27T03:53:00.655Z------ ---------------- ---------------- ---------------- -----
5882024-09-27T03:53:00.655Z 0 42916ab6fa364c70 42916ab6fa364c70 42916ab6fa364c70
5892024-09-27T03:53:00.655Z
5902024-09-27T03:53:00.668Zdump block test passed
5912024-09-27T03:53:00.668ZUpstairs tests have completed, stopping all downstairs
5922024-09-27T03:53:05.717ZCreating four larger downstairs regions
5932024-09-27T03:53:06.163ZStarting four downstairs
5942024-09-27T03:53:11.171ZNow do the replace-reconcile test
5952024-09-27T03:56:13.753ZCompleted test: replace-reconcile
5962024-09-27T03:56:13.756ZNow do the replace-before-active test
5972024-09-27T03:58:55.380ZCompleted test: replace-before-active
5982024-09-27T03:58:55.383ZTests have completed, stopping all downstairs
5992024-09-27T03:58:55.444Z
6002024-09-27T03:58:55.444ZAll Tests have passed
6012024-09-27T03:58:55.446Z8:17 Test duration
6022024-09-27T03:58:55.446Z
6032024-09-27T03:58:55.446Zreal 8:16.980952822
6042024-09-27T03:58:55.446Zuser 1:07.053773206
6052024-09-27T03:58:55.446Zsys 11.958022057
6062024-09-27T03:58:55.446Ztrap 0.178841061
6072024-09-27T03:58:55.446Ztflt 0.014175020
6082024-09-27T03:58:55.446Zdflt 0.053810792
6092024-09-27T03:58:55.446Zkflt 0.001730758
6102024-09-27T03:58:55.446Zlock 5:53:41.827080497
6112024-09-27T03:58:55.446Zslp 25:35.824692377
6122024-09-27T03:58:55.446Zlat 10.779465450
6132024-09-27T03:58:55.446Zstop 0.139645837
6142024-09-27T03:58:55.446Z+ echo 'test-up-unencrypted ends'
6152024-09-27T03:58:55.446Ztest-up-unencrypted ends
6162024-09-27T03:59:00.450Zprocess exited: duration 505145 ms, exit code 0
6172024-09-27T03:59:00.450Zexec warning: : stdio descriptors remain open after task exit; waiting 60 seconds for them to close
6182024-09-27T04:00:00.494Zexec warning: : stdout descriptor may be held open by a background process; giving up!
6192024-09-27T04:00:00.494Zexec warning: : stderr descriptor may be held open by a background process; giving up!
 
6202024-09-27T04:00:00.505Zfound 8 output files
6212024-09-27T04:00:00.505Zuploading: /tmp/debug/df.txt (1270 bytes)
6222024-09-27T04:00:01.514Zuploaded: /tmp/debug/df.txt
6232024-09-27T04:00:01.514Zuploading: /tmp/debug/dtrace.txt (495392 bytes)
6242024-09-27T04:00:02.539Zuploaded: /tmp/debug/dtrace.txt
6252024-09-27T04:00:02.541Zuploading: /tmp/debug/iostat.txt (170117 bytes)
6262024-09-27T04:00:02.555Zupload warning: file "/tmp/debug/iostat.txt" changed size mid upload: 170117 -> 170721
6272024-09-27T04:00:03.561Zuploaded: /tmp/debug/iostat.txt
6282024-09-27T04:00:03.563Zuploading: /tmp/debug/mpstat.txt (411556 bytes)
6292024-09-27T04:00:03.589Zupload warning: file "/tmp/debug/mpstat.txt" changed size mid upload: 411556 -> 413749
6302024-09-27T04:00:04.595Zuploaded: /tmp/debug/mpstat.txt
6312024-09-27T04:00:04.597Zuploading: /tmp/debug/paging.txt (74877 bytes)
6322024-09-27T04:00:04.605Zupload warning: file "/tmp/debug/paging.txt" changed size mid upload: 74877 -> 75345
6332024-09-27T04:00:05.611Zuploaded: /tmp/debug/paging.txt
6342024-09-27T04:00:05.614Zuploading: /tmp/debug/prstat.txt (777179 bytes)
6352024-09-27T04:00:05.648Zupload warning: file "/tmp/debug/prstat.txt" changed size mid upload: 777179 -> 783655
6362024-09-27T04:00:06.656Zuploaded: /tmp/debug/prstat.txt
6372024-09-27T04:00:06.656Zuploading: /tmp/debug/psrinfo.txt (1528 bytes)
6382024-09-27T04:00:07.664Zuploaded: /tmp/debug/psrinfo.txt
6392024-09-27T04:00:07.664Zuploading: /tmp/debug/upstairs-info.txt (76946 bytes)
6402024-09-27T04:00:08.680Zuploaded: /tmp/debug/upstairs-info.txt