01JH8G7RR2RT404TPPZKWCBMFC: test-up-encrypted

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

Buildomat Job: 01JH8G81G3DTSDKFT50370GJ5N

Tags:

Artefacts:

Output:

SEQ GLOBAL TIME DETAILS
12025-01-10T16:33:46.929Zjob dependencies complete; ready to run (waiting for 13 m 41 s)
22025-01-10T16:34:49.110Zjob assigned to worker 01JH8H16QRYG0ZMFS5DSD0AKB7 [factory aws, i-0f3bc212bc5dbff78] (queued for 1 m 2 s)
32025-01-10T16:34:57.269Zdownloading input: /input/build/work/bins/crucible-downstairs.gz
42025-01-10T16:34:58.382Zdownloaded input: /input/build/work/bins/crucible-downstairs.gz
52025-01-10T16:34:58.382Zdownloading input: /input/build/work/bins/crucible-hammer.gz
62025-01-10T16:34:59.451Zdownloaded input: /input/build/work/bins/crucible-hammer.gz
72025-01-10T16:34:59.452Zdownloading input: /input/build/work/bins/crutest.gz
82025-01-10T16:35:00.568Zdownloaded input: /input/build/work/bins/crutest.gz
92025-01-10T16:35:00.568Zdownloading input: /input/build/work/bins/dsc.gz
102025-01-10T16:35:01.255Zdownloaded input: /input/build/work/bins/dsc.gz
112025-01-10T16:35:01.276Zdownloading input: /input/build/work/scripts/perf-downstairs-tick.d
122025-01-10T16:35:01.288Zdownloaded input: /input/build/work/scripts/perf-downstairs-tick.d
132025-01-10T16:35:01.288Zdownloading input: /input/build/work/scripts/test_ds.sh
142025-01-10T16:35:01.312Zdownloaded input: /input/build/work/scripts/test_ds.sh
152025-01-10T16:35:01.312Zdownloading input: /input/build/work/scripts/test_live_repair.sh
162025-01-10T16:35:01.335Zdownloaded input: /input/build/work/scripts/test_live_repair.sh
172025-01-10T16:35:01.335Zdownloading input: /input/build/work/scripts/test_repair.sh
182025-01-10T16:35:01.356Zdownloaded input: /input/build/work/scripts/test_repair.sh
192025-01-10T16:35:01.356Zdownloading input: /input/build/work/scripts/test_replay.sh
202025-01-10T16:35:01.399Zdownloaded input: /input/build/work/scripts/test_replay.sh
212025-01-10T16:35:01.399Zdownloading input: /input/build/work/scripts/test_up.sh
222025-01-10T16:35:01.418Zdownloaded input: /input/build/work/scripts/test_up.sh
232025-01-10T16:35:01.418Zdownloading input: /input/build/work/scripts/upstairs_info.d
242025-01-10T16:35:01.437Zdownloaded input: /input/build/work/scripts/upstairs_info.d
252025-01-10T16:35:01.440Zdownloading input: /input/build/tmp/cargo-test-out.log
262025-01-10T16:35:02.165Zdownloaded input: /input/build/tmp/cargo-test-out.log
 
272025-01-10T16:35:02.165Zstarting task 0: "setup"
282025-01-10T16:35:02.172Z++ uname -s
292025-01-10T16:35:02.175Z+ kern=SunOS
302025-01-10T16:35:02.175Z+ case "$kern" in
312025-01-10T16:35:02.175Z+ groupadd -g 12345 build
322025-01-10T16:35:02.175Z+ useradd -u 12345 -g build -d /home/build -s /bin/bash -c build -P 'Primary Administrator' build
332025-01-10T16:35:04.181Z+ zfs create -o mountpoint=/work rpool/work
342025-01-10T16:35:04.279Z++ awk '$2 == "/home" { print $3 }' /etc/mnttab
352025-01-10T16:35:04.281Z+ home_fs=zfs
362025-01-10T16:35:04.281Z+ [[ zfs == autofs ]]
372025-01-10T16:35:04.281Z+ mkdir -p /home/build
382025-01-10T16:35:04.284Z+ chown build:build /home/build /work
392025-01-10T16:35:05.285Z+ chmod 0700 /home/build /work
402025-01-10T16:35:05.288Zprocess exited: duration 3133 ms, exit code 0
 
412025-01-10T16:35:05.294Zstarting task 1: "authentication"
422025-01-10T16:35:05.313Zprocess exited: duration 18 ms, exit code 0
 
432025-01-10T16:35:05.318Zstarting task 2: "build"
442025-01-10T16:35:05.324Z+ banner cores
452025-01-10T16:35:05.327Z
462025-01-10T16:35:05.328Z #### #### ##### ###### ####
472025-01-10T16:35:05.328Z # # # # # # # #
482025-01-10T16:35:05.328Z # # # # # ##### ####
492025-01-10T16:35:05.328Z # # # ##### # #
502025-01-10T16:35:05.328Z # # # # # # # # #
512025-01-10T16:35:05.328Z #### #### # # ###### ####
522025-01-10T16:35:05.328Z
532025-01-10T16:35:05.330Z+ pfexec coreadm -i /tmp/core.%f.%p -g /tmp/core.%f.%p -e global -e log -e proc-setid -e global-setid
542025-01-10T16:35:05.337Z+ echo 'input bins dir contains:'
552025-01-10T16:35:05.337Zinput bins dir contains:
562025-01-10T16:35:05.339Z+ ls -ltr /input/build/work/bins
572025-01-10T16:35:05.343Ztotal 762721
582025-01-10T16:35:05.343Z-rw-r--r-- 1 root root 109568203 Jan 10 16:34 crucible-downstairs.gz
592025-01-10T16:35:05.343Z-rw-r--r-- 1 root root 105130075 Jan 10 16:34 crucible-hammer.gz
602025-01-10T16:35:05.343Z-rw-r--r-- 1 root root 109591730 Jan 10 16:35 crutest.gz
612025-01-10T16:35:05.343Z-rw-r--r-- 1 root root 65965887 Jan 10 16:35 dsc.gz
622025-01-10T16:35:05.343Z+ banner unpack
632025-01-10T16:35:05.343Z
642025-01-10T16:35:05.343Z # # # # ##### ## #### # #
652025-01-10T16:35:05.343Z # # ## # # # # # # # # #
662025-01-10T16:35:05.343Z # # # # # # # # # # ####
672025-01-10T16:35:05.343Z # # # # # ##### ###### # # #
682025-01-10T16:35:05.343Z # # # ## # # # # # # #
692025-01-10T16:35:05.343Z #### # # # # # #### # #
702025-01-10T16:35:05.343Z
712025-01-10T16:35:05.343Z+ mkdir -p /var/tmp/bins
722025-01-10T16:35:05.346Z+ for t in "$input/bins/"*.gz
732025-01-10T16:35:05.355Z++ basename /input/build/work/bins/crucible-downstairs.gz
742025-01-10T16:35:05.355Z+ b=crucible-downstairs.gz
752025-01-10T16:35:05.356Z+ b=crucible-downstairs
762025-01-10T16:35:05.356Z+ gunzip
772025-01-10T16:35:07.619Z+ chmod +x /var/tmp/bins/crucible-downstairs
782025-01-10T16:35:07.622Z+ for t in "$input/bins/"*.gz
792025-01-10T16:35:07.625Z++ basename /input/build/work/bins/crucible-hammer.gz
802025-01-10T16:35:07.625Z+ b=crucible-hammer.gz
812025-01-10T16:35:07.625Z+ b=crucible-hammer
822025-01-10T16:35:07.625Z+ gunzip
832025-01-10T16:35:09.834Z+ chmod +x /var/tmp/bins/crucible-hammer
842025-01-10T16:35:09.837Z+ for t in "$input/bins/"*.gz
852025-01-10T16:35:09.839Z++ basename /input/build/work/bins/crutest.gz
862025-01-10T16:35:09.840Z+ b=crutest.gz
872025-01-10T16:35:09.840Z+ b=crutest
882025-01-10T16:35:09.840Z+ gunzip
892025-01-10T16:35:12.097Z+ chmod +x /var/tmp/bins/crutest
902025-01-10T16:35:12.100Z+ for t in "$input/bins/"*.gz
912025-01-10T16:35:12.102Z++ basename /input/build/work/bins/dsc.gz
922025-01-10T16:35:12.102Z+ b=dsc.gz
932025-01-10T16:35:12.102Z+ b=dsc
942025-01-10T16:35:12.102Z+ gunzip
952025-01-10T16:35:13.539Z+ chmod +x /var/tmp/bins/dsc
962025-01-10T16:35:13.542Z+ export BINDIR=/var/tmp/bins
972025-01-10T16:35:13.542Z+ BINDIR=/var/tmp/bins
982025-01-10T16:35:13.542Z+ jobpid=1144
992025-01-10T16:35:13.544Z+ echo 'Setup debug logging'
1002025-01-10T16:35:13.544ZSetup debug logging
1012025-01-10T16:35:13.544Z+ mkdir /tmp/debug
1022025-01-10T16:35:13.544Z+ sleep 3600
1032025-01-10T16:35:13.547Z+ psrinfo -v
1042025-01-10T16:35:13.549Z+ df -h
1052025-01-10T16:35:13.556Z+ prstat -d d -mLc 1
1062025-01-10T16:35:13.558Z+ iostat -T d -xn 1
1072025-01-10T16:35:13.558Z+ mpstat -T d 1
1082025-01-10T16:35:13.561Z+ vmstat -T d -p 1
1092025-01-10T16:35:13.561Z+ pfexec dtrace -Z -s /input/build/work/scripts/perf-downstairs-tick.d
1102025-01-10T16:35:13.561Z+ banner test_up_encrypted
1112025-01-10T16:35:13.561Z+ pfexec dtrace -Z -s /input/build/work/scripts/upstairs_info.d
1122025-01-10T16:35:13.564Z
1132025-01-10T16:35:13.564Z ##### ###### #### ##### # # ##### ###### # #
1142025-01-10T16:35:13.564Z # # # # # # # # # ## #
1152025-01-10T16:35:13.564Z # ##### #### # # # # # ##### # # #
1162025-01-10T16:35:13.564Z # # # # # # ##### # # # #
1172025-01-10T16:35:13.564Z # # # # # # # # # # ##
1182025-01-10T16:35:13.564Z # ###### #### # ####### #### # ####### ###### # #
1192025-01-10T16:35:13.564Z
1202025-01-10T16:35:13.564Z+ ptime -m bash /input/build/work/scripts/test_up.sh -N encrypted
1212025-01-10T16:35:13.574Z/input/build/work
1222025-01-10T16:35:13.587ZTurn off color for downstairs dump
1232025-01-10T16:35:13.603ZUpstairs using key: mXN1HeInmA+U7zxv5nOFK7rwa/XHBwx0albypllDS90=
1242025-01-10T16:35:13.605Zdsc output goes to /tmp/test_up-build/dsc-out.txt
1252025-01-10T16:35:13.605ZCreating 3 downstairs regions
1262025-01-10T16:35:13.935ZStarting 3 downstairs
1272025-01-10T16:35:13.938Zdsc started at PID: 1190
1282025-01-10T16:35:19.134ZDisable automatic restart on all downstairs
1292025-01-10T16:35:19.191Z
1302025-01-10T16:35:19.191ZBegin tests, output goes to /tmp/test_up-build/test_up_out.txt
1312025-01-10T16:35:19.195ZRunning test: span
1322025-01-10T16:35:23.346ZCompleted test: span
1332025-01-10T16:35:28.354ZRunning test: big
1342025-01-10T16:35:32.708ZCompleted test: big
1352025-01-10T16:35:37.716ZRunning test: dep
1362025-01-10T16:36:30.346ZCompleted test: dep
1372025-01-10T16:36:35.354ZRunning test: balloon
1382025-01-10T16:37:16.615ZCompleted test: balloon
1392025-01-10T16:37:21.623ZRunning test: deactivate
1402025-01-10T16:38:16.360ZCompleted test: deactivate
1412025-01-10T16:38:21.368ZRunning hammer
1422025-01-10T16:38:39.609ZRun repair tests
1432025-01-10T16:38:39.613Z/var/tmp/bins/crutest fill -g 31 -q --key mXN1HeInmA+U7zxv5nOFK7rwa/XHBwx0albypllDS90= --dsc 127.0.0.1:9998 --verify-out /var/tmp/test_up-build/verify_file
1442025-01-10T16:38:39.675Z{"msg":"Use this region info from dsc: RegionExtentInfo { block_size: 4096, blocks_per_extent: 10, extent_count: 5 }","v":0,"name":"crucible","level":30,"time":"2025-01-10T16:38:39.375321154Z","hostname":"w-01JH8H16QRYG0ZMFS5DSD0AKB7","pid":1227,"task":"crutest"}
1452025-01-10T16:38:39.677Z{"msg":"dsc has 3 regions. This means 1 sub_volumes","v":0,"name":"crucible","level":30,"time":"2025-01-10T16:38:39.376066158Z","hostname":"w-01JH8H16QRYG0ZMFS5DSD0AKB7","pid":1227,"task":"crutest"}
1462025-01-10T16:38:39.678Z{"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":"2025-01-10T16:38:39.377781682Z","hostname":"w-01JH8H16QRYG0ZMFS5DSD0AKB7","pid":1227,"task":"crutest"}
1472025-01-10T16:38:39.678Z{"msg":"Upstairs starts","v":0,"name":"crucible","level":30,"time":"2025-01-10T16:38:39.378012326Z","hostname":"w-01JH8H16QRYG0ZMFS5DSD0AKB7","pid":1227}
1482025-01-10T16:38:39.678Z{"msg":"Crucible Version: BuildInfo {\n version: \"0.0.1\",\n git_sha: \"56068760771d58f96ac946e6b2ae83073c18c1b4\",\n git_commit_timestamp: \"2025-01-10T16:19:36.000000000Z\",\n git_branch: \"alan/rust-1-84-please\",\n rustc_semver: \"1.84.0\",\n rustc_channel: \"stable\",\n rustc_host_triple: \"x86_64-unknown-illumos\",\n rustc_commit_sha: \"9fc6b43126469e3858e2fe86cafb4f0fd5068869\",\n cargo_triple: \"x86_64-unknown-illumos\",\n debug: true,\n opt_level: 0,\n}","v":0,"name":"crucible","level":30,"time":"2025-01-10T16:38:39.37805172Z","hostname":"w-01JH8H16QRYG0ZMFS5DSD0AKB7","pid":1227}
1492025-01-10T16:38:39.678Z{"msg":"Upstairs <-> Downstairs Message Version: 12","v":0,"name":"crucible","level":30,"time":"2025-01-10T16:38:39.378074786Z","hostname":"w-01JH8H16QRYG0ZMFS5DSD0AKB7","pid":1227}
1502025-01-10T16:38:39.678Z{"msg":"Using region definition RegionDefinition { block_size: 4096, extent_size: Block { value: 10, shift: 12 }, extent_count: 5, uuid: 00000000-0000-0000-0000-000000000000, encrypted: true, database_read_version: 1, database_write_version: 1 }","v":0,"name":"crucible","level":30,"time":"2025-01-10T16:38:39.378090483Z","hostname":"w-01JH8H16QRYG0ZMFS5DSD0AKB7","pid":1227}
1512025-01-10T16:38:39.680Z{"msg":"Crucible 04abb9f7-a39b-4813-992d-bc8943843398 has session id: 16b60670-b9a4-4ead-be42-82f8bee5ffc7","v":0,"name":"crucible","level":30,"time":"2025-01-10T16:38:39.378815031Z","hostname":"w-01JH8H16QRYG0ZMFS5DSD0AKB7","pid":1227,"session_id":"16b60670-b9a4-4ead-be42-82f8bee5ffc7"}
1522025-01-10T16:38:39.680Z{"msg":"Upstairs opts: Upstairs UUID: 04abb9f7-a39b-4813-992d-bc8943843398, Targets: [127.0.0.1:8810, 127.0.0.1:8820, 127.0.0.1:8830], lossy: false, flush_timeout: None, key populated: true, cert_pem populated: false, key_pem populated: false, root_cert_pem populated: false, Control: None, read_only: false","v":0,"name":"crucible","level":30,"time":"2025-01-10T16:38:39.378873242Z","hostname":"w-01JH8H16QRYG0ZMFS5DSD0AKB7","pid":1227,"session_id":"16b60670-b9a4-4ead-be42-82f8bee5ffc7"}
1532025-01-10T16:38:39.680Z{"msg":"Crucible stats registered with UUID: 04abb9f7-a39b-4813-992d-bc8943843398","v":0,"name":"crucible","level":30,"time":"2025-01-10T16:38:39.378891659Z","hostname":"w-01JH8H16QRYG0ZMFS5DSD0AKB7","pid":1227,"session_id":"16b60670-b9a4-4ead-be42-82f8bee5ffc7"}
1542025-01-10T16:38:39.712Z{"msg":"Downstairs in volume = 3","v":0,"name":"crucible","level":30,"time":"2025-01-10T16:38:39.412598553Z","hostname":"w-01JH8H16QRYG0ZMFS5DSD0AKB7","pid":1227,"task":"crutest"}
1552025-01-10T16:38:39.712Z{"msg":"The guest has requested activation with gen:31","v":0,"name":"crucible","level":30,"time":"2025-01-10T16:38:39.412674871Z","hostname":"w-01JH8H16QRYG0ZMFS5DSD0AKB7","pid":1227}
1562025-01-10T16:38:39.712Z{"msg":"04abb9f7-a39b-4813-992d-bc8943843398 active request set","v":0,"name":"crucible","level":30,"time":"2025-01-10T16:38:39.412696987Z","hostname":"w-01JH8H16QRYG0ZMFS5DSD0AKB7","pid":1227,"session_id":"16b60670-b9a4-4ead-be42-82f8bee5ffc7"}
1572025-01-10T16:38:39.712Z{"msg":"sending connect oneshot to client","v":0,"name":"crucible","level":30,"time":"2025-01-10T16:38:39.412715084Z","hostname":"w-01JH8H16QRYG0ZMFS5DSD0AKB7","pid":1227,"client":"0","":"downstairs","session_id":"16b60670-b9a4-4ead-be42-82f8bee5ffc7"}
1582025-01-10T16:38:39.712Z{"msg":"client set_active_request while in New; waiting...","v":0,"name":"crucible","level":30,"time":"2025-01-10T16:38:39.412777815Z","hostname":"w-01JH8H16QRYG0ZMFS5DSD0AKB7","pid":1227,"client":"0","":"downstairs","session_id":"16b60670-b9a4-4ead-be42-82f8bee5ffc7"}
1592025-01-10T16:38:39.716Z{"msg":"sending connect oneshot to client","v":0,"name":"crucible","level":30,"time":"2025-01-10T16:38:39.412814979Z","hostname":"w-01JH8H16QRYG0ZMFS5DSD0AKB7","pid":1227,"client":"1","":"downstairs","session_id":"16b60670-b9a4-4ead-be42-82f8bee5ffc7"}
1602025-01-10T16:38:39.716Z{"msg":"client set_active_request while in New; waiting...","v":0,"name":"crucible","level":30,"time":"2025-01-10T16:38:39.412850054Z","hostname":"w-01JH8H16QRYG0ZMFS5DSD0AKB7","pid":1227,"client":"1","":"downstairs","session_id":"16b60670-b9a4-4ead-be42-82f8bee5ffc7"}
1612025-01-10T16:38:39.716Z{"msg":"sending connect oneshot to client","v":0,"name":"crucible","level":30,"time":"2025-01-10T16:38:39.412879169Z","hostname":"w-01JH8H16QRYG0ZMFS5DSD0AKB7","pid":1227,"client":"2","":"downstairs","session_id":"16b60670-b9a4-4ead-be42-82f8bee5ffc7"}
1622025-01-10T16:38:39.716Z{"msg":"client set_active_request while in New; waiting...","v":0,"name":"crucible","level":30,"time":"2025-01-10T16:38:39.412920392Z","hostname":"w-01JH8H16QRYG0ZMFS5DSD0AKB7","pid":1227,"client":"2","":"downstairs","session_id":"16b60670-b9a4-4ead-be42-82f8bee5ffc7"}
1632025-01-10T16:38:39.716Z{"msg":"connecting to 127.0.0.1:8830","v":0,"name":"crucible","level":30,"time":"2025-01-10T16:38:39.412948928Z","hostname":"w-01JH8H16QRYG0ZMFS5DSD0AKB7","pid":1227,"":"io task","client":"2","":"downstairs","session_id":"16b60670-b9a4-4ead-be42-82f8bee5ffc7"}
1642025-01-10T16:38:39.716Z{"msg":"connecting to 127.0.0.1:8810","v":0,"name":"crucible","level":30,"time":"2025-01-10T16:38:39.412979873Z","hostname":"w-01JH8H16QRYG0ZMFS5DSD0AKB7","pid":1227,"":"io task","client":"0","":"downstairs","session_id":"16b60670-b9a4-4ead-be42-82f8bee5ffc7"}
1652025-01-10T16:38:39.716Z{"msg":"connecting to 127.0.0.1:8820","v":0,"name":"crucible","level":30,"time":"2025-01-10T16:38:39.413051542Z","hostname":"w-01JH8H16QRYG0ZMFS5DSD0AKB7","pid":1227,"":"io task","client":"1","":"downstairs","session_id":"16b60670-b9a4-4ead-be42-82f8bee5ffc7"}
1662025-01-10T16:38:39.716Z{"msg":"ds_connection connected from Ok(127.0.0.1:59148)","v":0,"name":"crucible","level":30,"time":"2025-01-10T16:38:39.413091816Z","hostname":"w-01JH8H16QRYG0ZMFS5DSD0AKB7","pid":1227,"":"io task","client":"1","":"downstairs","session_id":"16b60670-b9a4-4ead-be42-82f8bee5ffc7"}
1672025-01-10T16:38:39.716Z{"msg":"ds_connection connected from Ok(127.0.0.1:50998)","v":0,"name":"crucible","level":30,"time":"2025-01-10T16:38:39.413476116Z","hostname":"w-01JH8H16QRYG0ZMFS5DSD0AKB7","pid":1227,"":"io task","client":"2","":"downstairs","session_id":"16b60670-b9a4-4ead-be42-82f8bee5ffc7"}
1682025-01-10T16:38:39.716Z{"msg":"ds_connection connected from Ok(127.0.0.1:50473)","v":0,"name":"crucible","level":30,"time":"2025-01-10T16:38:39.413531828Z","hostname":"w-01JH8H16QRYG0ZMFS5DSD0AKB7","pid":1227,"":"io task","client":"0","":"downstairs","session_id":"16b60670-b9a4-4ead-be42-82f8bee5ffc7"}
1692025-01-10T16:38:39.716Z{"msg":"ds_transition from New to WaitActive","v":0,"name":"crucible","level":30,"time":"2025-01-10T16:38:39.413935565Z","hostname":"w-01JH8H16QRYG0ZMFS5DSD0AKB7","pid":1227,"client":"1","":"downstairs","session_id":"16b60670-b9a4-4ead-be42-82f8bee5ffc7"}
1702025-01-10T16:38:39.716Z{"msg":"[1] Transition from New to WaitActive","v":0,"name":"crucible","level":30,"time":"2025-01-10T16:38:39.413985307Z","hostname":"w-01JH8H16QRYG0ZMFS5DSD0AKB7","pid":1227,"client":"1","":"downstairs","session_id":"16b60670-b9a4-4ead-be42-82f8bee5ffc7"}
1712025-01-10T16:38:39.716Z{"msg":"ds_transition from New to WaitActive","v":0,"name":"crucible","level":30,"time":"2025-01-10T16:38:39.414126995Z","hostname":"w-01JH8H16QRYG0ZMFS5DSD0AKB7","pid":1227,"client":"2","":"downstairs","session_id":"16b60670-b9a4-4ead-be42-82f8bee5ffc7"}
1722025-01-10T16:38:39.716Z{"msg":"[2] Transition from New to WaitActive","v":0,"name":"crucible","level":30,"time":"2025-01-10T16:38:39.414184326Z","hostname":"w-01JH8H16QRYG0ZMFS5DSD0AKB7","pid":1227,"client":"2","":"downstairs","session_id":"16b60670-b9a4-4ead-be42-82f8bee5ffc7"}
1732025-01-10T16:38:39.716Z{"msg":"ds_transition from New to WaitActive","v":0,"name":"crucible","level":30,"time":"2025-01-10T16:38:39.414212762Z","hostname":"w-01JH8H16QRYG0ZMFS5DSD0AKB7","pid":1227,"client":"0","":"downstairs","session_id":"16b60670-b9a4-4ead-be42-82f8bee5ffc7"}
1742025-01-10T16:38:39.716Z{"msg":"[0] Transition from New to WaitActive","v":0,"name":"crucible","level":30,"time":"2025-01-10T16:38:39.414241097Z","hostname":"w-01JH8H16QRYG0ZMFS5DSD0AKB7","pid":1227,"client":"0","":"downstairs","session_id":"16b60670-b9a4-4ead-be42-82f8bee5ffc7"}
1752025-01-10T16:38:39.716Z{"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":"2025-01-10T16:38:39.414559008Z","hostname":"w-01JH8H16QRYG0ZMFS5DSD0AKB7","pid":1227,"client":"1","":"downstairs","session_id":"16b60670-b9a4-4ead-be42-82f8bee5ffc7"}
1762025-01-10T16:38:39.716Z{"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":"2025-01-10T16:38:39.414686448Z","hostname":"w-01JH8H16QRYG0ZMFS5DSD0AKB7","pid":1227,"client":"0","":"downstairs","session_id":"16b60670-b9a4-4ead-be42-82f8bee5ffc7"}
1772025-01-10T16:38:39.716Z{"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":"2025-01-10T16:38:39.414715764Z","hostname":"w-01JH8H16QRYG0ZMFS5DSD0AKB7","pid":1227,"client":"2","":"downstairs","session_id":"16b60670-b9a4-4ead-be42-82f8bee5ffc7"}
1782025-01-10T16:38:39.717Z{"msg":"ds_transition from WaitActive to WaitQuorum","v":0,"name":"crucible","level":30,"time":"2025-01-10T16:38:39.41493517Z","hostname":"w-01JH8H16QRYG0ZMFS5DSD0AKB7","pid":1227,"client":"1","":"downstairs","session_id":"16b60670-b9a4-4ead-be42-82f8bee5ffc7"}
1792025-01-10T16:38:39.717Z{"msg":"[1] Transition from WaitActive to WaitQuorum","v":0,"name":"crucible","level":30,"time":"2025-01-10T16:38:39.414984962Z","hostname":"w-01JH8H16QRYG0ZMFS5DSD0AKB7","pid":1227,"client":"1","":"downstairs","session_id":"16b60670-b9a4-4ead-be42-82f8bee5ffc7"}
1802025-01-10T16:38:39.717Z{"msg":"Waiting for more clients to be ready","v":0,"name":"crucible","level":30,"time":"2025-01-10T16:38:39.415036724Z","hostname":"w-01JH8H16QRYG0ZMFS5DSD0AKB7","pid":1227,"session_id":"16b60670-b9a4-4ead-be42-82f8bee5ffc7"}
1812025-01-10T16:38:39.717Z{"msg":"ds_transition from WaitActive to WaitQuorum","v":0,"name":"crucible","level":30,"time":"2025-01-10T16:38:39.415068179Z","hostname":"w-01JH8H16QRYG0ZMFS5DSD0AKB7","pid":1227,"client":"2","":"downstairs","session_id":"16b60670-b9a4-4ead-be42-82f8bee5ffc7"}
1822025-01-10T16:38:39.717Z{"msg":"[2] Transition from WaitActive to WaitQuorum","v":0,"name":"crucible","level":30,"time":"2025-01-10T16:38:39.415097214Z","hostname":"w-01JH8H16QRYG0ZMFS5DSD0AKB7","pid":1227,"client":"2","":"downstairs","session_id":"16b60670-b9a4-4ead-be42-82f8bee5ffc7"}
1832025-01-10T16:38:39.717Z{"msg":"Waiting for more clients to be ready","v":0,"name":"crucible","level":30,"time":"2025-01-10T16:38:39.415111762Z","hostname":"w-01JH8H16QRYG0ZMFS5DSD0AKB7","pid":1227,"session_id":"16b60670-b9a4-4ead-be42-82f8bee5ffc7"}
1842025-01-10T16:38:39.717Z{"msg":"ds_transition from WaitActive to WaitQuorum","v":0,"name":"crucible","level":30,"time":"2025-01-10T16:38:39.41512555Z","hostname":"w-01JH8H16QRYG0ZMFS5DSD0AKB7","pid":1227,"client":"0","":"downstairs","session_id":"16b60670-b9a4-4ead-be42-82f8bee5ffc7"}
1852025-01-10T16:38:39.717Z{"msg":"[0] Transition from WaitActive to WaitQuorum","v":0,"name":"crucible","level":30,"time":"2025-01-10T16:38:39.415154885Z","hostname":"w-01JH8H16QRYG0ZMFS5DSD0AKB7","pid":1227,"client":"0","":"downstairs","session_id":"16b60670-b9a4-4ead-be42-82f8bee5ffc7"}
1862025-01-10T16:38:39.717Z{"msg":"[0]R flush_numbers: [1494, 1494, 1494, 1494, 1494]","v":0,"name":"crucible","level":30,"time":"2025-01-10T16:38:39.415169623Z","hostname":"w-01JH8H16QRYG0ZMFS5DSD0AKB7","pid":1227,"":"downstairs","":"downstairs","session_id":"16b60670-b9a4-4ead-be42-82f8bee5ffc7"}
1872025-01-10T16:38:39.717Z{"msg":"[0]R generation: [25, 25, 25, 25, 25]","v":0,"name":"crucible","level":30,"time":"2025-01-10T16:38:39.415199838Z","hostname":"w-01JH8H16QRYG0ZMFS5DSD0AKB7","pid":1227,"":"downstairs","":"downstairs","session_id":"16b60670-b9a4-4ead-be42-82f8bee5ffc7"}
1882025-01-10T16:38:39.717Z{"msg":"[0]R dirty: [false, false, false, false, false]","v":0,"name":"crucible","level":30,"time":"2025-01-10T16:38:39.415215326Z","hostname":"w-01JH8H16QRYG0ZMFS5DSD0AKB7","pid":1227,"":"downstairs","":"downstairs","session_id":"16b60670-b9a4-4ead-be42-82f8bee5ffc7"}
1892025-01-10T16:38:39.717Z{"msg":"[1]R flush_numbers: [1494, 1494, 1494, 1494, 1494]","v":0,"name":"crucible","level":30,"time":"2025-01-10T16:38:39.415245161Z","hostname":"w-01JH8H16QRYG0ZMFS5DSD0AKB7","pid":1227,"":"downstairs","":"downstairs","session_id":"16b60670-b9a4-4ead-be42-82f8bee5ffc7"}
1902025-01-10T16:38:39.717Z{"msg":"[1]R generation: [25, 25, 25, 25, 25]","v":0,"name":"crucible","level":30,"time":"2025-01-10T16:38:39.415260769Z","hostname":"w-01JH8H16QRYG0ZMFS5DSD0AKB7","pid":1227,"":"downstairs","":"downstairs","session_id":"16b60670-b9a4-4ead-be42-82f8bee5ffc7"}
1912025-01-10T16:38:39.717Z{"msg":"[1]R dirty: [false, false, false, false, false]","v":0,"name":"crucible","level":30,"time":"2025-01-10T16:38:39.415291974Z","hostname":"w-01JH8H16QRYG0ZMFS5DSD0AKB7","pid":1227,"":"downstairs","":"downstairs","session_id":"16b60670-b9a4-4ead-be42-82f8bee5ffc7"}
1922025-01-10T16:38:39.717Z{"msg":"[2]R flush_numbers: [1494, 1494, 1494, 1494, 1494]","v":0,"name":"crucible","level":30,"time":"2025-01-10T16:38:39.415306662Z","hostname":"w-01JH8H16QRYG0ZMFS5DSD0AKB7","pid":1227,"":"downstairs","":"downstairs","session_id":"16b60670-b9a4-4ead-be42-82f8bee5ffc7"}
1932025-01-10T16:38:39.717Z{"msg":"[2]R generation: [25, 25, 25, 25, 25]","v":0,"name":"crucible","level":30,"time":"2025-01-10T16:38:39.415336317Z","hostname":"w-01JH8H16QRYG0ZMFS5DSD0AKB7","pid":1227,"":"downstairs","":"downstairs","session_id":"16b60670-b9a4-4ead-be42-82f8bee5ffc7"}
1942025-01-10T16:38:39.717Z{"msg":"[2]R dirty: [false, false, false, false, false]","v":0,"name":"crucible","level":30,"time":"2025-01-10T16:38:39.415351235Z","hostname":"w-01JH8H16QRYG0ZMFS5DSD0AKB7","pid":1227,"":"downstairs","":"downstairs","session_id":"16b60670-b9a4-4ead-be42-82f8bee5ffc7"}
1952025-01-10T16:38:39.717Z{"msg":"Max found gen is 26","v":0,"name":"crucible","level":30Wait for a query_work_queue command to finish before sending IO
1962025-01-10T16:38:39.717Z,"time":"2025-01-10T16:38:39.41538227Z","hostname":"w-01JH8H16QRYG0ZMFS5DSD0AKB7","pid":1227,"":"downstairs","":"downstairs","session_id":"16b60670-b9a4-4ead-be42-82f8bee5ffc7"}
1972025-01-10T16:38:39.717Z{"msg":"Generation requested: 31 >= found:26","v":0,"name":"crucible","level":30,"time":"2025-01-10T16:38:39.415401767Z","hostname":"w-01JH8H16QRYG0ZMFS5DSD0AKB7","pid":1227,"":"downstairs","":"downstairs","session_id":"16b60670-b9a4-4ead-be42-82f8bee5ffc7"}
1982025-01-10T16:38:39.717Z{"msg":"Next flush: 1495","v":0,"name":"crucible","level":30,"time":"2025-01-10T16:38:39.415431442Z","hostname":"w-01JH8H16QRYG0ZMFS5DSD0AKB7","pid":1227,"":"downstairs","":"downstairs","session_id":"16b60670-b9a4-4ead-be42-82f8bee5ffc7"}
1992025-01-10T16:38:39.717Z{"msg":"All extents match","v":0,"name":"crucible","level":30,"time":"2025-01-10T16:38:39.41544557Z","hostname":"w-01JH8H16QRYG0ZMFS5DSD0AKB7","pid":1227,"":"downstairs","":"downstairs","session_id":"16b60670-b9a4-4ead-be42-82f8bee5ffc7"}
2002025-01-10T16:38:39.717Z{"msg":"No downstairs reconciliation required","v":0,"name":"crucible","level":30,"time":"2025-01-10T16:38:39.415474286Z","hostname":"w-01JH8H16QRYG0ZMFS5DSD0AKB7","pid":1227,"session_id":"16b60670-b9a4-4ead-be42-82f8bee5ffc7"}
2012025-01-10T16:38:39.717Z{"msg":"Transition from WaitQuorum to Active","v":0,"name":"crucible","level":30,"time":"2025-01-10T16:38:39.415488773Z","hostname":"w-01JH8H16QRYG0ZMFS5DSD0AKB7","pid":1227,"client":"0","":"downstairs","session_id":"16b60670-b9a4-4ead-be42-82f8bee5ffc7"}
2022025-01-10T16:38:39.717Z{"msg":"Transition from WaitQuorum to Active","v":0,"name":"crucible","level":30,"time":"2025-01-10T16:38:39.415518139Z","hostname":"w-01JH8H16QRYG0ZMFS5DSD0AKB7","pid":1227,"client":"1","":"downstairs","session_id":"16b60670-b9a4-4ead-be42-82f8bee5ffc7"}
2032025-01-10T16:38:39.717Z{"msg":"Transition from WaitQuorum to Active","v":0,"name":"crucible","level":30,"time":"2025-01-10T16:38:39.415532777Z","hostname":"w-01JH8H16QRYG0ZMFS5DSD0AKB7","pid":1227,"client":"2","":"downstairs","session_id":"16b60670-b9a4-4ead-be42-82f8bee5ffc7"}
2042025-01-10T16:38:39.717ZDisk: sv:1 bs:4096 ts:204800 tb:50 max_io:50 or 204800
2052025-01-10T16:38:39.717Z{"msg":"All required reconciliation work is completed","v":0,"name":"crucible","level":30,"time":"2025-01-10T16:38:39.415564692Z","hostname":"w-01JH8H16QRYG0ZMFS5DSD0AKB7","pid":1227,"session_id":"16b60670-b9a4-4ead-be42-82f8bee5ffc7"}
2062025-01-10T16:38:39.717Z{"msg":"Set Downstairs and Upstairs active after reconciliation","v":0,"name":"crucible","level":30,"time":"2025-01-10T16:38:39.415579099Z","hostname":"w-01JH8H16QRYG0ZMFS5DSD0AKB7","pid":1227,"session_id":"16b60670-b9a4-4ead-be42-82f8bee5ffc7"}
2072025-01-10T16:38:39.717Z{"msg":"Fill test
2082025-01-10T16:38:39.717Z04abb9f7-a39b-4813-992d-bc8943843398 is now active with session: 16b60670-b9a4-4ead-be42-82f8bee5ffc7","v":0,"name":"crucible","level":30,"time":"2025-01-10T16:38:39.415609155Z","hostname":"w-01JH8H16QRYG0ZMFS5DSD0AKB7","pid":1227,"session_id":"16b60670-b9a4-4ead-be42-82f8bee5ffc7"}
2092025-01-10T16:38:39.717Z{"msg":"Set Active after no reconciliation","v":0,"name":"crucible","level":30,"time":"2025-01-10T16:38:39.415625212Z","hostname":"w-01JH8H16QRYG0ZMFS5DSD0AKB7","pid":1227,"session_id":"16b60670-b9a4-4ead-be42-82f8bee5ffc7"}
2102025-01-10T16:38:39.717Z{"msg":"The guest has finished waiting for activation with:31","v":0,"name":"crucible","level":30,"time":"2025-01-10T16:38:39.415652548Z","hostname":"w-01JH8H16QRYG0ZMFS5DSD0AKB7","pid":1227}
2112025-01-10T16:38:39.755ZRead and Verify all blocks (0..50 range:false)
2122025-01-10T16:38:39.796ZWrote out file "/var/tmp/test_up-build/verify_file"
2132025-01-10T16:38:39.796ZCLIENT: Tests done. All submitted work has been ACK'd
2142025-01-10T16:38:39.798Z----------------------------------------------------------------
2152025-01-10T16:38:39.798Z Crucible gen:31 GIO:true work queues: Upstairs:0 downstairs:1
2162025-01-10T16:38:39.798ZStates: Active Active Active
2172025-01-10T16:38:39.798ZJOBID ACK TYPE BKS/EXT DS:0 DS:1 DS:2 REPLAY
2182025-01-10T16:38:39.798Z 1002 Acked Read 50 Done Done Done false
2192025-01-10T16:38:39.799Z STATES DS:0 DS:1 DS:2 TOTAL
2202025-01-10T16:38:39.799Z Sent 0 0 0 0
2212025-01-10T16:38:39.799Z Done 1 1 1 3
2222025-01-10T16:38:39.799Z Skipped 0 0 0 0
2232025-01-10T16:38:39.799Z Error 0 0 0 0
2242025-01-10T16:38:39.799ZLast Flush: 1001 1001 1001
2252025-01-10T16:38:39.799ZDownstairs last five completed: 1001 1000
2262025-01-10T16:38:39.799ZUpstairs last five completed: 1002 1001 1000
2272025-01-10T16:38:39.799ZCLIENT: Up:0 ds:1 act:3
2282025-01-10T16:38:43.798Z----------------------------------------------------------------
2292025-01-10T16:38:43.798Z Crucible gen:31 GIO:true work queues: Upstairs:0 downstairs:0
2302025-01-10T16:38:43.798ZDownstairs last five completed: 1003 1002 1001 1000
2312025-01-10T16:38:43.798ZUpstairs last five completed: 1003 1002 1001 1000
2322025-01-10T16:38:43.798ZCLIENT: Up:0 ds:0 act:3
2332025-01-10T16:38:43.799ZCLIENT: All crucible jobs finished, exiting program
2342025-01-10T16:38:43.801Z{"msg":"Guest handle has been dropped","v":0,"name":"crucible","level":40,"time":"2025-01-10T16:38:43.498489295Z","hostname":"w-01JH8H16QRYG0ZMFS5DSD0AKB7","pid":1227}
2352025-01-10T16:38:43.810ZRepair setup passed
2362025-01-10T16:38:43.814ZCopy the region for /var/tmp/test_up-build/8830
2372025-01-10T16:38:43.816Zcp -r /var/tmp/test_up-build/8830 /var/tmp/test_up-build/previous
2382025-01-10T16:38:43.819Z/var/tmp/bins/crutest fill -g 32 -q --key mXN1HeInmA+U7zxv5nOFK7rwa/XHBwx0albypllDS90= --dsc 127.0.0.1:9998 --verify-out /var/tmp/test_up-build/verify_file --verify-in /var/tmp/test_up-build/verify_file
2392025-01-10T16:38:43.878Z{"msg":"Use this region info from dsc: RegionExtentInfo { block_size: 4096, blocks_per_extent: 10, extent_count: 5 }","v":0,"name":"crucible","level":30,"time":"2025-01-10T16:38:43.577322608Z","hostname":"w-01JH8H16QRYG0ZMFS5DSD0AKB7","pid":1233,"task":"crutest"}
2402025-01-10T16:38:43.881Z{"msg":"dsc has 3 regions. This means 1 sub_volumes","v":0,"name":"crucible","level":30,"time":"2025-01-10T16:38:43.577925814Z","hostname":"w-01JH8H16QRYG0ZMFS5DSD0AKB7","pid":1233,"task":"crutest"}
2412025-01-10T16:38:43.881Z{"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":"2025-01-10T16:38:43.579797723Z","hostname":"w-01JH8H16QRYG0ZMFS5DSD0AKB7","pid":1233,"task":"crutest"}
2422025-01-10T16:38:43.881Z{"msg":"Upstairs starts","v":0,"name":"crucible","level":30,"time":"2025-01-10T16:38:43.580047355Z","hostname":"w-01JH8H16QRYG0ZMFS5DSD0AKB7","pid":1233}
2432025-01-10T16:38:43.881Z{"msg":"Crucible Version: BuildInfo {\n version: \"0.0.1\",\n git_sha: \"56068760771d58f96ac946e6b2ae83073c18c1b4\",\n git_commit_timestamp: \"2025-01-10T16:19:36.000000000Z\",\n git_branch: \"alan/rust-1-84-please\",\n rustc_semver: \"1.84.0\",\n rustc_channel: \"stable\",\n rustc_host_triple: \"x86_64-unknown-illumos\",\n rustc_commit_sha: \"9fc6b43126469e3858e2fe86cafb4f0fd5068869\",\n cargo_triple: \"x86_64-unknown-illumos\",\n debug: true,\n opt_level: 0,\n}","v":0,"name":"crucible","level":30,"time":"2025-01-10T16:38:43.580093177Z","hostname":"w-01JH8H16QRYG0ZMFS5DSD0AKB7","pid":1233}
2442025-01-10T16:38:43.881Z{"msg":"Upstairs <-> Downstairs Message Version: 12","v":0,"name":"crucible","level":30,"time":"2025-01-10T16:38:43.580111645Z","hostname":"w-01JH8H16QRYG0ZMFS5DSD0AKB7","pid":1233}
2452025-01-10T16:38:43.881Z{"msg":"Using region definition RegionDefinition { block_size: 4096, extent_size: Block { value: 10, shift: 12 }, extent_count: 5, uuid: 00000000-0000-0000-0000-000000000000, encrypted: true, database_read_version: 1, database_write_version: 1 }","v":0,"name":"crucible","level":30,"time":"2025-01-10T16:38:43.58013867Z","hostname":"w-01JH8H16QRYG0ZMFS5DSD0AKB7","pid":1233}
2462025-01-10T16:38:43.884Z{"msg":"Crucible 4ef8f121-af6e-4168-a3a5-07e346c727e4 has session id: bd87ecf8-9eb7-45cd-8bd2-a89ebf26a0e2","v":0,"name":"crucible","level":30,"time":"2025-01-10T16:38:43.580873076Z","hostname":"w-01JH8H16QRYG0ZMFS5DSD0AKB7","pid":1233,"session_id":"bd87ecf8-9eb7-45cd-8bd2-a89ebf26a0e2"}
2472025-01-10T16:38:43.884Z{"msg":"Upstairs opts: Upstairs UUID: 4ef8f121-af6e-4168-a3a5-07e346c727e4, Targets: [127.0.0.1:8810, 127.0.0.1:8820, 127.0.0.1:8830], lossy: false, flush_timeout: None, key populated: true, cert_pem populated: false, key_pem populated: false, root_cert_pem populated: false, Control: None, read_only: false","v":0,"name":"crucible","level":30,"time":"2025-01-10T16:38:43.580946335Z","hostname":"w-01JH8H16QRYG0ZMFS5DSD0AKB7","pid":1233,"session_id":"bd87ecf8-9eb7-45cd-8bd2-a89ebf26a0e2"}
2482025-01-10T16:38:43.884Z{"msg":"Crucible stats registered with UUID: 4ef8f121-af6e-4168-a3a5-07e346c727e4","v":0,"name":"crucible","level":30,"time":"2025-01-10T16:38:43.580993817Z","hostname":"w-01JH8H16QRYG0ZMFS5DSD0AKB7","pid":1233,"session_id":"bd87ecf8-9eb7-45cd-8bd2-a89ebf26a0e2"}
2492025-01-10T16:38:43.915Z{"msg":"Downstairs in volume = 3","v":0,"name":"crucible","level":30,"time":"2025-01-10T16:38:43.614903329Z","hostname":"w-01JH8H16QRYG0ZMFS5DSD0AKB7","pid":1233,"task":"crutest"}
2502025-01-10T16:38:43.915Z{"msg":"The guest has requested activation with gen:32","v":0,"name":"crucible","level":30,"time":"2025-01-10T16:38:43.614995135Z","hostname":"w-01JH8H16QRYG0ZMFS5DSD0AKB7","pid":1233}
2512025-01-10T16:38:43.915Z{"msg":"4ef8f121-af6e-4168-a3a5-07e346c727e4 active request set","v":0,"name":"crucible","level":30,"time":"2025-01-10T16:38:43.61502994Z","hostname":"w-01JH8H16QRYG0ZMFS5DSD0AKB7","pid":1233,"session_id":"bd87ecf8-9eb7-45cd-8bd2-a89ebf26a0e2"}
2522025-01-10T16:38:43.918Z{"msg":"sending connect oneshot to client","v":0,"name":"crucible","level":30,"time":"2025-01-10T16:38:43.615087751Z","hostname":"w-01JH8H16QRYG0ZMFS5DSD0AKB7","pid":1233,"client":"0","":"downstairs","session_id":"bd87ecf8-9eb7-45cd-8bd2-a89ebf26a0e2"}
2532025-01-10T16:38:43.918Z{"msg":"client set_active_request while in New; waiting...","v":0,"name":"crucible","level":30,"time":"2025-01-10T16:38:43.615144542Z","hostname":"w-01JH8H16QRYG0ZMFS5DSD0AKB7","pid":1233,"client":"0","":"downstairs","session_id":"bd87ecf8-9eb7-45cd-8bd2-a89ebf26a0e2"}
2542025-01-10T16:38:43.918Z{"msg":"sending connect oneshot to client","v":0,"name":"crucible","level":30,"time":"2025-01-10T16:38:43.615181346Z","hostname":"w-01JH8H16QRYG0ZMFS5DSD0AKB7","pid":1233,"client":"1","":"downstairs","session_id":"bd87ecf8-9eb7-45cd-8bd2-a89ebf26a0e2"}
2552025-01-10T16:38:43.918Z{"msg":"client set_active_request while in New; waiting...","v":0,"name":"crucible","level":30,"time":"2025-01-10T16:38:43.615233878Z","hostname":"w-01JH8H16QRYG0ZMFS5DSD0AKB7","pid":1233,"client":"1","":"downstairs","session_id":"bd87ecf8-9eb7-45cd-8bd2-a89ebf26a0e2"}
2562025-01-10T16:38:43.918Z{"msg":"sending connect oneshot to client","v":0,"name":"crucible","level":30,"time":"2025-01-10T16:38:43.615267243Z","hostname":"w-01JH8H16QRYG0ZMFS5DSD0AKB7","pid":1233,"client":"2","":"downstairs","session_id":"bd87ecf8-9eb7-45cd-8bd2-a89ebf26a0e2"}
2572025-01-10T16:38:43.918Z{"msg":"client set_active_request while in New; waiting...","v":0,"name":"crucible","level":30,"time":"2025-01-10T16:38:43.615301018Z","hostname":"w-01JH8H16QRYG0ZMFS5DSD0AKB7","pid":1233,"client":"2","":"downstairs","session_id":"bd87ecf8-9eb7-45cd-8bd2-a89ebf26a0e2"}
2582025-01-10T16:38:43.918Z{"msg":"connecting to 127.0.0.1:8830","v":0,"name":"crucible","level":30,"time":"2025-01-10T16:38:43.615346091Z","hostname":"w-01JH8H16QRYG0ZMFS5DSD0AKB7","pid":1233,"":"io task","client":"2","":"downstairs","session_id":"bd87ecf8-9eb7-45cd-8bd2-a89ebf26a0e2"}
2592025-01-10T16:38:43.918Z{"msg":"connecting to 127.0.0.1:8810","v":0,"name":"crucible","level":30,"time":"2025-01-10T16:38:43.615366927Z","hostname":"w-01JH8H16QRYG0ZMFS5DSD0AKB7","pid":1233,"":"io task","client":"0","":"downstairs","session_id":"bd87ecf8-9eb7-45cd-8bd2-a89ebf26a0e2"}
2602025-01-10T16:38:43.918Z{"msg":"connecting to 127.0.0.1:8820","v":0,"name":"crucible","level":30,"time":"2025-01-10T16:38:43.615410461Z","hostname":"w-01JH8H16QRYG0ZMFS5DSD0AKB7","pid":1233,"":"io task","client":"1","":"downstairs","session_id":"bd87ecf8-9eb7-45cd-8bd2-a89ebf26a0e2"}
2612025-01-10T16:38:43.918Z{"msg":"ds_connection connected from Ok(127.0.0.1:45182)","v":0,"name":"crucible","level":30,"time":"2025-01-10T16:38:43.615446415Z","hostname":"w-01JH8H16QRYG0ZMFS5DSD0AKB7","pid":1233,"":"io task","client":"0","":"downstairs","session_id":"bd87ecf8-9eb7-45cd-8bd2-a89ebf26a0e2"}
2622025-01-10T16:38:43.918Z{"msg":"ds_connection connected from Ok(127.0.0.1:60722)","v":0,"name":"crucible","level":30,"time":"2025-01-10T16:38:43.615763796Z","hostname":"w-01JH8H16QRYG0ZMFS5DSD0AKB7","pid":1233,"":"io task","client":"2","":"downstairs","session_id":"bd87ecf8-9eb7-45cd-8bd2-a89ebf26a0e2"}
2632025-01-10T16:38:43.918Z{"msg":"ds_connection connected from Ok(127.0.0.1:54904)","v":0,"name":"crucible","level":30,"time":"2025-01-10T16:38:43.615828306Z","hostname":"w-01JH8H16QRYG0ZMFS5DSD0AKB7","pid":1233,"":"io task","client":"1","":"downstairs","session_id":"bd87ecf8-9eb7-45cd-8bd2-a89ebf26a0e2"}
2642025-01-10T16:38:43.918Z{"msg":"ds_transition from New to WaitActive","v":0,"name":"crucible","level":30,"time":"2025-01-10T16:38:43.616298693Z","hostname":"w-01JH8H16QRYG0ZMFS5DSD0AKB7","pid":1233,"client":"2","":"downstairs","session_id":"bd87ecf8-9eb7-45cd-8bd2-a89ebf26a0e2"}
2652025-01-10T16:38:43.918Z{"msg":"[2] Transition from New to WaitActive","v":0,"name":"crucible","level":30,"time":"2025-01-10T16:38:43.616334797Z","hostname":"w-01JH8H16QRYG0ZMFS5DSD0AKB7","pid":1233,"client":"2","":"downstairs","session_id":"bd87ecf8-9eb7-45cd-8bd2-a89ebf26a0e2"}
2662025-01-10T16:38:43.918Z{"msg":"ds_transition from New to WaitActive","v":0,"name":"crucible","level":30,"time":"2025-01-10T16:38:43.616350684Z","hostname":"w-01JH8H16QRYG0ZMFS5DSD0AKB7","pid":1233,"client":"1","":"downstairs","session_id":"bd87ecf8-9eb7-45cd-8bd2-a89ebf26a0e2"}
2672025-01-10T16:38:43.918Z{"msg":"[1] Transition from New to WaitActive","v":0,"name":"crucible","level":30,"time":"2025-01-10T16:38:43.616364372Z","hostname":"w-01JH8H16QRYG0ZMFS5DSD0AKB7","pid":1233,"client":"1","":"downstairs","session_id":"bd87ecf8-9eb7-45cd-8bd2-a89ebf26a0e2"}
2682025-01-10T16:38:43.918Z{"msg":"ds_transition from New to WaitActive","v":0,"name":"crucible","level":30,"time":"2025-01-10T16:38:43.61637768Z","hostname":"w-01JH8H16QRYG0ZMFS5DSD0AKB7","pid":1233,"client":"0","":"downstairs","session_id":"bd87ecf8-9eb7-45cd-8bd2-a89ebf26a0e2"}
2692025-01-10T16:38:43.918Z{"msg":"[0] Transition from New to WaitActive","v":0,"name":"crucible","level":30,"time":"2025-01-10T16:38:43.616400807Z","hostname":"w-01JH8H16QRYG0ZMFS5DSD0AKB7","pid":1233,"client":"0","":"downstairs","session_id":"bd87ecf8-9eb7-45cd-8bd2-a89ebf26a0e2"}
2702025-01-10T16:38:43.918Z{"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":"2025-01-10T16:38:43.616926045Z","hostname":"w-01JH8H16QRYG0ZMFS5DSD0AKB7","pid":1233,"client":"2","":"downstairs","session_id":"bd87ecf8-9eb7-45cd-8bd2-a89ebf26a0e2"}
2712025-01-10T16:38:43.918Z{"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":"2025-01-10T16:38:43.616971418Z","hostname":"w-01JH8H16QRYG0ZMFS5DSD0AKB7","pid":1233,"client":"1","":"downstairs","session_id":"bd87ecf8-9eb7-45cd-8bd2-a89ebf26a0e2"}
2722025-01-10T16:38:43.918Z{"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":"2025-01-10T16:38:43.617213721Z","hostname":"w-01JH8H16QRYG0ZMFS5DSD0AKB7","pid":1233,"client":"0","":"downstairs","session_id":"bd87ecf8-9eb7-45cd-8bd2-a89ebf26a0e2"}
2732025-01-10T16:38:43.918Z{"msg":"ds_transition from WaitActive to WaitQuorum","v":0,"name":"crucible","level":30,"time":"2025-01-10T16:38:43.617363187Z","hostname":"w-01JH8H16QRYG0ZMFS5DSD0AKB7","pid":1233,"client":"1","":"downstairs","session_id":"bd87ecf8-9eb7-45cd-8bd2-a89ebf26a0e2"}
2742025-01-10T16:38:43.918Z{"msg":"[1] Transition from WaitActive to WaitQuorum","v":0,"name":"crucible","level":30,"time":"2025-01-10T16:38:43.617426388Z","hostname":"w-01JH8H16QRYG0ZMFS5DSD0AKB7","pid":1233,"client":"1","":"downstairs","session_id":"bd87ecf8-9eb7-45cd-8bd2-a89ebf26a0e2"}
2752025-01-10T16:38:43.919Z{"msg":"Waiting for more clients to be ready","v":0,"name":"crucible","level":30,"time":"2025-01-10T16:38:43.617470071Z","hostname":"w-01JH8H16QRYG0ZMFS5DSD0AKB7","pid":1233,"session_id":"bd87ecf8-9eb7-45cd-8bd2-a89ebf26a0e2"}
2762025-01-10T16:38:43.919Z{"msg":"ds_transition from WaitActive to WaitQuorum","v":0,"name":"crucible","level":30,"time":"2025-01-10T16:38:43.617496306Z","hostname":"w-01JH8H16QRYG0ZMFS5DSD0AKB7","pid":1233,"client":"2","":"downstairs","session_id":"bd87ecf8-9eb7-45cd-8bd2-a89ebf26a0e2"}
2772025-01-10T16:38:43.919Z{"msg":"[2] Transition from WaitActive to WaitQuorum","v":0,"name":"crucible","level":30,"time":"2025-01-10T16:38:43.617511054Z","hostname":"w-01JH8H16QRYG0ZMFS5DSD0AKB7","pid":1233,"client":"2","":"downstairs","session_id":"bd87ecf8-9eb7-45cd-8bd2-a89ebf26a0e2"}
2782025-01-10T16:38:43.919Z{"msg":"Waiting for more clients to be ready","v":0,"name":"crucible","level":30,"time":"2025-01-10T16:38:43.617531031Z","hostname":"w-01JH8H16QRYG0ZMFS5DSD0AKB7","pid":1233,"session_id":"bd87ecf8-9eb7-45cd-8bd2-a89ebf26a0e2"}
2792025-01-10T16:38:43.919Z{"msg":"ds_transition from WaitActive to WaitQuorum","v":0,"name":"crucible","level":30,"time":"2025-01-10T16:38:43.617543179Z","hostname":"w-01JH8H16QRYG0ZMFS5DSD0AKB7","pid":1233,"client":"0","":"downstairs","session_id":"bd87ecf8-9eb7-45cd-8bd2-a89ebf26a0e2"}
2802025-01-10T16:38:43.919Z{"msg":"[0] Transition from WaitActive to WaitQuorum","v":0,"name":"crucible","level":30,"time":"2025-01-10T16:38:43.617562936Z","hostname":"w-01JH8H16QRYG0ZMFS5DSD0AKB7","pid":1233,"client":"0","":"downstairs","session_id":"bd87ecf8-9eb7-45cd-8bd2-a89ebf26a0e2"}
2812025-01-10T16:38:43.919Z{"msg":"[0]R flush_numbers: [1495, 1495, 1495, 1495, 1495]","v":0,"name":"crucible","level":30,"time":"2025-01-10T16:38:43.617576434Z","hostname":"w-01JH8H16QRYG0ZMFS5DSD0AKB7","pid":1233,"":"downstairs","":"downstairs","session_id":"bd87ecf8-9eb7-45cd-8bd2-a89ebf26a0e2"}
2822025-01-10T16:38:43.919Z{"msg":"[0]R generation: [31, 31, 31, 31, 31]","v":0,"name":"crucible","level":30,"time":"2025-01-10T16:38:43.617596271Z","hostname":"w-01JH8H16QRYG0ZMFS5DSD0AKB7","pid":1233,"":"downstairs","":"downstairs","session_id":"bd87ecf8-9eb7-45cd-8bd2-a89ebf26a0e2"}
2832025-01-10T16:38:43.919Z{"msg":"[0]R dirty: [false, false, false, false, false]","v":0,"name":"crucible","level":30,"time":"2025-01-10T16:38:43.617609959Z","hostname":"w-01JH8H16QRYG0ZMFS5DSD0AKB7","pid":1233,"":"downstairs","":"downstairs","session_id":"bd87ecf8-9eb7-45cd-8bd2-a89ebf26a0e2"}
2842025-01-10T16:38:43.919Z{"msg":"[1]R flush_numbers: [1495, 1495, 1495, 1495, 1495]","v":0,"name":"crucible","level":30,"time":"2025-01-10T16:38:43.617638635Z","hostname":"w-01JH8H16QRYG0ZMFS5DSD0AKB7","pid":1233,"":"downstairs","":"downstairs","session_id":"bd87ecf8-9eb7-45cd-8bd2-a89ebf26a0e2"}
2852025-01-10T16:38:43.919Z{"msg":"[1]R generation: [31, 31, 31, 31, 31]","v":0,"name":"crucible","level":30,"time":"2025-01-10T16:38:43.617662811Z","hostname":"w-01JH8H16QRYG0ZMFS5DSD0AKB7","pid":1233,"":"downstairs","":"downstairs","session_id":"bd87ecf8-9eb7-45cd-8bd2-a89ebf26a0e2"}
2862025-01-10T16:38:43.919Z{"msg":"[1]R dirty: [false, false, false, false, false]","v":0,"name":"crucible","level":30,"time":"2025-01-10T16:38:43.617695635Z","hostname":"w-01JH8H16QRYG0ZMFS5DSD0AKB7","pid":1233,"":"downstairs","":"downstairs","session_id":"bd87ecf8-9eb7-45cd-8bd2-a89ebf26a0e2"}
2872025-01-10T16:38:43.922Z{"msg":"[2]R flush_numbers: [1495, 1495, 1495, 1495, 1495]","v":0,"name":"crucible","level":30,"time":"2025-01-10T16:38:43.617718882Z","hostname":"w-01JH8H16QRYG0ZMFS5DSD0AKB7","pid":1233,"":"downstairs","":"downstairs","session_id":"bd87ecf8-9eb7-45cd-8bd2-a89ebf26a0e2"}
2882025-01-10T16:38:43.922Z{"msg":"[2]R generation: [31, 31, 31, 31, 31]","v":0,"name":"crucible","level":30,"time":"2025-01-10T16:38:43.617741968Z","hostname":"w-01JH8H16QRYG0ZMFS5DSD0AKB7","pid":1233,"":"downstairs","":"downstairs","session_id":"bd87ecf8-9eb7-45cd-8bd2-a89ebf26a0e2"}
2892025-01-10T16:38:43.922Z{"msg":"[2]R dirty: [false, false, false, false, false]","v":0,"name":"crucible","level":30,"time":Wait for a query_work_queue command to finish before sending IO
2902025-01-10T16:38:43.922Z"2025-01-10T16:38:43.617763755Z","hostname":"w-01JH8H16QRYG0ZMFS5DSD0AKB7","pid":1233,"":"downstairs","":"downstairs","session_id":"bd87ecf8-9eb7-45cd-8bd2-a89ebf26a0e2"}
2912025-01-10T16:38:43.922Z{"msg":"Max found gen is 32","v":0,"name":"crucible","level":30,"time":"2025-01-10T16:38:43.6177923Z","hostname":"w-01JH8H16QRYG0ZMFS5DSD0AKB7","pid":1233,"":"downstairs","":"downstairs","session_id":"bd87ecf8-9eb7-45cd-8bd2-a89ebf26a0e2"}
2922025-01-10T16:38:43.922Z{"msg":"Generation requested: 32 >= found:32","v":0,"name":"crucible","level":30,"time":"2025-01-10T16:38:43.617813067Z","hostname":"w-01JH8H16QRYG0ZMFS5DSD0AKB7","pid":1233,"":"downstairs","":"downstairs","session_id":"bd87ecf8-9eb7-45cd-8bd2-a89ebf26a0e2"}
2932025-01-10T16:38:43.922Z{"msg":"Next flush: 1496","v":0,"name":"crucible","level":30,"time":"2025-01-10T16:38:43.617852591Z","hostname":"w-01JH8H16QRYG0ZMFS5DSD0AKB7","pid":1233,"":"downstairs","":"downstairs","session_id":"bd87ecf8-9eb7-45cd-8bd2-a89ebf26a0e2"}
2942025-01-10T16:38:43.922Z{"msg":"All extents match","v":0,"name":"crucible","level":30,"time":"2025-01-10T16:38:43.617874328Z","hostname":"w-01JH8H16QRYG0ZMFS5DSD0AKB7","pid":1233,"":"downstairs","":"downstairs","session_id":"bd87ecf8-9eb7-45cd-8bd2-a89ebf26a0e2"}
2952025-01-10T16:38:43.922Z{"msg":"No downstairs reconciliation required","v":0,"name":"crucible","level":30,"time":"2025-01-10T16:38:43.617910032Z","hostname":"w-01JH8H16QRYG0ZMFS5DSD0AKB7","pid":1233,"session_id":"bd87ecf8-9eb7-45cd-8bd2-a89ebf26a0e2"}
2962025-01-10T16:38:43.922Z{"msg":"Transition from WaitQuorum to Active","v":0,"name":"crucible","level":30,"time":"2025-01-10T16:38:43.617942037Z","hostname":"w-01JH8H16QRYG0ZMFS5DSD0AKB7","pid":1233,"client":"0","":"downstairs","session_id":"bd87ecf8-9eb7-45cd-8bd2-a89ebf26a0e2"}
2972025-01-10T16:38:43.922Z{"msg":"Transition from WaitQuorum to Active","v":0,"name":"crucible","level":30,"time":"2025-01-10T16:38:43.617970933Z","hostname":"w-01JH8H16QRYG0ZMFS5DSD0AKB7","pid":1233,"client":"1","":"downstairs","session_id":"bd87ecf8-9eb7-45cd-8bd2-a89ebf26a0e2"}
2982025-01-10T16:38:43.922Z{"msg":"Transition from WaitQuorum to Active","v":0,"name":"crucible","level":30,"time":"2025-01-10T16:38:43.617985161Z","hostname":"w-01JH8H16QRYG0ZMFS5DSD0AKB7","pid":1233,"client":"2","":"downstairs","Disk: sv:1 bs:4096 ts:204800 tb:50 max_io:50 or 204800
2992025-01-10T16:38:43.922Zsession_id":"bd87ecf8-9eb7-45cd-8bd2-a89ebf26a0e2"}
3002025-01-10T16:38:43.922Z{"msg":"All required reconciliation work is completed","v":0,"name":"crucible","level":30,"time":"2025-01-10T16:38:43.618015546Z","hostname":"w-01JH8H16QRYG0ZMFS5DSD0AKB7","pid":1233,"session_id":"bd87ecf8-9eb7-45cd-8bd2-a89ebf26a0e2"}
3012025-01-10T16:38:43.922Z{"msg":"Set Downstairs and Upstairs active after reconciliation","v":0,"name":"crucible","level":30,"time":"2025-01-10T16:38:43.618030694Z","hostname":"w-01JH8H16QRYG0ZMFS5DSD0AKB7","pid":1233,"session_id":"bd87ecf8-9eb7-45cd-8bd2-a89ebf26a0e2"}
3022025-01-10T16:38:43.922Z{"msg":"4ef8f121-af6e-4168-a3a5-07e346c727e4 is now active with session: bd87ecf8-9eb7-45cd-8bd2-a89ebf26a0e2","v":0,"name":"crucible","level":30,"time":"2025-01-10T16:38:43.618044101Z","hostname":"w-01JH8H16QRYG0ZMFS5DSD0AKB7","pid":1233,"session_id":"bd87ecf8-9eb7-45cd-8bd2-a89ebf26a0e2"}
3032025-01-10T16:38:43.922Z{"msg":"Set Active after no reconciliation","v":0,"name":"crucible","level":30,"time":"2025-01-10T16:38:43.618064128Z","hostname":"w-01JH8H16QRYG0ZMFS5DSD0AKB7","pid":1233,"session_id":"bd87ecf8-9eb7-45cd-8bd2-a89ebf26a0e2"}
3042025-01-10T16:38:43.922Z{"msg":"The guest has finished waiting for activation with:32","v":0,"name":"crucible","level":30,"time":"2025-01-10T16:38:43.618076136Z","hostname":"w-01JH8H16QRYG0ZMFS5DSD0AKB7","pid":1233}
3052025-01-10T16:38:43.922ZLoading write count information from file "/var/tmp/test_up-build/verify_file"
3062025-01-10T16:38:43.922ZFill test
3072025-01-10T16:38:43.958ZRead and Verify all blocks (0..50 range:false)
3082025-01-10T16:38:43.997ZWrote out file "/var/tmp/test_up-build/verify_file"
3092025-01-10T16:38:43.997ZCLIENT: Tests done. All submitted work has been ACK'd
3102025-01-10T16:38:43.997Z----------------------------------------------------------------
3112025-01-10T16:38:43.997Z Crucible gen:32 GIO:true work queues: Upstairs:0 downstairs:1
3122025-01-10T16:38:43.997ZStates: Active Active Active
3132025-01-10T16:38:44.000ZJOBID ACK TYPE BKS/EXT DS:0 DS:1 DS:2 REPLAY
3142025-01-10T16:38:44.000Z 1002 Acked Read 50 Done Done Done false
3152025-01-10T16:38:44.000Z STATES DS:0 DS:1 DS:2 TOTAL
3162025-01-10T16:38:44.000Z Sent 0 0 0 0
3172025-01-10T16:38:44.000Z Done 1 1 1 3
3182025-01-10T16:38:44.000Z Skipped 0 0 0 0
3192025-01-10T16:38:44.000Z Error 0 0 0 0
3202025-01-10T16:38:44.000ZLast Flush: 1001 1001 1001
3212025-01-10T16:38:44.000ZDownstairs last five completed: 1001 1000
3222025-01-10T16:38:44.000ZUpstairs last five completed: 1002 1001 1000
3232025-01-10T16:38:44.000ZCLIENT: Up:0 ds:1 act:3
3242025-01-10T16:38:48.001Z----------------------------------------------------------------
3252025-01-10T16:38:48.001Z Crucible gen:32 GIO:true work queues: Upstairs:0 downstairs:0
3262025-01-10T16:38:48.001ZDownstairs last five completed: 1003 1002 1001 1000
3272025-01-10T16:38:48.001ZUpstairs last five completed: 1003 1002 1001 1000
3282025-01-10T16:38:48.001ZCLIENT: Up:0 ds:0 act:3
3292025-01-10T16:38:48.001ZCLIENT: All crucible jobs finished, exiting program
3302025-01-10T16:38:48.004Z{"msg":"Guest handle has been dropped","v":0,"name":"crucible","level":40,"time":"2025-01-10T16:38:47.699593878Z","hostname":"w-01JH8H16QRYG0ZMFS5DSD0AKB7","pid":1233}
3312025-01-10T16:38:48.008ZRepair part 1 passed
3322025-01-10T16:38:48.008Z
3332025-01-10T16:38:48.011ZKill the current downstairs
3342025-01-10T16:38:48.195ZDownstairs 2 stopped
3352025-01-10T16:38:48.195Zmv /var/tmp/test_up-build/8830 /var/tmp/test_up-build/new
3362025-01-10T16:38:48.197ZNow put back the original so we have a mismatch
3372025-01-10T16:38:48.197Zmv /var/tmp/test_up-build/previous /var/tmp/test_up-build/8830
3382025-01-10T16:38:48.200ZRestart downstairs with old directory
3392025-01-10T16:38:48.261Z/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
3402025-01-10T16:38:48.280ZEXT BLOCKS GEN0 GEN1 GEN2 FL0 FL1 FL2 D0 D1 D2 DIFF
3412025-01-10T16:38:48.283Z 0 000-009 32 32 31 1496 1496 1495 F F F <---
3422025-01-10T16:38:48.283Z 1 010-019 32 32 31 1496 1496 1495 F F F <---
3432025-01-10T16:38:48.283Z 2 020-029 32 32 31 1496 1496 1495 F F F <---
3442025-01-10T16:38:48.283Z 3 030-039 32 32 31 1496 1496 1495 F F F <---
3452025-01-10T16:38:48.283Z 4 040-049 32 32 31 1496 1496 1495 F F F <---
3462025-01-10T16:38:48.283ZMax gen: 32, Max flush: 1496
3472025-01-10T16:38:48.283ZError: Difference in extent metadata found!
3482025-01-10T16:38:48.286Zdump test found error as expected
3492025-01-10T16:38:48.288Z
3502025-01-10T16:38:48.288Z
3512025-01-10T16:38:48.288Z/var/tmp/bins/crutest verify --range -g 33 -q --key mXN1HeInmA+U7zxv5nOFK7rwa/XHBwx0albypllDS90= --dsc 127.0.0.1:9998 --verify-out /var/tmp/test_up-build/verify_file --verify-in /var/tmp/test_up-build/verify_file
3522025-01-10T16:38:48.348Z{"msg":"Use this region info from dsc: RegionExtentInfo { block_size: 4096, blocks_per_extent: 10, extent_count: 5 }","v":0,"name":"crucible","level":30,"time":"2025-01-10T16:38:48.046374333Z","hostname":"w-01JH8H16QRYG0ZMFS5DSD0AKB7","pid":1241,"task":"crutest"}
3532025-01-10T16:38:48.350Z{"msg":"dsc has 3 regions. This means 1 sub_volumes","v":0,"name":"crucible","level":30,"time":"2025-01-10T16:38:48.047011384Z","hostname":"w-01JH8H16QRYG0ZMFS5DSD0AKB7","pid":1241,"task":"crutest"}
3542025-01-10T16:38:48.350Z{"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":"2025-01-10T16:38:48.048753714Z","hostname":"w-01JH8H16QRYG0ZMFS5DSD0AKB7","pid":1241,"task":"crutest"}
3552025-01-10T16:38:48.350Z{"msg":"Upstairs starts","v":0,"name":"crucible","level":30,"time":"2025-01-10T16:38:48.048978149Z","hostname":"w-01JH8H16QRYG0ZMFS5DSD0AKB7","pid":1241}
3562025-01-10T16:38:48.350Z{"msg":"Crucible Version: BuildInfo {\n version: \"0.0.1\",\n git_sha: \"56068760771d58f96ac946e6b2ae83073c18c1b4\",\n git_commit_timestamp: \"2025-01-10T16:19:36.000000000Z\",\n git_branch: \"alan/rust-1-84-please\",\n rustc_semver: \"1.84.0\",\n rustc_channel: \"stable\",\n rustc_host_triple: \"x86_64-unknown-illumos\",\n rustc_commit_sha: \"9fc6b43126469e3858e2fe86cafb4f0fd5068869\",\n cargo_triple: \"x86_64-unknown-illumos\",\n debug: true,\n opt_level: 0,\n}","v":0,"name":"crucible","level":30,"time":"2025-01-10T16:38:48.049015213Z","hostname":"w-01JH8H16QRYG0ZMFS5DSD0AKB7","pid":1241}
3572025-01-10T16:38:48.350Z{"msg":"Upstairs <-> Downstairs Message Version: 12","v":0,"name":"crucible","level":30,"time":"2025-01-10T16:38:48.049036979Z","hostname":"w-01JH8H16QRYG0ZMFS5DSD0AKB7","pid":1241}
3582025-01-10T16:38:48.350Z{"msg":"Using region definition RegionDefinition { block_size: 4096, extent_size: Block { value: 10, shift: 12 }, extent_count: 5, uuid: 00000000-0000-0000-0000-000000000000, encrypted: true, database_read_version: 1, database_write_version: 1 }","v":0,"name":"crucible","level":30,"time":"2025-01-10T16:38:48.049052327Z","hostname":"w-01JH8H16QRYG0ZMFS5DSD0AKB7","pid":1241}
3592025-01-10T16:38:48.353Z{"msg":"Crucible 286764ad-329f-4d09-960d-6fe13dac7f47 has session id: c6ee8897-c2f4-4670-a4ae-e3783b6547b6","v":0,"name":"crucible","level":30,"time":"2025-01-10T16:38:48.049810699Z","hostname":"w-01JH8H16QRYG0ZMFS5DSD0AKB7","pid":1241,"session_id":"c6ee8897-c2f4-4670-a4ae-e3783b6547b6"}
3602025-01-10T16:38:48.353Z{"msg":"Upstairs opts: Upstairs UUID: 286764ad-329f-4d09-960d-6fe13dac7f47, Targets: [127.0.0.1:8810, 127.0.0.1:8820, 127.0.0.1:8830], lossy: false, flush_timeout: None, key populated: true, cert_pem populated: false, key_pem populated: false, root_cert_pem populated: false, Control: None, read_only: false","v":0,"name":"crucible","level":30,"time":"2025-01-10T16:38:48.049854203Z","hostname":"w-01JH8H16QRYG0ZMFS5DSD0AKB7","pid":1241,"session_id":"c6ee8897-c2f4-4670-a4ae-e3783b6547b6"}
3612025-01-10T16:38:48.353Z{"msg":"Crucible stats registered with UUID: 286764ad-329f-4d09-960d-6fe13dac7f47","v":0,"name":"crucible","level":30,"time":"2025-01-10T16:38:48.04986972Z","hostname":"w-01JH8H16QRYG0ZMFS5DSD0AKB7","pid":1241,"session_id":"c6ee8897-c2f4-4670-a4ae-e3783b6547b6"}
3622025-01-10T16:38:48.386Z{"msg":"Downstairs in volume = 3","v":0,"name":"crucible","level":30,"time":"2025-01-10T16:38:48.084067447Z","hostname":"w-01JH8H16QRYG0ZMFS5DSD0AKB7","pid":1241,"task":"crutest"}
3632025-01-10T16:38:48.386Z{"msg":"The guest has requested activation with gen:33","v":0,"name":"crucible","level":30,"time":"2025-01-10T16:38:48.084162902Z","hostname":"w-01JH8H16QRYG0ZMFS5DSD0AKB7","pid":1241}
3642025-01-10T16:38:48.386Z{"msg":"286764ad-329f-4d09-960d-6fe13dac7f47 active request set","v":0,"name":"crucible","level":30,"time":"2025-01-10T16:38:48.084196137Z","hostname":"w-01JH8H16QRYG0ZMFS5DSD0AKB7","pid":1241,"session_id":"c6ee8897-c2f4-4670-a4ae-e3783b6547b6"}
3652025-01-10T16:38:48.389Z{"msg":"sending connect oneshot to client","v":0,"name":"crucible","level":30,"time":"2025-01-10T16:38:48.08424153Z","hostname":"w-01JH8H16QRYG0ZMFS5DSD0AKB7","pid":1241,"client":"0","":"downstairs","session_id":"c6ee8897-c2f4-4670-a4ae-e3783b6547b6"}
3662025-01-10T16:38:48.389Z{"msg":"client set_active_request while in New; waiting...","v":0,"name":"crucible","level":30,"time":"2025-01-10T16:38:48.084351883Z","hostname":"w-01JH8H16QRYG0ZMFS5DSD0AKB7","pid":1241,"client":"0","":"downstairs","session_id":"c6ee8897-c2f4-4670-a4ae-e3783b6547b6"}
3672025-01-10T16:38:48.389Z{"msg":"sending connect oneshot to client","v":0,"name":"crucible","level":30,"time":"2025-01-10T16:38:48.084414303Z","hostname":"w-01JH8H16QRYG0ZMFS5DSD0AKB7","pid":1241,"client":"1","":"downstairs","session_id":"c6ee8897-c2f4-4670-a4ae-e3783b6547b6"}
3682025-01-10T16:38:48.389Z{"msg":"client set_active_request while in New; waiting...","v":0,"name":"crucible","level":30,"time":"2025-01-10T16:38:48.084463616Z","hostname":"w-01JH8H16QRYG0ZMFS5DSD0AKB7","pid":1241,"client":"1","":"downstairs","session_id":"c6ee8897-c2f4-4670-a4ae-e3783b6547b6"}
3692025-01-10T16:38:48.389Z{"msg":"sending connect oneshot to client","v":0,"name":"crucible","level":30,"time":"2025-01-10T16:38:48.08450339Z","hostname":"w-01JH8H16QRYG0ZMFS5DSD0AKB7","pid":1241,"client":"2","":"downstairs","session_id":"c6ee8897-c2f4-4670-a4ae-e3783b6547b6"}
3702025-01-10T16:38:48.389Z{"msg":"client set_active_request while in New; waiting...","v":0,"name":"crucible","level":30,"time":"2025-01-10T16:38:48.084533945Z","hostname":"w-01JH8H16QRYG0ZMFS5DSD0AKB7","pid":1241,"client":"2","":"downstairs","session_id":"c6ee8897-c2f4-4670-a4ae-e3783b6547b6"}
3712025-01-10T16:38:48.389Z{"msg":"connecting to 127.0.0.1:8810","v":0,"name":"crucible","level":30,"time":"2025-01-10T16:38:48.084578558Z","hostname":"w-01JH8H16QRYG0ZMFS5DSD0AKB7","pid":1241,"":"io task","client":"0","":"downstairs","session_id":"c6ee8897-c2f4-4670-a4ae-e3783b6547b6"}
3722025-01-10T16:38:48.389Z{"msg":"connecting to 127.0.0.1:8830","v":0,"name":"crucible","level":30,"time":"2025-01-10T16:38:48.084620271Z","hostname":"w-01JH8H16QRYG0ZMFS5DSD0AKB7","pid":1241,"":"io task","client":"2","":"downstairs","session_id":"c6ee8897-c2f4-4670-a4ae-e3783b6547b6"}
3732025-01-10T16:38:48.389Z{"msg":"connecting to 127.0.0.1:8820","v":0,"name":"crucible","level":30,"time":"2025-01-10T16:38:48.084716476Z","hostname":"w-01JH8H16QRYG0ZMFS5DSD0AKB7","pid":1241,"":"io task","client":"1","":"downstairs","session_id":"c6ee8897-c2f4-4670-a4ae-e3783b6547b6"}
3742025-01-10T16:38:48.389Z{"msg":"ds_connection connected from Ok(127.0.0.1:38832)","v":0,"name":"crucible","level":30,"time":"2025-01-10T16:38:48.08475599Z","hostname":"w-01JH8H16QRYG0ZMFS5DSD0AKB7","pid":1241,"":"io task","client":"0","":"downstairs","session_id":"c6ee8897-c2f4-4670-a4ae-e3783b6547b6"}
3752025-01-10T16:38:48.389Z{"msg":"ds_connection connected from Ok(127.0.0.1:32789)","v":0,"name":"crucible","level":30,"time":"2025-01-10T16:38:48.084803493Z","hostname":"w-01JH8H16QRYG0ZMFS5DSD0AKB7","pid":1241,"":"io task","client":"1","":"downstairs","session_id":"c6ee8897-c2f4-4670-a4ae-e3783b6547b6"}
3762025-01-10T16:38:48.389Z{"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":"2025-01-10T16:38:48.084854805Z","hostname":"w-01JH8H16QRYG0ZMFS5DSD0AKB7","pid":1241,"":"io task","client":"2","":"downstairs","session_id":"c6ee8897-c2f4-4670-a4ae-e3783b6547b6"}
3772025-01-10T16:38:48.389Z{"msg":"client task is sending Done(ConnectionFailed(Os { code: 146, kind: ConnectionRefused, message: \"Connection refused\" }))","v":0,"name":"crucible","level":40,"time":"2025-01-10T16:38:48.084907187Z","hostname":"w-01JH8H16QRYG0ZMFS5DSD0AKB7","pid":1241,"":"io task","client":"2","":"downstairs","session_id":"c6ee8897-c2f4-4670-a4ae-e3783b6547b6"}
3782025-01-10T16:38:48.389Z{"msg":"downstairs task for 2 stopped due to ConnectionFailed(Os { code: 146, kind: ConnectionRefused, message: \"Connection refused\" })","v":0,"name":"crucible","level":40,"time":"2025-01-10T16:38:48.084957619Z","hostname":"w-01JH8H16QRYG0ZMFS5DSD0AKB7","pid":1241,"session_id":"c6ee8897-c2f4-4670-a4ae-e3783b6547b6"}
3792025-01-10T16:38:48.389Z{"msg":"client task is exiting","v":0,"name":"crucible","level":30,"time":"2025-01-10T16:38:48.084997173Z","hostname":"w-01JH8H16QRYG0ZMFS5DSD0AKB7","pid":1241,"":"io task","client":"2","":"downstairs","session_id":"c6ee8897-c2f4-4670-a4ae-e3783b6547b6"}
3802025-01-10T16:38:48.389Z{"msg":"ds_transition from New to WaitActive","v":0,"name":"crucible","level":30,"time":"2025-01-10T16:38:48.085417638Z","hostname":"w-01JH8H16QRYG0ZMFS5DSD0AKB7","pid":1241,"client":"1","":"downstairs","session_id":"c6ee8897-c2f4-4670-a4ae-e3783b6547b6"}
3812025-01-10T16:38:48.389Z{"msg":"[1] Transition from New to WaitActive","v":0,"name":"crucible","level":30,"time":"2025-01-10T16:38:48.085454932Z","hostname":"w-01JH8H16QRYG0ZMFS5DSD0AKB7","pid":1241,"client":"1","":"downstairs","session_id":"c6ee8897-c2f4-4670-a4ae-e3783b6547b6"}
3822025-01-10T16:38:48.389Z{"msg":"ds_transition from New to WaitActive","v":0,"name":"crucible","level":30,"time":"2025-01-10T16:38:48.085478278Z","hostname":"w-01JH8H16QRYG0ZMFS5DSD0AKB7","pid":1241,"client":"0","":"downstairs","session_id":"c6ee8897-c2f4-4670-a4ae-e3783b6547b6"}
3832025-01-10T16:38:48.390Z{"msg":"[0] Transition from New to WaitActive","v":0,"name":"crucible","level":30,"time":"2025-01-10T16:38:48.085504154Z","hostname":"w-01JH8H16QRYG0ZMFS5DSD0AKB7","pid":1241,"client":"0","":"downstairs","session_id":"c6ee8897-c2f4-4670-a4ae-e3783b6547b6"}
3842025-01-10T16:38:48.390Z{"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":"2025-01-10T16:38:48.086061358Z","hostname":"w-01JH8H16QRYG0ZMFS5DSD0AKB7","pid":1241,"client":"0","":"downstairs","session_id":"c6ee8897-c2f4-4670-a4ae-e3783b6547b6"}
3852025-01-10T16:38:48.390Z{"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":"2025-01-10T16:38:48.08617428Z","hostname":"w-01JH8H16QRYG0ZMFS5DSD0AKB7","pid":1241,"client":"1","":"downstairs","session_id":"c6ee8897-c2f4-4670-a4ae-e3783b6547b6"}
3862025-01-10T16:38:48.390Z{"msg":"ds_transition from WaitActive to WaitQuorum","v":0,"name":"crucible","level":30,"time":"2025-01-10T16:38:48.086408624Z","hostname":"w-01JH8H16QRYG0ZMFS5DSD0AKB7","pid":1241,"client":"0","":"downstairs","session_id":"c6ee8897-c2f4-4670-a4ae-e3783b6547b6"}
3872025-01-10T16:38:48.390Z{"msg":"[0] Transition from WaitActive to WaitQuorum","v":0,"name":"crucible","level":30,"time":"2025-01-10T16:38:48.086454027Z","hostname":"w-01JH8H16QRYG0ZMFS5DSD0AKB7","pid":1241,"client":"0","":"downstairs","session_id":"c6ee8897-c2f4-4670-a4ae-e3783b6547b6"}
3882025-01-10T16:38:48.390Z{"msg":"Waiting for more clients to be ready","v":0,"name":"crucible","level":30,"time":"2025-01-10T16:38:48.086468674Z","hostname":"w-01JH8H16QRYG0ZMFS5DSD0AKB7","pid":1241,"session_id":"c6ee8897-c2f4-4670-a4ae-e3783b6547b6"}
3892025-01-10T16:38:48.390Z{"msg":"ds_transition from WaitActive to WaitQuorum","v":0,"name":"crucible","level":30,"time":"2025-01-10T16:38:48.086535524Z","hostname":"w-01JH8H16QRYG0ZMFS5DSD0AKB7","pid":1241,"client":"1","":"downstairs","session_id":"c6ee8897-c2f4-4670-a4ae-e3783b6547b6"}
3902025-01-10T16:38:48.390Z{"msg":"[1] Transition from WaitActive to WaitQuorum","v":0,"name":"crucible","level":30,"time":"2025-01-10T16:38:48.08656296Z","hostname":"w-01JH8H16QRYG0ZMFS5DSD0AKB7","pid":1241,"client":"1","":"downstairs","session_id":"c6ee8897-c2f4-4670-a4ae-e3783b6547b6"}
3912025-01-10T16:38:48.390Z{"msg":"Waiting for more clients to be ready","v":0,"name":"crucible","level":30,"time":"2025-01-10T16:38:48.086576927Z","hostname":"w-01JH8H16QRYG0ZMFS5DSD0AKB7","pid":1241,"session_id":"c6ee8897-c2f4-4670-a4ae-e3783b6547b6"}
3922025-01-10T16:38:58.389Z{"msg":"connecting to 127.0.0.1:8830","v":0,"name":"crucible","level":30,"time":"2025-01-10T16:38:58.086196287Z","hostname":"w-01JH8H16QRYG0ZMFS5DSD0AKB7","pid":1241,"":"io task","client":"2","":"downstairs","session_id":"c6ee8897-c2f4-4670-a4ae-e3783b6547b6"}
3932025-01-10T16:38:58.389Z{"msg":"ds_connection connected from Ok(127.0.0.1:48584)","v":0,"name":"crucible","level":30,"time":"2025-01-10T16:38:58.086297751Z","hostname":"w-01JH8H16QRYG0ZMFS5DSD0AKB7","pid":1241,"":"io task","client":"2","":"downstairs","session_id":"c6ee8897-c2f4-4670-a4ae-e3783b6547b6"}
3942025-01-10T16:38:58.393Z{"msg":"ds_transition from New to WaitActive","v":0,"name":"crucible","level":30,"time":"2025-01-10T16:38:58.087438674Z","hostname":"w-01JH8H16QRYG0ZMFS5DSD0AKB7","pid":1241,"client":"2","":"downstairs","session_id":"c6ee8897-c2f4-4670-a4ae-e3783b6547b6"}
3952025-01-10T16:38:58.393Z{"msg":"[2] Transition from New to WaitActive","v":0,"name":"crucible","level":30,"time":"2025-01-10T16:38:58.087498135Z","hostname":"w-01JH8H16QRYG0ZMFS5DSD0AKB7","pid":1241,"client":"2","":"downstairs","session_id":"c6ee8897-c2f4-4670-a4ae-e3783b6547b6"}
3962025-01-10T16:38:58.393Z{"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":"2025-01-10T16:38:58.088070646Z","hostname":"w-01JH8H16QRYG0ZMFS5DSD0AKB7","pid":1241,"client":"2","":"downstairs","session_id":"c6ee8897-c2f4-4670-a4ae-e3783b6547b6"}
3972025-01-10T16:38:58.393Z{"msg":"ds_transition from WaitActive to WaitQuorum","v":0,"name":"crucible","level":30,"time":"2025-01-10T16:38:58.08842642Z","hostname":"w-01JH8H16QRYG0ZMFS5DSD0AKB7","pid":1241,"client":"2","":"downstairs","session_id":"c6ee8897-c2f4-4670-a4ae-e3783b6547b6"}
3982025-01-10T16:38:58.393Z{"msg":"[2] Transition from WaitActive to WaitQuorum","v":0,"name":"crucible","level":30,"time":"2025-01-10T16:38:58.088458815Z","hostname":"w-01JH8H16QRYG0ZMFS5DSD0AKB7","pid":1241,"client":"2","":"downstairs","session_id":"c6ee8897-c2f4-4670-a4ae-e3783b6547b6"}
3992025-01-10T16:38:58.393Z{"msg":"[0]R flush_numbers: [1496, 1496, 1496, 1496, 1496]","v":0,"name":"crucible","level":30,"time":"2025-01-10T16:38:58.088474733Z","hostname":"w-01JH8H16QRYG0ZMFS5DSD0AKB7","pid":1241,"":"downstairs","":"downstairs","session_id":"c6ee8897-c2f4-4670-a4ae-e3783b6547b6"}
4002025-01-10T16:38:58.393Z{"msg":"[0]R generation: [32, 32, 32, 32, 32]","v":0,"name":"crucible","level":30,"time":"2025-01-10T16:38:58.088489191Z","hostname":"w-01JH8H16QRYG0ZMFS5DSD0AKB7","pid":1241,"":"downstairs","":"downstairs","session_id":"c6ee8897-c2f4-4670-a4ae-e3783b6547b6"}
4012025-01-10T16:38:58.393Z{"msg":"[0]R dirty: [false, false, false, false, false]","v":0,"name":"crucible","level":30,"time":"2025-01-10T16:38:58.088510147Z","hostname":"w-01JH8H16QRYG0ZMFS5DSD0AKB7","pid":1241,"":"downstairs","":"downstairs","session_id":"c6ee8897-c2f4-4670-a4ae-e3783b6547b6"}
4022025-01-10T16:38:58.393Z{"msg":"[1]R flush_numbers: [1496, 1496, 1496, 1496, 1496]","v":0,"name":"crucible","level":30,"time":"2025-01-10T16:38:58.088525355Z","hostname":"w-01JH8H16QRYG0ZMFS5DSD0AKB7","pid":1241,"":"downstairs","":"downstairs","session_id":"c6ee8897-c2f4-4670-a4ae-e3783b6547b6"}
4032025-01-10T16:38:58.394Z{"msg":"[1]R generation: [32, 32, 32, 32, 32]","v":0,"name":"crucible","level":30,"time":"2025-01-10T16:38:58.088545292Z","hostname":"w-01JH8H16QRYG0ZMFS5DSD0AKB7","pid":1241,"":"downstairs","":"downstairs","session_id":"c6ee8897-c2f4-4670-a4ae-e3783b6547b6"}
4042025-01-10T16:38:58.394Z{"msg":"[1]R dirty: [false, false, false, false, false]","v":0,"name":"crucible","level":30,"time":"2025-01-10T16:38:58.08855879Z","hostname":"w-01JH8H16QRYG0ZMFS5DSD0AKB7","pid":1241,"":"downstairs","":"downstairs","session_id":"c6ee8897-c2f4-4670-a4ae-e3783b6547b6"}
4052025-01-10T16:38:58.394Z{"msg":"[2]R flush_numbers: [1495, 1495, 1495, 1495, 1495]","v":0,"name":"crucible","level":30,"time":"2025-01-10T16:38:58.088580296Z","hostname":"w-01JH8H16QRYG0ZMFS5DSD0AKB7","pid":1241,"":"downstairs","":"downstairs","session_id":"c6ee8897-c2f4-4670-a4ae-e3783b6547b6"}
4062025-01-10T16:38:58.394Z{"msg":"[2]R generation: [31, 31, 31, 31, 31]","v":0,"name":"crucible","level":30,"time":"2025-01-10T16:38:58.088596634Z","hostname":"w-01JH8H16QRYG0ZMFS5DSD0AKB7","pid":1241,"":"downstairs","":"downstairs","session_id":"c6ee8897-c2f4-4670-a4ae-e3783b6547b6"}
4072025-01-10T16:38:58.394Z{"msg":"[2]R dirty: [false, false, false, false, false]","v":0,"name":"crucible","level":30,"time":"2025-01-10T16:38:58.088613231Z","hostname":"w-01JH8H16QRYG0ZMFS5DSD0AKB7","pid":1241,"":"downstairs","":"downstairs","session_id":"c6ee8897-c2f4-4670-a4ae-e3783b6547b6"}
4082025-01-10T16:38:58.394Z{"msg":"Max found gen is 33","v":0,"name":"crucible","level":30,"time":"2025-01-10T16:38:58.088636748Z","hostname":"w-01JH8H16QRYG0ZMFS5DSD0AKB7","pid":1241,"":"downstairs","":"downstairs","session_id":"c6ee8897-c2f4-4670-a4ae-e3783b6547b6"}
4092025-01-10T16:38:58.394Z{"msg":"Generation requested: 33 >= found:33","v":0,"name":"crucible","level":30,"time":"2025-01-10T16:38:58.088668463Z","hostname":"w-01JH8H16QRYG0ZMFS5DSD0AKB7","pid":1241,"":"downstairs","":"downstairs","session_id":"c6ee8897-c2f4-4670-a4ae-e3783b6547b6"}
4102025-01-10T16:38:58.394Z{"msg":"Next flush: 1497","v":0,"name":"crucible","level":30,"time":"2025-01-10T16:38:58.088693679Z","hostname":"w-01JH8H16QRYG0ZMFS5DSD0AKB7","pid":1241,"":"downstairs","":"downstairs","session_id":"c6ee8897-c2f4-4670-a4ae-e3783b6547b6"}
4112025-01-10T16:38:58.394Z{"msg":"Extent 0 has flush number mismatch","v":0,"name":"crucible","level":30,"time":"2025-01-10T16:38:58.088709886Z","hostname":"w-01JH8H16QRYG0ZMFS5DSD0AKB7","pid":1241,"":"mend","":"downstairs","":"downstairs","session_id":"c6ee8897-c2f4-4670-a4ae-e3783b6547b6"}
4122025-01-10T16:38:58.394Z{"msg":"First source client ID for extent 0","v":0,"name":"crucible","level":30,"time":"2025-01-10T16:38:58.088734583Z","hostname":"w-01JH8H16QRYG0ZMFS5DSD0AKB7","pid":1241,"mrl":"flush_mismatch","":"mend","":"downstairs","":"downstairs","session_id":"c6ee8897-c2f4-4670-a4ae-e3783b6547b6"}
4132025-01-10T16:38:58.395Z{"msg":"extent:0 gens: 32 32 31","v":0,"name":"crucible","level":30,"time":"2025-01-10T16:38:58.08875302Z","hostname":"w-01JH8H16QRYG0ZMFS5DSD0AKB7","pid":1241,"mrl":"flush_mismatch","":"mend","":"downstairs","":"downstairs","session_id":"c6ee8897-c2f4-4670-a4ae-e3783b6547b6"}
4142025-01-10T16:38:58.395Z{"msg":"extent:0 flush: 1496 1496 1495 scs: [ClientId(0), ClientId(1)]","v":0,"name":"crucible","level":30,"time":"2025-01-10T16:38:58.088778466Z","hostname":"w-01JH8H16QRYG0ZMFS5DSD0AKB7","pid":1241,"mrl":"flush_mismatch","":"mend","":"downstairs","":"downstairs","session_id":"c6ee8897-c2f4-4670-a4ae-e3783b6547b6"}
4152025-01-10T16:38:58.395Z{"msg":"max_flush now has: [ClientId(0), ClientId(1)]","v":0,"name":"crucible","level":30,"time":"2025-01-10T16:38:58.088807361Z","hostname":"w-01JH8H16QRYG0ZMFS5DSD0AKB7","pid":1241,"mrl":"flush_mismatch","":"mend","":"downstairs","":"downstairs","session_id":"c6ee8897-c2f4-4670-a4ae-e3783b6547b6"}
4162025-01-10T16:38:58.395Z{"msg":"extent:0 dirty: false false false","v":0,"name":"crucible","level":30,"time":"2025-01-10T16:38:58.088825698Z","hostname":"w-01JH8H16QRYG0ZMFS5DSD0AKB7","pid":1241,"mrl":"flush_mismatch","":"mend","":"downstairs","":"downstairs","session_id":"c6ee8897-c2f4-4670-a4ae-e3783b6547b6"}
4172025-01-10T16:38:58.395Z{"msg":"No maxes found, left with: [ClientId(0), ClientId(1)]","v":0,"name":"crucible","level":30,"time":"2025-01-10T16:38:58.088852084Z","hostname":"w-01JH8H16QRYG0ZMFS5DSD0AKB7","pid":1241,"mrl":"flush_mismatch","":"mend","":"downstairs","":"downstairs","session_id":"c6ee8897-c2f4-4670-a4ae-e3783b6547b6"}
4182025-01-10T16:38:58.395Z{"msg":"find dest for source 0 for extent at index 0","v":0,"name":"crucible","level":30,"time":"2025-01-10T16:38:58.088871101Z","hostname":"w-01JH8H16QRYG0ZMFS5DSD0AKB7","pid":1241,"mrl":"flush_mismatch","":"mend","":"downstairs","":"downstairs","session_id":"c6ee8897-c2f4-4670-a4ae-e3783b6547b6"}
4192025-01-10T16:38:58.395Z{"msg":"source 0, add dest 2 gen","v":0,"name":"crucible","level":30,"time":"2025-01-10T16:38:58.088896487Z","hostname":"w-01JH8H16QRYG0ZMFS5DSD0AKB7","pid":1241,"mrl":"flush_mismatch","":"mend","":"downstairs","":"downstairs","session_id":"c6ee8897-c2f4-4670-a4ae-e3783b6547b6"}
4202025-01-10T16:38:58.395Z{"msg":"Extent 1 has flush number mismatch","v":0,"name":"crucible","level":30,"time":"2025-01-10T16:38:58.088921854Z","hostname":"w-01JH8H16QRYG0ZMFS5DSD0AKB7","pid":1241,"":"mend","":"downstairs","":"downstairs","session_id":"c6ee8897-c2f4-4670-a4ae-e3783b6547b6"}
4212025-01-10T16:38:58.395Z{"msg":"First source client ID for extent 1","v":0,"name":"crucible","level":30,"time":"2025-01-10T16:38:58.08894715Z","hostname":"w-01JH8H16QRYG0ZMFS5DSD0AKB7","pid":1241,"mrl":"flush_mismatch","":"mend","":"downstairs","":"downstairs","session_id":"c6ee8897-c2f4-4670-a4ae-e3783b6547b6"}
4222025-01-10T16:38:58.395Z{"msg":"extent:1 gens: 32 32 31","v":0,"name":"crucible","level":30,"time":"2025-01-10T16:38:58.088965167Z","hostname":"w-01JH8H16QRYG0ZMFS5DSD0AKB7","pid":1241,"mrl":"flush_mismatch","":"mend","":"downstairs","":"downstairs","session_id":"c6ee8897-c2f4-4670-a4ae-e3783b6547b6"}
4232025-01-10T16:38:58.395Z{"msg":"extent:1 flush: 1496 1496 1495 scs: [ClientId(0), ClientId(1)]","v":0,"name":"crucible","level":30,"time":"2025-01-10T16:38:58.088990903Z","hostname":"w-01JH8H16QRYG0ZMFS5DSD0AKB7","pid":1241,"mrl":"flush_mismatch","":"mend","":"downstairs","":"downstairs","session_id":"c6ee8897-c2f4-4670-a4ae-e3783b6547b6"}
4242025-01-10T16:38:58.395Z{"msg":"max_flush now has: [ClientId(0), ClientId(1)]","v":0,"name":"crucible","level":30,"time":"2025-01-10T16:38:58.089029987Z","hostname":"w-01JH8H16QRYG0ZMFS5DSD0AKB7","pid":1241,"mrl":"flush_mismatch","":"mend","":"downstairs","":"downstairs","session_id":"c6ee8897-c2f4-4670-a4ae-e3783b6547b6"}
4252025-01-10T16:38:58.395Z{"msg":"extent:1 dirty: false false false","v":0,"name":"crucible","level":30,"time":"2025-01-10T16:38:58.089048044Z","hostname":"w-01JH8H16QRYG0ZMFS5DSD0AKB7","pid":1241,"mrl":"flush_mismatch","":"mend","":"downstairs","":"downstairs","session_id":"c6ee8897-c2f4-4670-a4ae-e3783b6547b6"}
4262025-01-10T16:38:58.395Z{"msg":"No maxes found, left with: [ClientId(0), ClientId(1)]","v":0,"name":"crucible","level":30,"time":"2025-01-10T16:38:58.089090417Z","hostname":"w-01JH8H16QRYG0ZMFS5DSD0AKB7","pid":1241,"mrl":"flush_mismatch","":"mend","":"downstairs","":"downstairs","session_id":"c6ee8897-c2f4-4670-a4ae-e3783b6547b6"}
4272025-01-10T16:38:58.395Z{"msg":"find dest for source 0 for extent at index 1","v":0,"name":"crucible","level":30,"time":"2025-01-10T16:38:58.08913978Z","hostname":"w-01JH8H16QRYG0ZMFS5DSD0AKB7","pid":1241,"mrl":"flush_mismatch","":"mend","":"downstairs","":"downstairs","session_id":"c6ee8897-c2f4-4670-a4ae-e3783b6547b6"}
4282025-01-10T16:38:58.395Z{"msg":"source 0, add dest 2 gen","v":0,"name":"crucible","level":30,"time":"2025-01-10T16:38:58.089190302Z","hostname":"w-01JH8H16QRYG0ZMFS5DSD0AKB7","pid":1241,"mrl":"flush_mismatch","":"mend","":"downstairs","":"downstairs","session_id":"c6ee8897-c2f4-4670-a4ae-e3783b6547b6"}
4292025-01-10T16:38:58.395Z{"msg":"Extent 2 has flush number mismatch","v":0,"name":"crucible","level":30,"time":"2025-01-10T16:38:58.089243873Z","hostname":"w-01JH8H16QRYG0ZMFS5DSD0AKB7","pid":1241,"":"mend","":"downstairs","":"downstairs","session_id":"c6ee8897-c2f4-4670-a4ae-e3783b6547b6"}
4302025-01-10T16:38:58.395Z{"msg":"First source client ID for extent 2","v":0,"name":"crucible","level":30,"time":"2025-01-10T16:38:58.089291086Z","hostname":"w-01JH8H16QRYG0ZMFS5DSD0AKB7","pid":1241,"mrl":"flush_mismatch","":"mend","":"downstairs","":"downstairs","session_id":"c6ee8897-c2f4-4670-a4ae-e3783b6547b6"}
4312025-01-10T16:38:58.399Z{"msg":"extent:2 gens: 32 32 31","v":0,"name":"crucible","level":30,"time":"2025-01-10T16:38:58.089340758Z","hostname":"w-01JH8H16QRYG0ZMFS5DSD0AKB7","pid":1241,"mrl":"flush_mismatch","":"mend","":"downstairs","":"downstairs","session_id":"c6ee8897-c2f4-4670-a4ae-e3783b6547b6"}
4322025-01-10T16:38:58.399Z{"msg":"extent:2 flush: 1496 1496 1495 scs: [ClientId(0), ClientId(1)]","v":0,"name":"crucible","level":30,"time":"2025-01-10T16:38:58.08939234Z","hostname":"w-01JH8H16QRYG0ZMFS5DSD0AKB7","pid":1241,"mrl":"flush_mismatch","":"mend","":"downstairs","":"downstairs","session_id":"c6ee8897-c2f4-4670-a4ae-e3783b6547b6"}
4332025-01-10T16:38:58.399Z{"msg":"max_flush now has: [ClientId(0), ClientId(1)]","v":0,"name":"crucible","level":30,"time":"2025-01-10T16:38:58.089414747Z","hostname":"w-01JH8H16QRYG0ZMFS5DSD0AKB7","pid":1241,"mrl":"flush_mismatch","":"mend","":"downstairs","":"downstairs","session_id":"c6ee8897-c2f4-4670-a4ae-e3783b6547b6"}
4342025-01-10T16:38:58.399Z{"msg":"extent:2 dirty: false false false","v":0,"name":"crucible","level":30,"time":"2025-01-10T16:38:58.089441723Z","hostname":"w-01JH8H16QRYG0ZMFS5DSD0AKB7","pid":1241,"mrl":"flush_mismatch","":"mend","":"downstairs","":"downstairs","session_id":"c6ee8897-c2f4-4670-a4ae-e3783b6547b6"}
4352025-01-10T16:38:58.399Z{"msg":"No maxes found, left with: [ClientId(0), ClientId(1)]","v":0,"name":"crucible","level":30,"time":"2025-01-10T16:38:58.0894596Z","hostname":"w-01JH8H16QRYG0ZMFS5DSD0AKB7","pid":1241,"mrl":"flush_mismatch","":"mend","":"downstairs","":"downstairs","session_id":"c6ee8897-c2f4-4670-a4ae-e3783b6547b6"}
4362025-01-10T16:38:58.399Z{"msg":"find dest for source 0 for extent at index 2","v":0,"name":"crucible","level":30,"time":"2025-01-10T16:38:58.089476957Z","hostname":"w-01JH8H16QRYG0ZMFS5DSD0AKB7","pid":1241,"mrl":"flush_mismatch","":"mend","":"downstairs","":"downstairs","session_id":"c6ee8897-c2f4-4670-a4ae-e3783b6547b6"}
4372025-01-10T16:38:58.399Z{"msg":"source 0, add dest 2 gen","v":0,"name":"crucible","level":30,"time":"2025-01-10T16:38:58.089494754Z","hostname":"w-01JH8H16QRYG0ZMFS5DSD0AKB7","pid":1241,"mrl":"flush_mismatch","":"mend","":"downstairs","":"downstairs","session_id":"c6ee8897-c2f4-4670-a4ae-e3783b6547b6"}
4382025-01-10T16:38:58.399Z{"msg":"Extent 3 has flush number mismatch","v":0,"name":"crucible","level":30,"time":"2025-01-10T16:38:58.08952368Z","hostname":"w-01JH8H16QRYG0ZMFS5DSD0AKB7","pid":1241,"":"mend","":"downstairs","":"downstairs","session_id":"c6ee8897-c2f4-4670-a4ae-e3783b6547b6"}
4392025-01-10T16:38:58.399Z{"msg":"First source client ID for extent 3","v":0,"name":"crucible","level":30,"time":"2025-01-10T16:38:58.089554255Z","hostname":"w-01JH8H16QRYG0ZMFS5DSD0AKB7","pid":1241,"mrl":"flush_mismatch","":"mend","":"downstairs","":"downstairs","session_id":"c6ee8897-c2f4-4670-a4ae-e3783b6547b6"}
4402025-01-10T16:38:58.399Z{"msg":"extent:3 gens: 32 32 31","v":0,"name":"crucible","level":30,"time":"2025-01-10T16:38:58.089600238Z","hostname":"w-01JH8H16QRYG0ZMFS5DSD0AKB7","pid":1241,"mrl":"flush_mismatch","":"mend","":"downstairs","":"downstairs","session_id":"c6ee8897-c2f4-4670-a4ae-e3783b6547b6"}
4412025-01-10T16:38:58.399Z{"msg":"extent:3 flush: 1496 1496 1495 scs: [ClientId(0), ClientId(1)]","v":0,"name":"crucible","level":30,"time":"2025-01-10T16:38:58.08965053Z","hostname":"w-01JH8H16QRYG0ZMFS5DSD0AKB7","pid":1241,"mrl":"flush_mismatch","":"mend","":"downstairs","":"downstairs","session_id":"c6ee8897-c2f4-4670-a4ae-e3783b6547b6"}
4422025-01-10T16:38:58.399Z{"msg":"max_flush now has: [ClientId(0), ClientId(1)]","v":0,"name":"crucible","level":30,"time":"2025-01-10T16:38:58.089700013Z","hostname":"w-01JH8H16QRYG0ZMFS5DSD0AKB7","pid":1241,"mrl":"flush_mismatch","":"mend","":"downstairs","":"downstairs","session_id":"c6ee8897-c2f4-4670-a4ae-e3783b6547b6"}
4432025-01-10T16:38:58.399Z{"msg":"extent:3 dirty: false false false","v":0,"name":"crucible","level":30,"time":"2025-01-10T16:38:58.089743246Z","hostname":"w-01JH8H16QRYG0ZMFS5DSD0AKB7","pid":1241,"mrl":"flush_mismatch","":"mend","":"downstairs","":"downstairs","session_id":"c6ee8897-c2f4-4670-a4ae-e3783b6547b6"}
4442025-01-10T16:38:58.399Z{"msg":"No maxes found, left with: [ClientId(0), ClientId(1)]","v":0,"name":"crucible","level":30,"time":"2025-01-10T16:38:58.089767842Z","hostname":"w-01JH8H16QRYG0ZMFS5DSD0AKB7","pid":1241,"mrl":"flush_mismatch","":"mend","":"downstairs","":"downstairs","session_id":"c6ee8897-c2f4-4670-a4ae-e3783b6547b6"}
4452025-01-10T16:38:58.399Z{"msg":"find dest for source 0 for extent at index 3","v":0,"name":"crucible","level":30,"time":"2025-01-10T16:38:58.089795298Z","hostname":"w-01JH8H16QRYG0ZMFS5DSD0AKB7","pid":1241,"mrl":"flush_mismatch","":"mend","":"downstairs","":"downstairs","session_id":"c6ee8897-c2f4-4670-a4ae-e3783b6547b6"}
4462025-01-10T16:38:58.399Z{"msg":"source 0, add dest 2 gen","v":0,"name":"crucible","level":30,"time":"2025-01-10T16:38:58.089814195Z","hostname":"w-01JH8H16QRYG0ZMFS5DSD0AKB7","pid":1241,"mrl":"flush_mismatch","":"mend","":"downstairs","":"downstairs","session_id":"c6ee8897-c2f4-4670-a4ae-e3783b6547b6"}
4472025-01-10T16:38:58.399Z{"msg":"Extent 4 has flush number mismatch","v":0,"name":"crucible","level":30,"time":"2025-01-10T16:38:58.089836491Z","hostname":"w-01JH8H16QRYG0ZMFS5DSD0AKB7","pid":1241,"":"mend","":"downstairs","":"downstairs","session_id":"c6ee8897-c2f4-4670-a4ae-e3783b6547b6"}
4482025-01-10T16:38:58.399Z{"msg":"First source client ID for extent 4","v":0,"name":"crucible","level":30,"time":"2025-01-10T16:38:58.089850189Z","hostname":"w-01JH8H16QRYG0ZMFS5DSD0AKB7","pid":1241,"mrl":"flush_mismatch","":"mend","":"downstairs","":"downstairs","session_id":"c6ee8897-c2f4-4670-a4ae-e3783b6547b6"}
4492025-01-10T16:38:58.399Z{"msg":"extent:4 gens: 32 32 31","v":0,"name":"crucible","level":30,"time":"2025-01-10T16:38:58.089864107Z","hostname":"w-01JH8H16QRYG0ZMFS5DSD0AKB7","pid":1241,"mrl":"flush_mismatch","":"mend","":"downstairs","":"downstairs","session_id":"c6ee8897-c2f4-4670-a4ae-e3783b6547b6"}
4502025-01-10T16:38:58.399Z{"msg":"extent:4 flush: 1496 1496 1495 scs: [ClientId(0), ClientId(1)]","v":0,"name":"crucible","level":30,"time":"2025-01-10T16:38:58.089884964Z","hostname":"w-01JH8H16QRYG0ZMFS5DSD0AKB7","pid":1241,"mrl":"flush_mismatch","":"mend","":"downstairs","":"downstairs","session_id":"c6ee8897-c2f4-4670-a4ae-e3783b6547b6"}
4512025-01-10T16:38:58.399Z{"msg":"max_flush now has: [ClientId(0), ClientId(1)]","v":0,"name":"crucible","level":30,"time":"2025-01-10T16:38:58.089899142Z","hostname":"w-01JH8H16QRYG0ZMFS5DSD0AKB7","pid":1241,"mrl":"flush_mismatch","":"mend","":"downstairs","":"downstairs","session_id":"c6ee8897-c2f4-4670-a4ae-e3783b6547b6"}
4522025-01-10T16:38:58.399Z{"msg":"extent:4 dirty: false false false","v":0,"name":"crucible","level":30,"time":"2025-01-10T16:38:58.089912789Z","hostname":"w-01JH8H16QRYG0ZMFS5DSD0AKB7","pid":1241,"mrl":"flush_mismatch","":"mend","":"downstairs","":"downstairs","session_id":"c6ee8897-c2f4-4670-a4ae-e3783b6547b6"}
4532025-01-10T16:38:58.399Z{"msg":"No maxes found, left with: [ClientId(0), ClientId(1)]","v":0,"name":"crucible","level":30,"time":"2025-01-10T16:38:58.089933346Z","hostname":"w-01JH8H16QRYG0ZMFS5DSD0AKB7","pid":1241,"mrl":"flush_mismatch","":"mend","":"downstairs","":"downstairs","session_id":"c6ee8897-c2f4-4670-a4ae-e3783b6547b6"}
4542025-01-10T16:38:58.399Z{"msg":"find dest for source 0 for extent at index 4","v":0,"name":"crucible","level":30,"time":"2025-01-10T16:38:58.089947534Z","hostname":"w-01JH8H16QRYG0ZMFS5DSD0AKB7","pid":1241,"mrl":"flush_mismatch","":"mend","":"downstairs","":"downstairs","session_id":"c6ee8897-c2f4-4670-a4ae-e3783b6547b6"}
4552025-01-10T16:38:58.399Z{"msg":"source 0, add dest 2 gen","v":0,"name":"crucible","level":30,"time":"2025-01-10T16:38:58.089961762Z","hostname":"w-01JH8H16QRYG0ZMFS5DSD0AKB7","pid":1241,"mrl":"flush_mismatch","":"mend","":"downstairs","":"downstairs","session_id":"c6ee8897-c2f4-4670-a4ae-e3783b6547b6"}
4562025-01-10T16:38:58.399Z{"msg":"Transition from WaitQuorum to Reconcile","v":0,"name":"crucible","level":30,"time":"2025-01-10T16:38:58.08997626Z","hostname":"w-01JH8H16QRYG0ZMFS5DSD0AKB7","pid":1241,"client":"0","":"downstairs","session_id":"c6ee8897-c2f4-4670-a4ae-e3783b6547b6"}
4572025-01-10T16:38:58.399Z{"msg":"Transition from WaitQuorum to Reconcile","v":0,"name":"crucible","level":30,"time":"2025-01-10T16:38:58.089989488Z","hostname":"w-01JH8H16QRYG0ZMFS5DSD0AKB7","pid":1241,"client":"1","":"downstairs","session_id":"c6ee8897-c2f4-4670-a4ae-e3783b6547b6"}
4582025-01-10T16:38:58.400Z{"msg":"Transition from WaitQuorum to Reconcile","v":0,"name":"crucible","level":30,"time":"2025-01-10T16:38:58.090031081Z","hostname":"w-01JH8H16QRYG0ZMFS5DSD0AKB7","pid":1241,"client":"2","":"downstairs","session_id":"c6ee8897-c2f4-4670-a4ae-e3783b6547b6"}
4592025-01-10T16:38:58.400Z{"msg":"Full repair list: {ExtentId(1): ExtentFix { source: ClientId(0), dest: [ClientId(2)] }, ExtentId(0): ExtentFix { source: ClientId(0), dest: [ClientId(2)] }, ExtentId(2): ExtentFix { source: ClientId(0), dest: [ClientId(2)] }, ExtentId(3): ExtentFix { source: ClientId(0), dest: [ClientId(2)] }, ExtentId(4): ExtentFix { source: ClientId(0), dest: [ClientId(2)] }}","v":0,"name":"crucible","level":30,"time":"2025-01-10T16:38:58.090051068Z","hostname":"w-01JH8H16QRYG0ZMFS5DSD0AKB7","pid":1241,"":"downstairs","":"downstairs","session_id":"c6ee8897-c2f4-4670-a4ae-e3783b6547b6"}
4602025-01-10T16:38:58.400Z{"msg":"Task list: [ReconcileIO { id: ReconciliationId(0), op: ExtentFlush { repair_id: ReconciliationId(0), extent_id: ExtentId(1), client_id: ClientId(0), flush_number: 1497, gen_number: 33 }, state: ClientData([New, New, New]) }, ReconcileIO { id: ReconciliationId(1), op: ExtentClose { repair_id: ReconciliationId(1), extent_id: ExtentId(1) }, state: ClientData([New, New, New]) }, ReconcileIO { id: ReconciliationId(2), op: ExtentRepair { repair_id: ReconciliationId(2), extent_id: ExtentId(1), source_client_id: ClientId(0), source_repair_address: 0.0.0.0:12810, dest_clients: [ClientId(2)] }, state: ClientData([New, New, New]) }, ReconcileIO { id: ReconciliationId(3), op: ExtentReopen { repair_id: ReconciliationId(3), extent_id: ExtentId(1) }, state: ClientData([New, New, New]) }, ReconcileIO { id: ReconciliationId(4), op: ExtentFlush { repair_id: ReconciliationId(4), extent_id: ExtentId(0), client_id: ClientId(0), flush_number: 1497, gen_number: 33 }, state: ClientData([New, New, New]) }, ReconcileIO { id: ReconciliationId(5), op: ExtentClose { repair_id: ReconciliationId(5), extent_id: ExtentId(0) }, state: ClientData([New, New, New]) }, ReconcileIO { id: ReconciliationId(6), op: ExtentRepair { repair_id: ReconciliationId(6), extent_id: ExtentId(0), source_client_id: ClientId(0), source_repair_address: 0.0.0.0:12810, dest_clients: [ClientId(2)] }, state: ClientData([New, New, New]) }, ReconcileIO { id: ReconciliationId(7), op: ExtentReopen { repair_id: ReconciliationId(7), extent_id: ExtentId(0) }, state: ClientData([New, New, New]) }, ReconcileIO { id: ReconciliationId(8), op: ExtentFlush { repair_id: ReconciliationId(8), extent_id: ExtentId(2), client_id: ClientId(0), flush_number: 1497, gen_number: 33 }, state: ClientData([New, New, New]) }, ReconcileIO { id: ReconciliationId(9), op: ExtentClose { repair_id: ReconciliationId(9), extent_id: ExtentId(2) }, state: ClientData([New, New, New]) }, ReconcileIO { id: ReconciliationId(10), op: ExtentRepair { repair_id: ReconciliationId(10), extent_id: ExtentId(2), source_client_id: ClientId(0), source_repair_address: 0.0.0.0:12810, dest_clients: [ClientId(2)] }, state: ClientData([New, New, New]) }, ReconcileIO { id: ReconciliationId(11), op: ExtentReopen { repair_id: ReconciliationId(11), extent_id: ExtentId(2) }, state: ClientData([New, New, New]) }, ReconcileIO { id: ReconciliationId(12), op: ExtentFlush { repair_id: ReconciliationId(12), extent_id: ExtentId(3), client_id: ClientId(0), flush_number: 1497, gen_number: 33 }, state: ClientData([New, New, New]) }, ReconcileIO { id: ReconciliationId(13), op: ExtentClose { repair_id: ReconciliationId(13), extent_id: ExtentId(3) }, state: ClientData([New, New, New]) }, ReconcileIO { id: ReconciliationId(14), op: ExtentRepair { repair_id: ReconciliationId(14), extent_id: ExtentId(3), source_client_id: ClientId(0), source_repair_address: 0.0.0.0:12810, dest_clients: [ClientId(2)] }, state: ClientData([New, New, New]) }, ReconcileIO { id: ReconciliationId(15), op: ExtentReopen { repair_id: ReconciliationId(15), extent_id: ExtentId(3) }, state: ClientData([New, New, New]) }, ReconcileIO { id: ReconciliationId(16), op: ExtentFlush { repair_id: ReconciliationId(16), extent_id: ExtentId(4), client_id: ClientId(0), flush_number: 1497, gen_number: 33 }, state: ClientData([New, New, New]) }, ReconcileIO { id: ReconciliationId(17), op: ExtentClose { repair_id: ReconciliationId(17), extent_id: ExtentId(4) }, state: ClientData([New, New, New]) }, ReconcileIO { id: ReconciliationId(18), op: ExtentRepair { repair_id: ReconciliationId(18), extent_id: ExtentId(4), source_client_id: ClientId(0), source_repair_address: 0.0.0.0:12810, dest_clients: [ClientId(2)] }, state: ClientData([New, New, New]) }, ReconcileIO { id: ReconciliationId(19), op: ExtentReopen { repair_id: ReconciliationId(19), extent_id: ExtentId(4) }, state: ClientData([New, New, New]) }]","v":0,"name":"crucible","level":30,"time":"2025-01-10T16:38:58.090134835Z","hostname":"w-01JH8H16QRYG0ZMFS5DSD0AKB7","pid":1241,"":"downstairs","":"downstairs","session_id":"c6ee8897-c2f4-4670-a4ae-e3783b6547b6"}
4612025-01-10T16:38:58.400Z{"msg":"starting reconciliation 91b8d4e0-d7b8-417c-bd08-906f7718731f: found 20 extents that need repair","v":0,"name":"crucible","level":30,"time":"2025-01-10T16:38:58.090150272Z","hostname":"w-01JH8H16QRYG0ZMFS5DSD0AKB7","pid":1241,"":"downstairs","":"downstairs","session_id":"c6ee8897-c2f4-4670-a4ae-e3783b6547b6"}
4622025-01-10T16:38:58.400Z{"msg":"no Nexus client from DNS, aborting progress notification","v":0,"name":"crucible","level":50,"time":"2025-01-10T16:38:58.090202934Z","hostname":"w-01JH8H16QRYG0ZMFS5DSD0AKB7","pid":1241,"reconcile":"91b8d4e0-d7b8-417c-bd08-906f7718731f","":"downstairs","":"downstairs","session_id":"c6ee8897-c2f4-4670-a4ae-e3783b6547b6"}
4632025-01-10T16:38:58.400Z{"msg":"no Nexus client from DNS, aborting start notification","v":0,"name":"crucible","level":50,"time":"2025-01-10T16:38:58.090219012Z","hostname":"w-01JH8H16QRYG0ZMFS5DSD0AKB7","pid":1241,"reconcile":"91b8d4e0-d7b8-417c-bd08-906f7718731f","":"downstairs","":"downstairs","session_id":"c6ee8897-c2f4-4670-a4ae-e3783b6547b6"}
4642025-01-10T16:38:58.400Z{"msg":"no Nexus client from DNS, aborting progress notification","v":0,"name":"crucible","level":50,"time":"2025-01-10T16:38:58.09023383Z","hostname":"w-01JH8H16QRYG0ZMFS5DSD0AKB7","pid":1241,"reconcile":"91b8d4e0-d7b8-417c-bd08-906f7718731f","":"downstairs","":"downstairs","session_id":"c6ee8897-c2f4-4670-a4ae-e3783b6547b6"}
4652025-01-10T16:38:58.400Z{"msg":"sending reconcile request ReconciliationId(2)","v":0,"name":"crucible","level":30,"time":"2025-01-10T16:38:58.090255196Z","hostname":"w-01JH8H16QRYG0ZMFS5DSD0AKB7","pid":1241,"client":"2","":"downstairs","session_id":"c6ee8897-c2f4-4670-a4ae-e3783b6547b6"}
4662025-01-10T16:38:58.400Z{"msg":"no Nexus client from DNS, aborting progress notification","v":0,"name":"crucible","level":50,"time":"2025-01-10T16:38:58.090268684Z","hostname":"w-01JH8H16QRYG0ZMFS5DSD0AKB7","pid":1241,"reconcile":"91b8d4e0-d7b8-417c-bd08-906f7718731f","":"downstairs","":"downstairs","session_id":"c6ee8897-c2f4-4670-a4ae-e3783b6547b6"}
4672025-01-10T16:38:58.403Z{"msg":"no Nexus client from DNS, aborting progress notification","v":0,"name":"crucible","level":50,"time":"2025-01-10T16:38:58.098411139Z","hostname":"w-01JH8H16QRYG0ZMFS5DSD0AKB7","pid":1241,"reconcile":"91b8d4e0-d7b8-417c-bd08-906f7718731f","":"downstairs","":"downstairs","session_id":"c6ee8897-c2f4-4670-a4ae-e3783b6547b6"}
4682025-01-10T16:38:58.403Z{"msg":"no Nexus client from DNS, aborting progress notification","v":0,"name":"crucible","level":50,"time":"2025-01-10T16:38:58.098846441Z","hostname":"w-01JH8H16QRYG0ZMFS5DSD0AKB7","pid":1241,"reconcile":"91b8d4e0-d7b8-417c-bd08-906f7718731f","":"downstairs","":"downstairs","session_id":"c6ee8897-c2f4-4670-a4ae-e3783b6547b6"}
4692025-01-10T16:38:58.403Z{"msg":"no Nexus client from DNS, aborting progress notification","v":0,"name":"crucible","level":50,"time":"2025-01-10T16:38:58.099083115Z","hostname":"w-01JH8H16QRYG0ZMFS5DSD0AKB7","pid":1241,"reconcile":"91b8d4e0-d7b8-417c-bd08-906f7718731f","":"downstairs","":"downstairs","session_id":"c6ee8897-c2f4-4670-a4ae-e3783b6547b6"}
4702025-01-10T16:38:58.403Z{"msg":"sending reconcile request ReconciliationId(6)","v":0,"name":"crucible","level":30,"time":"2025-01-10T16:38:58.099416383Z","hostname":"w-01JH8H16QRYG0ZMFS5DSD0AKB7","pid":1241,"client":"2","":"downstairs","session_id":"c6ee8897-c2f4-4670-a4ae-e3783b6547b6"}
4712025-01-10T16:38:58.403Z{"msg":"no Nexus client from DNS, aborting progress notification","v":0,"name":"crucible","level":50,"time":"2025-01-10T16:38:58.099453017Z","hostname":"w-01JH8H16QRYG0ZMFS5DSD0AKB7","pid":1241,"reconcile":"91b8d4e0-d7b8-417c-bd08-906f7718731f","":"downstairs","":"downstairs","session_id":"c6ee8897-c2f4-4670-a4ae-e3783b6547b6"}
4722025-01-10T16:38:58.405Z{"msg":"no Nexus client from DNS, aborting progress notification","v":0,"name":"crucible","level":50,"time":"2025-01-10T16:38:58.102323721Z","hostname":"w-01JH8H16QRYG0ZMFS5DSD0AKB7","pid":1241,"reconcile":"91b8d4e0-d7b8-417c-bd08-906f7718731f","":"downstairs","":"downstairs","session_id":"c6ee8897-c2f4-4670-a4ae-e3783b6547b6"}
4732025-01-10T16:38:58.405Z{"msg":"no Nexus client from DNS, aborting progress notification","v":0,"name":"crucible","level":50,"time":"2025-01-10T16:38:58.10271724Z","hostname":"w-01JH8H16QRYG0ZMFS5DSD0AKB7","pid":1241,"reconcile":"91b8d4e0-d7b8-417c-bd08-906f7718731f","":"downstairs","":"downstairs","session_id":"c6ee8897-c2f4-4670-a4ae-e3783b6547b6"}
4742025-01-10T16:38:58.408Z{"msg":"no Nexus client from DNS, aborting progress notification","v":0,"name":"crucible","level":50,"time":"2025-01-10T16:38:58.102948824Z","hostname":"w-01JH8H16QRYG0ZMFS5DSD0AKB7","pid":1241,"reconcile":"91b8d4e0-d7b8-417c-bd08-906f7718731f","":"downstairs","":"downstairs","session_id":"c6ee8897-c2f4-4670-a4ae-e3783b6547b6"}
4752025-01-10T16:38:58.408Z{"msg":"sending reconcile request ReconciliationId(10)","v":0,"name":"crucible","level":30,"time":"2025-01-10T16:38:58.103281652Z","hostname":"w-01JH8H16QRYG0ZMFS5DSD0AKB7","pid":1241,"client":"2","":"downstairs","session_id":"c6ee8897-c2f4-4670-a4ae-e3783b6547b6"}
4762025-01-10T16:38:58.408Z{"msg":"no Nexus client from DNS, aborting progress notification","v":0,"name":"crucible","level":50,"time":"2025-01-10T16:38:58.103317717Z","hostname":"w-01JH8H16QRYG0ZMFS5DSD0AKB7","pid":1241,"reconcile":"91b8d4e0-d7b8-417c-bd08-906f7718731f","":"downstairs","":"downstairs","session_id":"c6ee8897-c2f4-4670-a4ae-e3783b6547b6"}
4772025-01-10T16:38:58.410Z{"msg":"no Nexus client from DNS, aborting progress notification","v":0,"name":"crucible","level":50,"time":"2025-01-10T16:38:58.106149487Z","hostname":"w-01JH8H16QRYG0ZMFS5DSD0AKB7","pid":1241,"reconcile":"91b8d4e0-d7b8-417c-bd08-906f7718731f","":"downstairs","":"downstairs","session_id":"c6ee8897-c2f4-4670-a4ae-e3783b6547b6"}
4782025-01-10T16:38:58.410Z{"msg":"no Nexus client from DNS, aborting progress notification","v":0,"name":"crucible","level":50,"time":"2025-01-10T16:38:58.106587429Z","hostname":"w-01JH8H16QRYG0ZMFS5DSD0AKB7","pid":1241,"reconcile":"91b8d4e0-d7b8-417c-bd08-906f7718731f","":"downstairs","":"downstairs","session_id":"c6ee8897-c2f4-4670-a4ae-e3783b6547b6"}
4792025-01-10T16:38:58.410Z{"msg":"no Nexus client from DNS, aborting progress notification","v":0,"name":"crucible","level":50,"time":"2025-01-10T16:38:58.106804495Z","hostname":"w-01JH8H16QRYG0ZMFS5DSD0AKB7","pid":1241,"reconcile":"91b8d4e0-d7b8-417c-bd08-906f7718731f","":"downstairs","":"downstairs","session_id":"c6ee8897-c2f4-4670-a4ae-e3783b6547b6"}
4802025-01-10T16:38:58.410Z{"msg":"sending reconcile request ReconciliationId(14)","v":0,"name":"crucible","level":30,"time":"2025-01-10T16:38:58.107106958Z","hostname":"w-01JH8H16QRYG0ZMFS5DSD0AKB7","pid":1241,"client":"2","":"downstairs","session_id":"c6ee8897-c2f4-4670-a4ae-e3783b6547b6"}
4812025-01-10T16:38:58.410Z{"msg":"no Nexus client from DNS, aborting progress notification","v":0,"name":"crucible","level":50,"time":"2025-01-10T16:38:58.107152401Z","hostname":"w-01JH8H16QRYG0ZMFS5DSD0AKB7","pid":1241,"reconcile":"91b8d4e0-d7b8-417c-bd08-906f7718731f","":"downstairs","":"downstairs","session_id":"c6ee8897-c2f4-4670-a4ae-e3783b6547b6"}
4822025-01-10T16:38:58.413Z{"msg":"no Nexus client from DNS, aborting progress notification","v":0,"name":"crucible","level":50,"time":"2025-01-10T16:38:58.109842683Z","hostname":"w-01JH8H16QRYG0ZMFS5DSD0AKB7","pid":1241,"reconcile":"91b8d4e0-d7b8-417c-bd08-906f7718731f","":"downstairs","":"downstairs","session_id":"c6ee8897-c2f4-4670-a4ae-e3783b6547b6"}
4832025-01-10T16:38:58.413Z{"msg":"no Nexus client from DNS, aborting progress notification","v":0,"name":"crucible","level":50,"time":"2025-01-10T16:38:58.110270037Z","hostname":"w-01JH8H16QRYG0ZMFS5DSD0AKB7","pid":1241,"reconcile":"91b8d4e0-d7b8-417c-bd08-906f7718731f","":"downstairs","":"downstairs","session_id":"c6ee8897-c2f4-4670-a4ae-e3783b6547b6"}
4842025-01-10T16:38:58.415Z{"msg":"no Nexus client from DNS, aborting progress notification","v":0,"name":"crucible","level":50,"time":"2025-01-10T16:38:58.110518908Z","hostname":"w-01JH8H16QRYG0ZMFS5DSD0AKB7","pid":1241,"reconcile":"91b8d4e0-d7b8-417c-bd08-906f7718731f","":"downstairs","":"downstairs","session_id":"c6ee8897-c2f4-4670-a4ae-e3783b6547b6"}
4852025-01-10T16:38:58.415Z{"msg":"sending reconcile request ReconciliationId(18)","v":0,"name":"crucible","level":30,"time":"2025-01-10T16:38:58.11082865Z","hostname":"w-01JH8H16QRYG0ZMFS5DSD0AKB7","pid":1241,"client":"2","":"downstairs","session_id":"c6ee8897-c2f4-4670-a4ae-e3783b6547b6"}
4862025-01-10T16:38:58.415Z{"msg":"no Nexus client from DNS, aborting progress notification","v":0,"name":"crucible","level":50,"time":"2025-01-10T16:38:58.110866594Z","hostname":"w-01JH8H16QRYG0ZMFS5DSD0AKB7","pid":1241,"reconcile":"91b8d4e0-d7b8-417c-bd08-906f7718731f","":"downstairs","":"downstairs","session_id":"c6ee8897-c2f4-4670-a4ae-e3783b6547b6"}
4872025-01-10T16:38:58.418Z{"msg":"no Nexus client from DNS, aborting progress notification","v":0,"name":"crucible","level":50,"time":"2025-01-10T16:38:58.113797559Z","hostname":"w-01JH8H16QRYG0ZMFS5DSD0AKB7","pid":1241,"reconcile":"91b8d4e0-d7b8-417c-bd08-906f7718731f","":"downstairs","":"downstairs","session_id":"c6ee8897-c2f4-4670-a4ae-e3783b6547b6"}
4882025-01-10T16:38:58.418Z{"msg":"done with reconciliation","v":0,"name":"crucible","level":30,"time":"2025-01-10T16:38:58.114154243Z","hostname":"w-01JH8H16QRYG0ZMFS5DSD0AKB7","pid":1241,"":"downstairs","":"downstairs","session_id":"c6ee8897-c2f4-4670-a4ae-e3783b6547b6"}
4892025-01-10T16:38:58.418Z{"msg":"Transition from Reconcile to Active","v":0,"name":"crucible","level":30,"time":"2025-01-10T16:38:58.114201446Z","hostname":"w-01JH8H16QRYG0ZMFS5DSD0AKB7","pid":1241,"client":"0","":"downstairs","session_id":"c6ee8897-c2f4-4670-a4ae-e3783b6547b6"}
4902025-01-10T16:38:58.418Z{"msg":"Transition from Reconcile to Active","v":0,"name":"crucible","level":30,"time":"2025-01-10T16:38:58.114232441Z","hostname":"w-01JH8H16QRYG0ZMFS5DSD0AKB7","pid":1241,"client":"1","":"downstairs","session_id":"c6ee8897-c2f4-4670-a4ae-e3783b6547b6"}
4912025-01-10T16:38:58.418Z{"msg":"Transition from Reconcile to Active","v":0,"name":"crucible","level":30,"time":"2025-01-10T16:38:58.114260757Z","hostname":"w-01JH8H16QRYG0ZMFS5DSD0AKB7","pid":1241,"client":"2","":"downstairs","session_id":"c6ee8897-c2f4-4670-a4ae-e3783b6547b6"}
4922025-01-10T16:38:58.418Z{"msg":"All required reconciliation work is completed","v":0,"name":"crucible","level":30,"time":"2025-01-10T16:38:58.114290322Z","hostname":"w-01JH8H16QRYG0ZMFS5DSD0AKB7","pid":1241,"session_id":"c6ee8897-c2f4-4670-a4ae-e3783b6547b6"}
4932025-01-10T16:38:58.418Z{"msg":"Set Downstairs and Upstairs active after reconciliation","v":0,"name":"crucible","level":30Wait for a query_work_queue command to finish before sending IO
4942025-01-10T16:38:58.418Z,"time":"2025-01-10T16:38:58.114332006Z","hostname":"w-01JH8H16QRYG0ZMFS5DSD0AKB7","pid":1241,"session_id":"c6ee8897-c2f4-4670-a4ae-e3783b6547b6"}
4952025-01-10T16:38:58.418Z{"msg":"286764ad-329f-4d09-960d-6fe13dac7f47 is now active with session: c6ee8897-c2f4-4670-a4ae-e3783b6547b6","v":0,"name":"crucible","level":30,"time":"2025-01-10T16:38:58.114378779Z","hostname":"w-01JH8H16QRYG0ZMFS5DSD0AKB7","pid":1241,"session_id":"c6ee8897-c2f4-4670-a4ae-e3783b6547b6"}
4962025-01-10T16:38:58.418Z{"msg":"The guest has finished waiting for activation with:33","v":0,"name":"crucible","level":30,"time":"2025-01-10T16:38:58.114421192Z","hostname":"w-01JH8H16QRYG0ZMFS5DSD0AKB7","pid":1241}
4972025-01-10T16:38:58.418Z{"msg":"no Nexus client from DNS, aborting finish notification","v":0,"name":"crucible","level":50,"time":"2025-01-10T16:38:58.114459476Z","hostname":"w-01JH8H16QRYG0ZMFS5DSD0AKB7","pid":1241,"reconcile":"91b8d4e0-d7b8-417c-bd08-906f7718731f","":"downstairs","":"downstairs","session_id":"c6ee8897-c2f4-4670-a4ae-e3783b6547b6"}
4982025-01-10T16:38:58.418ZDisk: sv:1 bs:4096 ts:204800 tb:50 max_io:50 or 204800
4992025-01-10T16:38:58.418ZLoading write count information from file "/var/tmp/test_up-build/verify_file"
5002025-01-10T16:38:58.418ZRead and Verify all blocks (0..50 range:true)
5012025-01-10T16:38:58.458ZWrote out file "/var/tmp/test_up-build/verify_file"
5022025-01-10T16:38:58.458ZVerify test completed
5032025-01-10T16:38:58.461ZWrote out file "/var/tmp/test_up-build/verify_file"
5042025-01-10T16:38:58.461ZCLIENT: Tests done. All submitted work has been ACK'd
5052025-01-10T16:38:58.461Z----------------------------------------------------------------
5062025-01-10T16:38:58.461Z Crucible gen:33 GIO:true work queues: Upstairs:0 downstairs:1
5072025-01-10T16:38:58.461ZStates: Active Active Active
5082025-01-10T16:38:58.461ZJOBID ACK TYPE BKS/EXT DS:0 DS:1 DS:2 REPLAY
5092025-01-10T16:38:58.461Z 1000 Acked Read 50 Done Done Done false
5102025-01-10T16:38:58.461Z STATES DS:0 DS:1 DS:2 TOTAL
5112025-01-10T16:38:58.461Z Sent 0 0 0 0
5122025-01-10T16:38:58.461Z Done 1 1 1 3
5132025-01-10T16:38:58.461Z Skipped 0 0 0 0
5142025-01-10T16:38:58.461Z Error 0 0 0 0
5152025-01-10T16:38:58.461ZLast Flush: 0 0 0
5162025-01-10T16:38:58.461ZDownstairs last five completed:
5172025-01-10T16:38:58.461ZUpstairs last five completed: 1000
5182025-01-10T16:38:58.461ZCLIENT: Up:0 ds:1 act:3
5192025-01-10T16:39:02.461Z----------------------------------------------------------------
5202025-01-10T16:39:02.461Z Crucible gen:33 GIO:true work queues: Upstairs:0 downstairs:0
5212025-01-10T16:39:02.461ZDownstairs last five completed: 1001 1000
5222025-01-10T16:39:02.461ZUpstairs last five completed: 1001 1000
5232025-01-10T16:39:02.461ZCLIENT: Up:0 ds:0 act:3
5242025-01-10T16:39:02.461ZCLIENT: All crucible jobs finished, exiting program
5252025-01-10T16:39:02.464Z{"msg":"Guest handle has been dropped","v":0,"name":"crucible","level":40,"time":"2025-01-10T16:39:02.157476179Z","hostname":"w-01JH8H16QRYG0ZMFS5DSD0AKB7","pid":1241}
5262025-01-10T16:39:02.468ZRepair part 2 passed
5272025-01-10T16:39:02.471Z/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
5282025-01-10T16:39:02.487ZEXT BLOCKS GEN0 GEN1 GEN2 FL0 FL1 FL2 D0 D1 D2 DIFF
5292025-01-10T16:39:02.488Z 0 000-009 32 32 32 1496 1496 1496 F F F
5302025-01-10T16:39:02.488Z 1 010-019 32 32 32 1496 1496 1496 F F F
5312025-01-10T16:39:02.488Z 2 020-029 32 32 32 1496 1496 1496 F F F
5322025-01-10T16:39:02.488Z 3 030-039 32 32 32 1496 1496 1496 F F F
5332025-01-10T16:39:02.488Z 4 040-049 32 32 32 1496 1496 1496 F F F
5342025-01-10T16:39:02.488ZMax gen: 32, Max flush: 1496
5352025-01-10T16:39:02.493Zdump test passed
5362025-01-10T16:39:02.497Z/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
5372025-01-10T16:39:02.512Z Extent 1
5382025-01-10T16:39:02.515ZGEN 32 32 32
5392025-01-10T16:39:02.515ZFLUSH_ID 1496 1496 1496
5402025-01-10T16:39:02.515ZDIRTY
5412025-01-10T16:39:02.515Z
5422025-01-10T16:39:02.515ZBLOCK D0 D1 D2 C0 C1 C2 DIFF
5432025-01-10T16:39:02.515Z010 A A A A A A
5442025-01-10T16:39:02.518Z011 A A A A A A
5452025-01-10T16:39:02.518Z012 A A A A A A
5462025-01-10T16:39:02.520Z013 A A A A A A
5472025-01-10T16:39:02.520Z014 A A A A A A
5482025-01-10T16:39:02.522Z015 A A A A A A
5492025-01-10T16:39:02.525Z016 A A A A A A
5502025-01-10T16:39:02.525Z017 A A A A A A
5512025-01-10T16:39:02.527Z018 A A A A A A
5522025-01-10T16:39:02.527Z019 A A A A A A
5532025-01-10T16:39:02.532Zdump extent test passed
5542025-01-10T16:39:02.534Z/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
5552025-01-10T16:39:02.550ZExtent 2 Block in extent 0 Actual block 20
5562025-01-10T16:39:02.550Z
5572025-01-10T16:39:02.553Z DATA SHA256 VER
5582025-01-10T16:39:02.553Z------ ---------------------------------------------------------------- ---
5592025-01-10T16:39:02.553Z 0 19623db8257f4c2fe83667827251144622b34d51f80bf3fef3c23ff9fa458eba A
5602025-01-10T16:39:02.553Z 1 19623db8257f4c2fe83667827251144622b34d51f80bf3fef3c23ff9fa458eba A
5612025-01-10T16:39:02.556Z 2 19623db8257f4c2fe83667827251144622b34d51f80bf3fef3c23ff9fa458eba A
5622025-01-10T16:39:02.556Z
5632025-01-10T16:39:02.556ZNONCES 0 1 2 DIFF
5642025-01-10T16:39:02.556Z------ ------------------------ ------------------------ ------------------------ -----
5652025-01-10T16:39:02.556Z 0 502fd9469c56c91345652142 502fd9469c56c91345652142 502fd9469c56c91345652142
5662025-01-10T16:39:02.556Z
5672025-01-10T16:39:02.556Z TAGS 0 1 2 DIFF
5682025-01-10T16:39:02.556Z------ -------------------------------- -------------------------------- -------------------------------- -----
5692025-01-10T16:39:02.556Z 0 a50face04d793be04c0147e739fb4499 a50face04d793be04c0147e739fb4499 a50face04d793be04c0147e739fb4499
5702025-01-10T16:39:02.556Z
5712025-01-10T16:39:02.556ZHASHES 0 1 2 DIFF
5722025-01-10T16:39:02.556Z------ ---------------- ---------------- ---------------- -----
5732025-01-10T16:39:02.556Z
5742025-01-10T16:39:02.558Zdump block test passed
5752025-01-10T16:39:02.561ZInitial upstairs tests have completed, stopping all downstairs
5762025-01-10T16:39:07.626ZCreating 4 larger downstairs regions
5772025-01-10T16:39:07.742ZStarting 4 downstairs
5782025-01-10T16:39:12.750Zdsc restarted at PID: 1254
5792025-01-10T16:39:12.985ZNow do the replace-reconcile test
5802025-01-10T16:39:13.047ZUsing 8840 for the replacement port
5812025-01-10T16:42:19.959ZCompleted test: replace-reconcile
5822025-01-10T16:42:19.959ZNow do the replace-before-active test
5832025-01-10T16:45:26.728ZCompleted test: replace-before-active
5842025-01-10T16:45:26.728ZAll tests have completed, stopping all downstairs
5852025-01-10T16:45:26.789Z
5862025-01-10T16:45:26.789ZAll Tests have passed
5872025-01-10T16:45:26.791Z10:13 Test duration
5882025-01-10T16:45:26.791Z
5892025-01-10T16:45:26.791Zreal 10:13.114974751
5902025-01-10T16:45:26.792Zuser 6:33.456971190
5912025-01-10T16:45:26.792Zsys 12.831407914
5922025-01-10T16:45:26.792Ztrap 0.218413076
5932025-01-10T16:45:26.792Ztflt 0.017313500
5942025-01-10T16:45:26.792Zdflt 0.018586949
5952025-01-10T16:45:26.792Zkflt 0.001098747
5962025-01-10T16:45:26.792Zlock 8:44:20.713351682
5972025-01-10T16:45:26.792Zslp 34:51.775222386
5982025-01-10T16:45:26.792Zlat 24.303200085
5992025-01-10T16:45:26.792Zstop 0.132850643
6002025-01-10T16:45:26.792Z+ echo 'test-up-encrypted ends'
6012025-01-10T16:45:26.792Ztest-up-encrypted ends
6022025-01-10T16:45:31.795Zprocess exited: duration 621362 ms, exit code 0
6032025-01-10T16:45:31.795Zexec warning: : stdio descriptors remain open after task exit; waiting 60 seconds for them to close
6042025-01-10T16:46:31.840Zexec warning: : stdout descriptor may be held open by a background process; giving up!
6052025-01-10T16:46:31.840Zexec warning: : stderr descriptor may be held open by a background process; giving up!
 
6062025-01-10T16:46:31.851Zfound 14 output files
6072025-01-10T16:46:31.851Zuploading: /tmp/test_up-build/dsc-out.txt (41322 bytes)
6082025-01-10T16:46:32.863Zuploaded: /tmp/test_up-build/dsc-out.txt
6092025-01-10T16:46:32.864Zuploading: /tmp/test_up-build/test_up_out.txt (10279117 bytes)
6102025-01-10T16:46:34.043Zuploaded: /tmp/test_up-build/test_up_out.txt
6112025-01-10T16:46:34.047Zuploading: /tmp/test_up-build/dsc/downstairs-8810.txt (253670 bytes)
6122025-01-10T16:46:35.069Zuploaded: /tmp/test_up-build/dsc/downstairs-8810.txt
6132025-01-10T16:46:35.072Zuploading: /tmp/test_up-build/dsc/downstairs-8820.txt (144633 bytes)
6142025-01-10T16:46:36.092Zuploaded: /tmp/test_up-build/dsc/downstairs-8820.txt
6152025-01-10T16:46:36.092Zuploading: /tmp/test_up-build/dsc/downstairs-8830.txt (251105 bytes)
6162025-01-10T16:46:37.117Zuploaded: /tmp/test_up-build/dsc/downstairs-8830.txt
6172025-01-10T16:46:37.120Zuploading: /tmp/test_up-build/dsc/downstairs-8840.txt (139424 bytes)
6182025-01-10T16:46:38.138Zuploaded: /tmp/test_up-build/dsc/downstairs-8840.txt
6192025-01-10T16:46:38.142Zuploading: /tmp/debug/df.txt (1270 bytes)
6202025-01-10T16:46:39.150Zuploaded: /tmp/debug/df.txt
6212025-01-10T16:46:39.150Zuploading: /tmp/debug/dtrace.txt (562043 bytes)
6222025-01-10T16:46:40.189Zuploaded: /tmp/debug/dtrace.txt
6232025-01-10T16:46:40.189Zuploading: /tmp/debug/iostat.txt (203741 bytes)
6242025-01-10T16:46:40.207Zupload warning: file "/tmp/debug/iostat.txt" changed size mid upload: 203741 -> 206141
6252025-01-10T16:46:41.216Zuploaded: /tmp/debug/iostat.txt
6262025-01-10T16:46:41.216Zuploading: /tmp/debug/mpstat.txt (494995 bytes)
6272025-01-10T16:46:41.246Zupload warning: file "/tmp/debug/mpstat.txt" changed size mid upload: 494995 -> 501556
6282025-01-10T16:46:42.253Zuploaded: /tmp/debug/mpstat.txt
6292025-01-10T16:46:42.253Zuploading: /tmp/debug/paging.txt (88829 bytes)
6302025-01-10T16:46:42.266Zupload warning: file "/tmp/debug/paging.txt" changed size mid upload: 88829 -> 90137
6312025-01-10T16:46:43.273Zuploaded: /tmp/debug/paging.txt
6322025-01-10T16:46:43.276Zuploading: /tmp/debug/prstat.txt (949119 bytes)
6332025-01-10T16:46:43.317Zupload warning: file "/tmp/debug/prstat.txt" changed size mid upload: 949119 -> 964665
6342025-01-10T16:46:44.324Zuploaded: /tmp/debug/prstat.txt
6352025-01-10T16:46:44.324Zuploading: /tmp/debug/psrinfo.txt (1528 bytes)
6362025-01-10T16:46:45.332Zuploaded: /tmp/debug/psrinfo.txt
6372025-01-10T16:46:45.332Zuploading: /tmp/debug/upstairs-info.txt (102343 bytes)
6382025-01-10T16:46:46.349Zuploaded: /tmp/debug/upstairs-info.txt