01M3XF94N78JGRXF0D64RJ8HXZ: 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: 01M3XF9T557CE7C35XR2RGQVCR

Tags:

Artefacts:

Output:

SEQ GLOBAL TIME DETAILS
12026-10-02T05:05:17.240Zjob dependencies complete; ready to run (waiting for 12 m 47 s)
22026-10-02T05:06:55.270Zjob assigned to worker 01M3XG2YQ47DAN19ZT48ZEB7HJ [factory aws, i-0b01cd04d3213d14d] (queued for 1 m 38 s)
32026-10-02T05:07:02.629Zdownloading input: /input/build/work/bins/crucible-downstairs.gz
42026-10-02T05:07:04.283Zdownloaded input: /input/build/work/bins/crucible-downstairs.gz
52026-10-02T05:07:04.287Zdownloading input: /input/build/work/bins/crucible-hammer.gz
62026-10-02T05:07:05.857Zdownloaded input: /input/build/work/bins/crucible-hammer.gz
72026-10-02T05:07:05.868Zdownloading input: /input/build/work/bins/crutest.gz
82026-10-02T05:07:07.902Zdownloaded input: /input/build/work/bins/crutest.gz
92026-10-02T05:07:07.907Zdownloading input: /input/build/work/bins/dsc.gz
102026-10-02T05:07:09.434Zdownloaded input: /input/build/work/bins/dsc.gz
112026-10-02T05:07:09.449Zdownloading input: /input/build/work/scripts/perf-downstairs-tick.d
122026-10-02T05:07:09.480Zdownloaded input: /input/build/work/scripts/perf-downstairs-tick.d
132026-10-02T05:07:09.499Zdownloading input: /input/build/work/scripts/test_ds.sh
142026-10-02T05:07:09.522Zdownloaded input: /input/build/work/scripts/test_ds.sh
152026-10-02T05:07:09.523Zdownloading input: /input/build/work/scripts/test_live_repair.sh
162026-10-02T05:07:09.564Zdownloaded input: /input/build/work/scripts/test_live_repair.sh
172026-10-02T05:07:09.572Zdownloading input: /input/build/work/scripts/test_repair.sh
182026-10-02T05:07:09.601Zdownloaded input: /input/build/work/scripts/test_repair.sh
192026-10-02T05:07:09.601Zdownloading input: /input/build/work/scripts/test_replay.sh
202026-10-02T05:07:09.645Zdownloaded input: /input/build/work/scripts/test_replay.sh
212026-10-02T05:07:09.655Zdownloading input: /input/build/work/scripts/test_up.sh
222026-10-02T05:07:09.675Zdownloaded input: /input/build/work/scripts/test_up.sh
232026-10-02T05:07:09.693Zdownloading input: /input/build/work/scripts/upstairs_info.d
242026-10-02T05:07:09.720Zdownloaded input: /input/build/work/scripts/upstairs_info.d
252026-10-02T05:07:09.728Zdownloading input: /input/build/tmp/cargo-test-out.log
262026-10-02T05:07:10.677Zdownloaded input: /input/build/tmp/cargo-test-out.log
 
272026-10-02T05:07:10.677Zstarting task 0: "setup"
282026-10-02T05:07:10.697Z++ uname -s
292026-10-02T05:07:10.697Z+ kern=SunOS
302026-10-02T05:07:10.697Z+ build_user=build
312026-10-02T05:07:10.697Z+ build_uid=12345
322026-10-02T05:07:10.698Z+ work_dir=/work
332026-10-02T05:07:10.698Z+ input_dir=/input
342026-10-02T05:07:10.698Z+ [[ 0 == 12345 ]]
352026-10-02T05:07:10.698Z+ case "$kern" in
362026-10-02T05:07:10.698Z+ groupadd -g 12345 build
372026-10-02T05:07:10.698Z+ useradd -u 12345 -g build -d /home/build -s /bin/bash -c build -P 'Primary Administrator' build
382026-10-02T05:07:12.692Z+ zfs create -o mountpoint=/work rpool/work
392026-10-02T05:07:12.993Z++ awk '$2 == "/home" { print $3 }' /etc/mnttab
402026-10-02T05:07:13.014Z+ home_fs=zfs
412026-10-02T05:07:13.014Z+ [[ zfs == autofs ]]
422026-10-02T05:07:13.015Z+ mkdir -p /home/build
432026-10-02T05:07:13.015Z+ chown build:build /home/build /work
442026-10-02T05:07:14.982Z+ chmod 0700 /home/build /work
452026-10-02T05:07:14.987Zprocess exited: duration 4315 ms, exit code 0
 
462026-10-02T05:07:15.020Zstarting task 1: "authentication"
472026-10-02T05:07:15.042Zprocess exited: duration 17 ms, exit code 0
 
482026-10-02T05:07:15.056Zstarting task 2: "build"
492026-10-02T05:07:15.063Z+ banner cores
502026-10-02T05:07:15.063Z
512026-10-02T05:07:15.063Z #### #### ##### ###### ####
522026-10-02T05:07:15.063Z # # # # # # # #
532026-10-02T05:07:15.063Z # # # # # ##### ####
542026-10-02T05:07:15.063Z # # # ##### # #
552026-10-02T05:07:15.063Z # # # # # # # # #
562026-10-02T05:07:15.063Z #### #### # # ###### ####
572026-10-02T05:07:15.063Z
582026-10-02T05:07:15.064Z+ pfexec coreadm -i /tmp/core.%f.%p -g /tmp/core.%f.%p -e global -e log -e proc-setid -e global-setid
592026-10-02T05:07:15.071Z+ echo 'input bins dir contains:'
602026-10-02T05:07:15.071Zinput bins dir contains:
612026-10-02T05:07:15.071Z+ ls -ltr /input/build/work/bins
622026-10-02T05:07:15.071Ztotal 1031381
632026-10-02T05:07:15.071Z-rw-r--r-- 1 root root 155621399 Oct 2 05:07 crucible-downstairs.gz
642026-10-02T05:07:15.071Z-rw-r--r-- 1 root root 148572045 Oct 2 05:07 crucible-hammer.gz
652026-10-02T05:07:15.071Z-rw-r--r-- 1 root root 154566567 Oct 2 05:07 crutest.gz
662026-10-02T05:07:15.071Z-rw-r--r-- 1 root root 68960740 Oct 2 05:07 dsc.gz
672026-10-02T05:07:15.072Z+ banner unpack
682026-10-02T05:07:15.072Z
692026-10-02T05:07:15.072Z # # # # ##### ## #### # #
702026-10-02T05:07:15.072Z # # ## # # # # # # # # #
712026-10-02T05:07:15.072Z # # # # # # # # # # ####
722026-10-02T05:07:15.072Z # # # # # ##### ###### # # #
732026-10-02T05:07:15.072Z # # # ## # # # # # # #
742026-10-02T05:07:15.072Z #### # # # # # #### # #
752026-10-02T05:07:15.072Z
762026-10-02T05:07:15.072Z+ mkdir -p /var/tmp/bins
772026-10-02T05:07:15.086Z+ for t in "$input/bins/"*.gz
782026-10-02T05:07:15.086Z++ basename /input/build/work/bins/crucible-downstairs.gz
792026-10-02T05:07:15.086Z+ b=crucible-downstairs.gz
802026-10-02T05:07:15.086Z+ b=crucible-downstairs
812026-10-02T05:07:15.086Z+ gunzip
822026-10-02T05:07:17.671Z+ chmod +x /var/tmp/bins/crucible-downstairs
832026-10-02T05:07:17.676Z+ for t in "$input/bins/"*.gz
842026-10-02T05:07:17.676Z++ basename /input/build/work/bins/crucible-hammer.gz
852026-10-02T05:07:17.676Z+ b=crucible-hammer.gz
862026-10-02T05:07:17.676Z+ b=crucible-hammer
872026-10-02T05:07:17.676Z+ gunzip
882026-10-02T05:07:20.128Z+ chmod +x /var/tmp/bins/crucible-hammer
892026-10-02T05:07:20.132Z+ for t in "$input/bins/"*.gz
902026-10-02T05:07:20.133Z++ basename /input/build/work/bins/crutest.gz
912026-10-02T05:07:20.133Z+ b=crutest.gz
922026-10-02T05:07:20.133Z+ b=crutest
932026-10-02T05:07:20.133Z+ gunzip
942026-10-02T05:07:22.709Z+ chmod +x /var/tmp/bins/crutest
952026-10-02T05:07:22.713Z+ for t in "$input/bins/"*.gz
962026-10-02T05:07:22.713Z++ basename /input/build/work/bins/dsc.gz
972026-10-02T05:07:22.713Z+ b=dsc.gz
982026-10-02T05:07:22.713Z+ b=dsc
992026-10-02T05:07:22.713Z+ gunzip
1002026-10-02T05:07:23.855Z+ chmod +x /var/tmp/bins/dsc
1012026-10-02T05:07:23.864Z+ export BINDIR=/var/tmp/bins
1022026-10-02T05:07:23.864Z+ BINDIR=/var/tmp/bins
1032026-10-02T05:07:23.864Z+ export RUST_BACKTRACE=1
1042026-10-02T05:07:23.864Z+ RUST_BACKTRACE=1
1052026-10-02T05:07:23.864Z+ jobpid=1088
1062026-10-02T05:07:23.864Z+ echo 'Setup debug logging'
1072026-10-02T05:07:23.864Z+ mkdir /tmp/debug
1082026-10-02T05:07:23.865ZSetup debug logging
1092026-10-02T05:07:23.865Z+ sleep 3600
1102026-10-02T05:07:23.865Z+ psrinfo -v
1112026-10-02T05:07:23.865Z+ df -h
1122026-10-02T05:07:23.874Z+ prstat -d d -mLc 1
1132026-10-02T05:07:23.874Z+ iostat -T d -xn 1
1142026-10-02T05:07:23.874Z+ mpstat -T d 1
1152026-10-02T05:07:23.874Z+ vmstat -T d -p 1
1162026-10-02T05:07:23.874Z+ pfexec dtrace -Z -s /input/build/work/scripts/perf-downstairs-tick.d
1172026-10-02T05:07:23.874Z+ banner test_up_encrypted
1182026-10-02T05:07:23.874Z+ pfexec dtrace -Z -s /input/build/work/scripts/upstairs_info.d
1192026-10-02T05:07:23.875Z
1202026-10-02T05:07:23.875Z ##### ###### #### ##### # # ##### ###### # #
1212026-10-02T05:07:23.875Z # # # # # # # # # ## #
1222026-10-02T05:07:23.875Z # ##### #### # # # # # ##### # # #
1232026-10-02T05:07:23.875Z # # # # # # ##### # # # #
1242026-10-02T05:07:23.875Z # # # # # # # # # # ##
1252026-10-02T05:07:23.875Z # ###### #### # ####### #### # ####### ###### # #
1262026-10-02T05:07:23.875Z
1272026-10-02T05:07:23.875Z+ ptime -m bash /input/build/work/scripts/test_up.sh -N encrypted
1282026-10-02T05:07:23.885Z/input/build/work
1292026-10-02T05:07:23.894ZTurn off color for downstairs dump
1302026-10-02T05:07:23.907ZUpstairs using key: 56ZdSM6FT+QfRRl60PClQFCd8eE7r61dV2c3E4xGAJ4=
1312026-10-02T05:07:23.921Zdsc output goes to /tmp/test_up-build/dsc-out.txt
1322026-10-02T05:07:23.922ZCreating 3 downstairs regions
1332026-10-02T05:07:24.125ZStarting 3 downstairs
1342026-10-02T05:07:24.137Zdsc started at PID: 1134
1352026-10-02T05:07:29.167ZDisable automatic restart on all downstairs
1362026-10-02T05:07:29.180Z
1372026-10-02T05:07:29.180ZBegin tests, output goes to /tmp/test_up-build/test_up_out.txt
1382026-10-02T05:07:29.185ZRunning test: span
1392026-10-02T05:07:33.274ZCompleted test: span
1402026-10-02T05:07:38.283ZRunning test: big
1412026-10-02T05:07:42.442ZCompleted test: big
1422026-10-02T05:07:47.448ZRunning test: dep
1432026-10-02T05:08:18.568ZCompleted test: dep
1442026-10-02T05:08:23.574ZRunning test: balloon
1452026-10-02T05:08:48.641ZCompleted test: balloon
1462026-10-02T05:08:53.647ZRunning test: deactivate
1472026-10-02T05:08:57.981ZCompleted test: deactivate
1482026-10-02T05:09:02.992ZRunning hammer
1492026-10-02T05:09:10.210ZRun repair tests
1502026-10-02T05:09:10.214Z/var/tmp/bins/crutest fill -g 31 -q --key 56ZdSM6FT+QfRRl60PClQFCd8eE7r61dV2c3E4xGAJ4= --dsc 127.0.0.1:9998 --verify-out /var/tmp/test_up-build/verify_file
1512026-10-02T05:09:10.231Z{"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":"2026-10-02T05:09:08.934589329Z","hostname":"w-01M3XG2YQ47DAN19ZT48ZEB7HJ","pid":1171,"task":"crutest"}
1522026-10-02T05:09:10.236Z{"msg":"dsc has 3 regions. This means 1 sub_volumes","v":0,"name":"crucible","level":30,"time":"2026-10-02T05:09:08.93489725Z","hostname":"w-01M3XG2YQ47DAN19ZT48ZEB7HJ","pid":1171,"task":"crutest"}
1532026-10-02T05:09:10.236Z{"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":"2026-10-02T05:09:08.935495455Z","hostname":"w-01M3XG2YQ47DAN19ZT48ZEB7HJ","pid":1171,"task":"crutest"}
1542026-10-02T05:09:10.236Z{"msg":"Upstairs starts","v":0,"name":"crucible","level":30,"time":"2026-10-02T05:09:08.935753478Z","hostname":"w-01M3XG2YQ47DAN19ZT48ZEB7HJ","pid":1171}
1552026-10-02T05:09:10.236Z{"msg":"Crucible Version: BuildInfo {\n version: \"0.0.1\",\n git_sha: \"f17e50f6faf759d2ca3282ac1efe39527caf16d9\",\n git_commit_timestamp: \"2026-10-02T04:51:42.000000000Z\",\n git_branch: \"renovate/tokio-rustls-0.x\",\n rustc_semver: \"1.90.0\",\n rustc_channel: \"stable\",\n rustc_host_triple: \"x86_64-unknown-illumos\",\n rustc_commit_sha: \"1159e78c4747b02ef996e55082b704c09b970588\",\n cargo_triple: \"x86_64-unknown-illumos\",\n debug: true,\n opt_level: 0,\n}","v":0,"name":"crucible","level":30,"time":"2026-10-02T05:09:08.93578663Z","hostname":"w-01M3XG2YQ47DAN19ZT48ZEB7HJ","pid":1171}
1562026-10-02T05:09:10.236Z{"msg":"Upstairs <-> Downstairs Message Version: 13","v":0,"name":"crucible","level":30,"time":"2026-10-02T05:09:08.935799887Z","hostname":"w-01M3XG2YQ47DAN19ZT48ZEB7HJ","pid":1171}
1572026-10-02T05:09:10.236Z{"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":"2026-10-02T05:09:08.935812134Z","hostname":"w-01M3XG2YQ47DAN19ZT48ZEB7HJ","pid":1171}
1582026-10-02T05:09:10.236Z{"msg":"Crucible 2e75944b-d9db-4ae8-a100-f71634bdb04b has session id: 6fc4c38c-15df-4a04-82df-5f04e68b6865","v":0,"name":"crucible","level":30,"time":"2026-10-02T05:09:08.936193569Z","hostname":"w-01M3XG2YQ47DAN19ZT48ZEB7HJ","pid":1171,"session_id":"6fc4c38c-15df-4a04-82df-5f04e68b6865"}
1592026-10-02T05:09:10.236Z{"msg":"Upstairs opts: Upstairs UUID: 2e75944b-d9db-4ae8-a100-f71634bdb04b, 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":"2026-10-02T05:09:08.936221673Z","hostname":"w-01M3XG2YQ47DAN19ZT48ZEB7HJ","pid":1171,"session_id":"6fc4c38c-15df-4a04-82df-5f04e68b6865"}
1602026-10-02T05:09:10.236Z{"msg":"Crucible stats registered with UUID: 2e75944b-d9db-4ae8-a100-f71634bdb04b","v":0,"name":"crucible","level":30,"time":"2026-10-02T05:09:08.936236159Z","hostname":"w-01M3XG2YQ47DAN19ZT48ZEB7HJ","pid":1171,"session_id":"6fc4c38c-15df-4a04-82df-5f04e68b6865"}
1612026-10-02T05:09:10.236Z{"msg":"could not find Downstairs address for Nexus","v":0,"name":"crucible","level":40,"time":"2026-10-02T05:09:08.936246307Z","hostname":"w-01M3XG2YQ47DAN19ZT48ZEB7HJ","pid":1171,"session_id":"6fc4c38c-15df-4a04-82df-5f04e68b6865"}
1622026-10-02T05:09:10.236Z{"msg":"client is waiting for oneshot","v":0,"name":"crucible","level":30,"time":"2026-10-02T05:09:08.936401582Z","hostname":"w-01M3XG2YQ47DAN19ZT48ZEB7HJ","pid":1171,"":"io task","client":"1","":"downstairs","session_id":"6fc4c38c-15df-4a04-82df-5f04e68b6865"}
1632026-10-02T05:09:10.236Z{"msg":"client is waiting for oneshot","v":0,"name":"crucible","level":30,"time":"2026-10-02T05:09:08.936434615Z","hostname":"w-01M3XG2YQ47DAN19ZT48ZEB7HJ","pid":1171,"":"io task","client":"2","":"downstairs","session_id":"6fc4c38c-15df-4a04-82df-5f04e68b6865"}
1642026-10-02T05:09:10.236Z{"msg":"client is waiting for oneshot","v":0,"name":"crucible","level":30,"time":"2026-10-02T05:09:08.936446152Z","hostname":"w-01M3XG2YQ47DAN19ZT48ZEB7HJ","pid":1171,"":"io task","client":"0","":"downstairs","session_id":"6fc4c38c-15df-4a04-82df-5f04e68b6865"}
1652026-10-02T05:09:10.236Z{"msg":"Downstairs in volume = 3","v":0,"name":"crucible","level":30,"time":"2026-10-02T05:09:08.936613885Z","hostname":"w-01M3XG2YQ47DAN19ZT48ZEB7HJ","pid":1171,"task":"crutest"}
1662026-10-02T05:09:10.236Z{"msg":"The guest has requested activation with gen:31","v":0,"name":"crucible","level":30,"time":"2026-10-02T05:09:08.936628731Z","hostname":"w-01M3XG2YQ47DAN19ZT48ZEB7HJ","pid":1171}
1672026-10-02T05:09:10.236Z{"msg":"2e75944b-d9db-4ae8-a100-f71634bdb04b active request set","v":0,"name":"crucible","level":30,"time":"2026-10-02T05:09:08.936668592Z","hostname":"w-01M3XG2YQ47DAN19ZT48ZEB7HJ","pid":1171,"session_id":"6fc4c38c-15df-4a04-82df-5f04e68b6865"}
1682026-10-02T05:09:10.236Z{"msg":"sending connect oneshot to client","v":0,"name":"crucible","level":30,"time":"2026-10-02T05:09:08.936692597Z","hostname":"w-01M3XG2YQ47DAN19ZT48ZEB7HJ","pid":1171,"client":"0","":"downstairs","session_id":"6fc4c38c-15df-4a04-82df-5f04e68b6865"}
1692026-10-02T05:09:10.236Z{"msg":"sending connect oneshot to client","v":0,"name":"crucible","level":30,"time":"2026-10-02T05:09:08.936703974Z","hostname":"w-01M3XG2YQ47DAN19ZT48ZEB7HJ","pid":1171,"client":"1","":"downstairs","session_id":"6fc4c38c-15df-4a04-82df-5f04e68b6865"}
1702026-10-02T05:09:10.236Z{"msg":"sending connect oneshot to client","v":0,"name":"crucible","level":30,"time":"2026-10-02T05:09:08.936714752Z","hostname":"w-01M3XG2YQ47DAN19ZT48ZEB7HJ","pid":1171,"client":"2","":"downstairs","session_id":"6fc4c38c-15df-4a04-82df-5f04e68b6865"}
1712026-10-02T05:09:10.236Z{"msg":"connecting to 127.0.0.1:8830","v":0,"name":"crucible","level":30,"time":"2026-10-02T05:09:08.93672534Z","hostname":"w-01M3XG2YQ47DAN19ZT48ZEB7HJ","pid":1171,"":"io task","client":"2","":"downstairs","session_id":"6fc4c38c-15df-4a04-82df-5f04e68b6865"}
1722026-10-02T05:09:10.237Z{"msg":"connecting to 127.0.0.1:8810","v":0,"name":"crucible","level":30,"time":"2026-10-02T05:09:08.936736237Z","hostname":"w-01M3XG2YQ47DAN19ZT48ZEB7HJ","pid":1171,"":"io task","client":"0","":"downstairs","session_id":"6fc4c38c-15df-4a04-82df-5f04e68b6865"}
1732026-10-02T05:09:10.237Z{"msg":"connecting to 127.0.0.1:8820","v":0,"name":"crucible","level":30,"time":"2026-10-02T05:09:08.936746895Z","hostname":"w-01M3XG2YQ47DAN19ZT48ZEB7HJ","pid":1171,"":"io task","client":"1","":"downstairs","session_id":"6fc4c38c-15df-4a04-82df-5f04e68b6865"}
1742026-10-02T05:09:10.237Z{"msg":"ds_connection connected from Ok(127.0.0.1:52603)","v":0,"name":"crucible","level":30,"time":"2026-10-02T05:09:08.936853091Z","hostname":"w-01M3XG2YQ47DAN19ZT48ZEB7HJ","pid":1171,"":"io task","client":"0","":"downstairs","session_id":"6fc4c38c-15df-4a04-82df-5f04e68b6865"}
1752026-10-02T05:09:10.237Z{"msg":"ds_connection connected from Ok(127.0.0.1:39638)","v":0,"name":"crucible","level":30,"time":"2026-10-02T05:09:08.937005517Z","hostname":"w-01M3XG2YQ47DAN19ZT48ZEB7HJ","pid":1171,"":"io task","client":"1","":"downstairs","session_id":"6fc4c38c-15df-4a04-82df-5f04e68b6865"}
1762026-10-02T05:09:10.237Z{"msg":"ds_connection connected from Ok(127.0.0.1:59803)","v":0,"name":"crucible","level":30,"time":"2026-10-02T05:09:08.937074111Z","hostname":"w-01M3XG2YQ47DAN19ZT48ZEB7HJ","pid":1171,"":"io task","client":"2","":"downstairs","session_id":"6fc4c38c-15df-4a04-82df-5f04e68b6865"}
1772026-10-02T05:09:10.237Z{"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":"2026-10-02T05:09:08.937537168Z","hostname":"w-01M3XG2YQ47DAN19ZT48ZEB7HJ","pid":1171,"client":"0","":"downstairs","session_id":"6fc4c38c-15df-4a04-82df-5f04e68b6865"}
1782026-10-02T05:09:10.237Z{"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":"2026-10-02T05:09:08.937555213Z","hostname":"w-01M3XG2YQ47DAN19ZT48ZEB7HJ","pid":1171,"client":"1","":"downstairs","session_id":"6fc4c38c-15df-4a04-82df-5f04e68b6865"}
1792026-10-02T05:09:10.237Z{"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":"2026-10-02T05:09:08.937566611Z","hostname":"w-01M3XG2YQ47DAN19ZT48ZEB7HJ","pid":1171,"client":"2","":"downstairs","session_id":"6fc4c38c-15df-4a04-82df-5f04e68b6865"}
1802026-10-02T05:09:10.237Z{"msg":"Waiting for more clients to be ready","v":0,"name":"crucible","level":30,"time":"2026-10-02T05:09:08.937733464Z","hostname":"w-01M3XG2YQ47DAN19ZT48ZEB7HJ","pid":1171,"session_id":"6fc4c38c-15df-4a04-82df-5f04e68b6865"}
1812026-10-02T05:09:10.237Z{"msg":"Waiting for more clients to be ready","v":0,"name":"crucible","level":30,"time":"2026-10-02T05:09:08.93774949Z","hostname":"w-01M3XG2YQ47DAN19ZT48ZEB7HJ","pid":1171,"session_id":"6fc4c38c-15df-4a04-82df-5f04e68b6865"}
1822026-10-02T05:09:10.237Z{"msg":"[0]R flush_numbers: [1500, 1500, 1500, 1500, 1500]","v":0,"name":"crucible","level":30,"time":"2026-10-02T05:09:08.937776274Z","hostname":"w-01M3XG2YQ47DAN19ZT48ZEB7HJ","pid":1171,"":"downstairs","":"downstairs","session_id":"6fc4c38c-15df-4a04-82df-5f04e68b6865"}
1832026-10-02T05:09:10.237Z{"msg":"[0]R generation: [25, 25, 25, 25, 25]","v":0,"name":"crucible","level":30,"time":"2026-10-02T05:09:08.937787451Z","hostname":"w-01M3XG2YQ47DAN19ZT48ZEB7HJ","pid":1171,"":"downstairs","":"downstairs","session_id":"6fc4c38c-15df-4a04-82df-5f04e68b6865"}
1842026-10-02T05:09:10.237Z{"msg":"[0]R dirty: [false, false, false, false, false]","v":0,"name":"crucible","level":30,"time":"2026-10-02T05:09:08.937798439Z","hostname":"w-01M3XG2YQ47DAN19ZT48ZEB7HJ","pid":1171,"":"downstairs","":"downstairs","session_id":"6fc4c38c-15df-4a04-82df-5f04e68b6865"}
1852026-10-02T05:09:10.237Z{"msg":"[1]R flush_numbers: [1500, 1500, 1500, 1500, 1500]","v":0,"name":"crucible","level":30,"time":"2026-10-02T05:09:08.937809167Z","hostname":"w-01M3XG2YQ47DAN19ZT48ZEB7HJ","pid":1171,"":"downstairs","":"downstairs","session_id":"6fc4c38c-15df-4a04-82df-5f04e68b6865"}
1862026-10-02T05:09:10.237Z{"msg":"[1]R generation: [25, 25, 25, 25, 25]","v":0,"name":"crucible","level":30,"time":"2026-10-02T05:09:08.937819604Z","hostname":"w-01M3XG2YQ47DAN19ZT48ZEB7HJ","pid":1171,"":"downstairs","":"downstairs","session_id":"6fc4c38c-15df-4a04-82df-5f04e68b6865"}
1872026-10-02T05:09:10.237Z{"msg":"[1]R dirty: [false, false, false, false, false]","v":0,"name":"crucible","level":30,"time":"2026-10-02T05:09:08.937830182Z","hostname":"w-01M3XG2YQ47DAN19ZT48ZEB7HJ","pid":1171,"":"downstairs","":"downstairs","session_id":"6fc4c38c-15df-4a04-82df-5f04e68b6865"}
1882026-10-02T05:09:10.237Z{"msg":"[2]R flush_numbers: [1500, 1500, 1500, 1500, 1500]","v":0,"name":"crucible","level":30,"time":"2026-10-02T05:09:08.937840679Z","hostname":"w-01M3XG2YQ47DAN19ZT48ZEB7HJ","pid":1171,"":"downstairs","":"downstairs","session_id":"6fc4c38c-15df-4a04-82df-5f04e68b6865"}
1892026-10-02T05:09:10.237Z{"msg":"[2]R generation: [25, 25, 25, 25, 25]","v":0,"name":"crucible","level":30,"time":"2026-10-02T05:09:08.937851057Z","hostname":"w-01M3XG2YQ47DAN19ZT48ZEB7HJ","pid":1171,"":"downstairs","":"downstairs","session_id":"6fc4c38c-15df-4a04-82df-5f04e68b6865"}
1902026-10-02T05:09:10.237Z{"msg":"[2]R dirty: [false, false, false, false, false]","v":0,"name":"crucible","level":30,"time":"2026-10-02T05:09:08.937860915Z","hostname":"w-01M3XG2YQ47DAN19ZT48ZEB7HJ","pid":1171,"":"downstairs","":"downstairs","session_id":"6fc4c38c-15df-4a04-82df-5f04e68b6865"}
1912026-10-02T05:09:10.237Z{"msg":"Max found gen is 26","v":0,"name":"crucible","level":30,"time":"2026-10-02T05:09:08.937870733Z","hostname":"w-01M3XG2YQ47DAN19ZT48ZEB7HJ","pid":1171,"":"downstairs","":"downstairs","session_id":"6fc4c38c-15df-4a04-82df-5f04e68b6865"}
1922026-10-02T05:09:10.237Z{"msg":"Generation requested: 31 >= found:26","v":0,"name":"crucible","level":30,"time":"2026-10-02T05:09:08.93788139Z","hostname":"w-01M3XG2YQ47DAN19ZT48ZEB7HJ","pid":1171,"":"downstairs","":"downstairs","session_id":"6fc4c38c-15df-4a04-82df-5f04e68b6865"}
1932026-10-02T05:09:10.237Z{"msg":"Next flush: 1501","v":0,"name":"crucible","level":30,"time":"2026-10-02T05:09:08.937891278Z","hostname":"w-01M3XG2YQ47DAN19ZT48ZEB7HJ","pid":1171,"":"downstairs","":"downstairs","session_id":"6fc4c38c-15df-4a04-82df-5f04e68b6865"}
1942026-10-02T05:09:10.237Z{"msg":"All extents match","v":0,"name":"crucible","level":30,"time":"2026-10-02T05:09:08.937901836Z","hostname":"w-01M3XG2YQ47DAN19ZT48ZEB7HJ","pid":1171,"":"downstairs","":"downstairs","session_id":"6fc4c38c-15df-4a04-82df-5f04e68b6865"}
1952026-10-02T05:09:10.237Z{"msg":"No downstairs reconciliation required","v":0,"name":"crucible","level":30,"time":"2026-10-02T05:09:08.937912433Z","hostname":"w-01M3XG2YQ47DAN19ZT48ZEB7HJ","pid":1171,"session_id":"6fc4c38c-15df-4a04-82df-5f04e68b6865"}
1962026-10-02T05:09:10.237Z{"msg":"Transition from WaitQuorum to Active","v":0,"name":"crucible","level":30,"time":"2026-10-02T05:09:08.937921961Z","hostname":"w-01M3XG2YQ47DAN19ZT48ZEB7HJ","pid":1171,"client":"0","":"downstairs","session_id":"6fc4c38c-15df-4a04-82df-5f04e68b6865"}
1972026-10-02T05:09:10.237Z{"msg":"Transition from WaitQuorum to Active","v":0,"name":"crucible","level":30,"time":"2026-10-02T05:09:08.937932149Z","hostname":"w-01M3XG2YQ47DAN19ZT48ZEB7HJ","pid":1171,"client":"1","":"downstairs","session_id":"6fc4c38c-15df-4a04-82df-5f04e68b6865"}
1982026-10-02T05:09:10.237Z{"msg":"Transition from WaitQuorum to Active","v":0,"name":"crucible","level":30,"time":"2026-10-02T05:09:08.937942297Z","hostname":"w-01M3XG2YQ47DAN19ZT48ZEB7HJ","pid":1171,"client":"2","":"downstairs","session_id":"6fc4c38c-15df-4a04-82df-5f04e68b6865"}
1992026-10-02T05:09:10.238Z{"msg":"All required reconciliation work is completed","v":0,"name":"crucible","level":30,"time":"2026-10-02T05:09:08.937952604Z","hostname":"w-01M3XG2YQ47DAN19ZT48ZEB7HJ","pid":1171,"session_id":"6fc4c38c-15df-4a04-82df-5f04e68b6865"}
2002026-10-02T05:09:10.238Z{"msg":"Set Downstairs and Upstairs active after reconciliation","v":0,"name":"crucible","level":30,"time":"2026-10-02T05:09:08.937962432Z","hostname":"w-01M3XG2YQ47DAN19ZT48ZEB7HJ","pid":1171,"session_id":"6fc4c38c-15df-4a04-82df-5f04e68b6865"}
2012026-10-02T05:09:10.238Z{"msg":"2e75944b-d9db-4ae8-a100-f71634bdb04b is now active with session: 6fc4c38c-15df-4a04-82df-5f04e68b6865","v":0,"name":"crucible","level":30,"time":"2026-10-02T05:09:08.93797324Z","hostname":"w-01M3XG2YQ47DAN19ZT48ZEB7HJ","pid":1171,"session_id":"6fc4c38c-15df-4a04-82df-5f04e68b6865"}
2022026-10-02T05:09:10.238Z{"msg":"Set Active after no reconciliation","v":0,"name":"crucible","level":30,"time":"2026-10-02T05:09:08.937982588Z","hostname":"w-01M3XG2YQ47DAN19ZT48ZEB7HJ","pid":1171,"session_id":"6fc4c38c-15df-4a04-82df-5f04e68b6865"}
2032026-10-02T05:09:10.238Z{"msg":"The guest has finished waiting for activation with:31","v":0,"name":"crucible","level":30,"time":"2026-10-02T05:09:08.937992905Z","hostname":"w-01M3XG2YQ47DAN19ZT48ZEB7HJ","pid":1171}
2042026-10-02T05:09:10.238Z{"msg":"Activated sub_volume 2e75944b-d9db-4ae8-a100-f71634bdb04b","v":0,"name":"crucible","level":30,"time":"2026-10-02T05:09:08.938001653Z","hostname":"w-01M3XG2YQ47DAN19ZT48ZEB7HJ","pid":1171}
2052026-10-02T05:09:10.238Z{"msg":"Wait for a query_work_queue command to finish before sending IO","v":0,"name":"crucible","level":30,"time":"2026-10-02T05:09:08.938010361Z","hostname":"w-01M3XG2YQ47DAN19ZT48ZEB7HJ","pid":1171,"task":"crutest"}
2062026-10-02T05:09:10.238ZDisk: sv:1 bs:4096 ts:204800 tb:50 max_io:50 or 204800
2072026-10-02T05:09:10.241Z{"msg":"Fill test","v":0,"name":"crucible","level":30,"time":"2026-10-02T05:09:08.93805981Z","hostname":"w-01M3XG2YQ47DAN19ZT48ZEB7HJ","pid":1171,"task":"crutest"}
2082026-10-02T05:09:10.258ZRead and Verify all blocks (0..50 range:false)
2092026-10-02T05:09:10.285Z{"msg":"Wrote out file \"/var/tmp/test_up-build/verify_file\"","v":0,"name":"crucible","level":30,"time":"2026-10-02T05:09:08.986417217Z"----------------------------------------------------------------
2102026-10-02T05:09:10.285Z,"hostname":"w-01M3XG2YQ47DAN19ZT48ZEB7HJ","pid":1171," Crucible gen:31 GIO:true work queues: Upstairs:0 downstairs:1
2112026-10-02T05:09:10.285ZtaskStates:":"crutest" Active} Active
2122026-10-02T05:09:10.285Z Active
2132026-10-02T05:09:10.289Z{JOBID ACK TYPE BKS/EXT DS:0 DS:1 DS:2 REPLAY
2142026-10-02T05:09:10.289Z"msg":"CLIENT: Tests done. All submitted work has been ACK'd","v" 1002 Acked Read 50:0 Done, Done" Done falsename"
2152026-10-02T05:09:10.289Z:"crucible","level":30 STATES DS:0 DS:1 DS:2 TOTAL
2162026-10-02T05:09:10.289Z Sent 0 0 0 0
2172026-10-02T05:09:10.289Z, Done " 1 time": 1 " 1 3
2182026-10-02T05:09:10.289Z2026-10-02T05:09:08.986458408Z Skipped " 0 , 0 " 0 0
2192026-10-02T05:09:10.289Zhostname":" Error 0 0 0 0
2202026-10-02T05:09:10.289Zw-01M3XG2YQ47DAN19ZT48ZEB7HJ","Last Flush: pid":Some(JobId(1001)) 1171Some(JobId(1001)) ,Some(JobId(1001)) "
2212026-10-02T05:09:10.289Ztask"Downstairs last five completed::"crutest"}
2222026-10-02T05:09:10.289Z 1001 1000
2232026-10-02T05:09:10.289ZUpstairs last five completed: 1002 1001 1000
2242026-10-02T05:09:10.289Z{"msg":"CLIENT: Up:0 ds:1 act:3","v":0,"name":"crucible","level":30,"time":"2026-10-02T05:09:08.986507277Z","hostname":"w-01M3XG2YQ47DAN19ZT48ZEB7HJ","pid":1171,"task":"crutest"}
2252026-10-02T05:09:14.285Z----------------------------------------------------------------
2262026-10-02T05:09:14.285Z Crucible gen:31 GIO:true work queues: Upstairs:0 downstairs:0
2272026-10-02T05:09:14.285ZDownstairs last five completed: 1003 1002 1001 1000
2282026-10-02T05:09:14.285ZUpstairs last five completed: 1003 1002 1001 1000
2292026-10-02T05:09:14.288Z{"msg":"CLIENT: Up:0 ds:0 act:3","v":0,"name":"crucible","level":30,"time":"2026-10-02T05:09:12.987513906Z","hostname":"w-01M3XG2YQ47DAN19ZT48ZEB7HJ","pid":1171,"task":"crutest"}
2302026-10-02T05:09:14.288Z{"msg":"CLIENT: All crucible jobs finished, exiting program","v":0,"name":"crucible","level":30,"time":"2026-10-02T05:09:12.987555337Z","hostname":"w-01M3XG2YQ47DAN19ZT48ZEB7HJ","pid":1171,"task":"crutest"}
2312026-10-02T05:09:14.288Z{"msg":"Guest handle has been dropped","v":0,"name":"crucible","level":40,"time":"2026-10-02T05:09:12.987565745Z","hostname":"w-01M3XG2YQ47DAN19ZT48ZEB7HJ","pid":1171}
2322026-10-02T05:09:14.292ZRepair setup passed
2332026-10-02T05:09:14.294ZCopy the region for /var/tmp/test_up-build/8830
2342026-10-02T05:09:14.297Zcp -r /var/tmp/test_up-build/8830 /var/tmp/test_up-build/previous
2352026-10-02T05:09:14.297Z/var/tmp/bins/crutest fill -g 32 -q --key 56ZdSM6FT+QfRRl60PClQFCd8eE7r61dV2c3E4xGAJ4= --dsc 127.0.0.1:9998 --verify-out /var/tmp/test_up-build/verify_file --verify-in /var/tmp/test_up-build/verify_file
2362026-10-02T05:09:14.316Z{"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":"2026-10-02T05:09:13.01831218Z","hostname":"w-01M3XG2YQ47DAN19ZT48ZEB7HJ","pid":1177,"task":"crutest"}
2372026-10-02T05:09:14.319Z{"msg":"dsc has 3 regions. This means 1 sub_volumes","v":0,"name":"crucible","level":30,"time":"2026-10-02T05:09:13.018693735Z","hostname":"w-01M3XG2YQ47DAN19ZT48ZEB7HJ","pid":1177,"task":"crutest"}
2382026-10-02T05:09:14.319Z{"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":"2026-10-02T05:09:13.019413693Z","hostname":"w-01M3XG2YQ47DAN19ZT48ZEB7HJ","pid":1177,"task":"crutest"}
2392026-10-02T05:09:14.319Z{"msg":"Upstairs starts","v":0,"name":"crucible","level":30,"time":"2026-10-02T05:09:13.019666007Z","hostname":"w-01M3XG2YQ47DAN19ZT48ZEB7HJ","pid":1177}
2402026-10-02T05:09:14.319Z{"msg":"Crucible Version: BuildInfo {\n version: \"0.0.1\",\n git_sha: \"f17e50f6faf759d2ca3282ac1efe39527caf16d9\",\n git_commit_timestamp: \"2026-10-02T04:51:42.000000000Z\",\n git_branch: \"renovate/tokio-rustls-0.x\",\n rustc_semver: \"1.90.0\",\n rustc_channel: \"stable\",\n rustc_host_triple: \"x86_64-unknown-illumos\",\n rustc_commit_sha: \"1159e78c4747b02ef996e55082b704c09b970588\",\n cargo_triple: \"x86_64-unknown-illumos\",\n debug: true,\n opt_level: 0,\n}","v":0,"name":"crucible","level":30,"time":"2026-10-02T05:09:13.019693061Z","hostname":"w-01M3XG2YQ47DAN19ZT48ZEB7HJ","pid":1177}
2412026-10-02T05:09:14.319Z{"msg":"Upstairs <-> Downstairs Message Version: 13","v":0,"name":"crucible","level":30,"time":"2026-10-02T05:09:13.019702539Z","hostname":"w-01M3XG2YQ47DAN19ZT48ZEB7HJ","pid":1177}
2422026-10-02T05:09:14.319Z{"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":"2026-10-02T05:09:13.019714966Z","hostname":"w-01M3XG2YQ47DAN19ZT48ZEB7HJ","pid":1177}
2432026-10-02T05:09:14.319Z{"msg":"Crucible 951dc8a7-43fb-40df-b5d0-9117db471eba has session id: 4e6cbc62-51c5-4515-97b7-337972dcf072","v":0,"name":"crucible","level":30,"time":"2026-10-02T05:09:13.020113806Z","hostname":"w-01M3XG2YQ47DAN19ZT48ZEB7HJ","pid":1177,"session_id":"4e6cbc62-51c5-4515-97b7-337972dcf072"}
2442026-10-02T05:09:14.319Z{"msg":"Upstairs opts: Upstairs UUID: 951dc8a7-43fb-40df-b5d0-9117db471eba, 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":"2026-10-02T05:09:13.020157627Z","hostname":"w-01M3XG2YQ47DAN19ZT48ZEB7HJ","pid":1177,"session_id":"4e6cbc62-51c5-4515-97b7-337972dcf072"}
2452026-10-02T05:09:14.319Z{"msg":"Crucible stats registered with UUID: 951dc8a7-43fb-40df-b5d0-9117db471eba","v":0,"name":"crucible","level":30,"time":"2026-10-02T05:09:13.020173743Z","hostname":"w-01M3XG2YQ47DAN19ZT48ZEB7HJ","pid":1177,"session_id":"4e6cbc62-51c5-4515-97b7-337972dcf072"}
2462026-10-02T05:09:14.319Z{"msg":"could not find Downstairs address for Nexus","v":0,"name":"crucible","level":40,"time":"2026-10-02T05:09:13.020183311Z","hostname":"w-01M3XG2YQ47DAN19ZT48ZEB7HJ","pid":1177,"session_id":"4e6cbc62-51c5-4515-97b7-337972dcf072"}
2472026-10-02T05:09:14.319Z{"msg":"client is waiting for oneshot","v":0,"name":"crucible","level":30,"time":"2026-10-02T05:09:13.020289017Z","hostname":"w-01M3XG2YQ47DAN19ZT48ZEB7HJ","pid":1177,"":"io task","client":"1","":"downstairs","session_id":"4e6cbc62-51c5-4515-97b7-337972dcf072"}
2482026-10-02T05:09:14.319Z{"msg":"client is waiting for oneshot","v":0,"name":"crucible","level":30,"time":"2026-10-02T05:09:13.020310862Z","hostname":"w-01M3XG2YQ47DAN19ZT48ZEB7HJ","pid":1177,"":"io task","client":"2","":"downstairs","session_id":"4e6cbc62-51c5-4515-97b7-337972dcf072"}
2492026-10-02T05:09:14.319Z{"msg":"client is waiting for oneshot","v":0,"name":"crucible","level":30,"time":"2026-10-02T05:09:13.0203211Z","hostname":"w-01M3XG2YQ47DAN19ZT48ZEB7HJ","pid":1177,"":"io task","client":"0","":"downstairs","session_id":"4e6cbc62-51c5-4515-97b7-337972dcf072"}
2502026-10-02T05:09:14.319Z{"msg":"Downstairs in volume = 3","v":0,"name":"crucible","level":30,"time":"2026-10-02T05:09:13.020508268Z","hostname":"w-01M3XG2YQ47DAN19ZT48ZEB7HJ","pid":1177,"task":"crutest"}
2512026-10-02T05:09:14.319Z{"msg":"The guest has requested activation with gen:32","v":0,"name":"crucible","level":30,"time":"2026-10-02T05:09:13.020522115Z","hostname":"w-01M3XG2YQ47DAN19ZT48ZEB7HJ","pid":1177}
2522026-10-02T05:09:14.319Z{"msg":"951dc8a7-43fb-40df-b5d0-9117db471eba active request set","v":0,"name":"crucible","level":30,"time":"2026-10-02T05:09:13.020562236Z","hostname":"w-01M3XG2YQ47DAN19ZT48ZEB7HJ","pid":1177,"session_id":"4e6cbc62-51c5-4515-97b7-337972dcf072"}
2532026-10-02T05:09:14.319Z{"msg":"sending connect oneshot to client","v":0,"name":"crucible","level":30,"time":"2026-10-02T05:09:13.020575893Z","hostname":"w-01M3XG2YQ47DAN19ZT48ZEB7HJ","pid":1177,"client":"0","":"downstairs","session_id":"4e6cbc62-51c5-4515-97b7-337972dcf072"}
2542026-10-02T05:09:14.319Z{"msg":"sending connect oneshot to client","v":0,"name":"crucible","level":30,"time":"2026-10-02T05:09:13.02058604Z","hostname":"w-01M3XG2YQ47DAN19ZT48ZEB7HJ","pid":1177,"client":"1","":"downstairs","session_id":"4e6cbc62-51c5-4515-97b7-337972dcf072"}
2552026-10-02T05:09:14.319Z{"msg":"sending connect oneshot to client","v":0,"name":"crucible","level":30,"time":"2026-10-02T05:09:13.020596828Z","hostname":"w-01M3XG2YQ47DAN19ZT48ZEB7HJ","pid":1177,"client":"2","":"downstairs","session_id":"4e6cbc62-51c5-4515-97b7-337972dcf072"}
2562026-10-02T05:09:14.319Z{"msg":"connecting to 127.0.0.1:8830","v":0,"name":"crucible","level":30,"time":"2026-10-02T05:09:13.020606756Z","hostname":"w-01M3XG2YQ47DAN19ZT48ZEB7HJ","pid":1177,"":"io task","client":"2","":"downstairs","session_id":"4e6cbc62-51c5-4515-97b7-337972dcf072"}
2572026-10-02T05:09:14.319Z{"msg":"connecting to 127.0.0.1:8810","v":0,"name":"crucible","level":30,"time":"2026-10-02T05:09:13.020617293Z","hostname":"w-01M3XG2YQ47DAN19ZT48ZEB7HJ","pid":1177,"":"io task","client":"0","":"downstairs","session_id":"4e6cbc62-51c5-4515-97b7-337972dcf072"}
2582026-10-02T05:09:14.319Z{"msg":"connecting to 127.0.0.1:8820","v":0,"name":"crucible","level":30,"time":"2026-10-02T05:09:13.020669212Z","hostname":"w-01M3XG2YQ47DAN19ZT48ZEB7HJ","pid":1177,"":"io task","client":"1","":"downstairs","session_id":"4e6cbc62-51c5-4515-97b7-337972dcf072"}
2592026-10-02T05:09:14.319Z{"msg":"ds_connection connected from Ok(127.0.0.1:49026)","v":0,"name":"crucible","level":30,"time":"2026-10-02T05:09:13.020684488Z","hostname":"w-01M3XG2YQ47DAN19ZT48ZEB7HJ","pid":1177,"":"io task","client":"2","":"downstairs","session_id":"4e6cbc62-51c5-4515-97b7-337972dcf072"}
2602026-10-02T05:09:14.319Z{"msg":"ds_connection connected from Ok(127.0.0.1:55059)","v":0,"name":"crucible","level":30,"time":"2026-10-02T05:09:13.020777078Z","hostname":"w-01M3XG2YQ47DAN19ZT48ZEB7HJ","pid":1177,"":"io task","client":"1","":"downstairs","session_id":"4e6cbc62-51c5-4515-97b7-337972dcf072"}
2612026-10-02T05:09:14.319Z{"msg":"ds_connection connected from Ok(127.0.0.1:35349)","v":0,"name":"crucible","level":30,"time":"2026-10-02T05:09:13.020802482Z","hostname":"w-01M3XG2YQ47DAN19ZT48ZEB7HJ","pid":1177,"":"io task","client":"0","":"downstairs","session_id":"4e6cbc62-51c5-4515-97b7-337972dcf072"}
2622026-10-02T05:09:14.319Z{"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":"2026-10-02T05:09:13.021343491Z","hostname":"w-01M3XG2YQ47DAN19ZT48ZEB7HJ","pid":1177,"client":"1","":"downstairs","session_id":"4e6cbc62-51c5-4515-97b7-337972dcf072"}
2632026-10-02T05:09:14.320Z{"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":"2026-10-02T05:09:13.021371444Z","hostname":"w-01M3XG2YQ47DAN19ZT48ZEB7HJ","pid":1177,"client":"2","":"downstairs","session_id":"4e6cbc62-51c5-4515-97b7-337972dcf072"}
2642026-10-02T05:09:14.320Z{"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":"2026-10-02T05:09:13.021383812Z","hostname":"w-01M3XG2YQ47DAN19ZT48ZEB7HJ","pid":1177,"client":"0","":"downstairs","session_id":"4e6cbc62-51c5-4515-97b7-337972dcf072"}
2652026-10-02T05:09:14.323Z{"msg":"Waiting for more clients to be ready","v":0,"name":"crucible","level":30,"time":"2026-10-02T05:09:13.021585206Z","hostname":"w-01M3XG2YQ47DAN19ZT48ZEB7HJ","pid":1177,"session_id":"4e6cbc62-51c5-4515-97b7-337972dcf072"}
2662026-10-02T05:09:14.323Z{"msg":"Waiting for more clients to be ready","v":0,"name":"crucible","level":30,"time":"2026-10-02T05:09:13.021596844Z","hostname":"w-01M3XG2YQ47DAN19ZT48ZEB7HJ","pid":1177,"session_id":"4e6cbc62-51c5-4515-97b7-337972dcf072"}
2672026-10-02T05:09:14.323Z{"msg":"[0]R flush_numbers: [1501, 1501, 1501, 1501, 1501]","v":0,"name":"crucible","level":30,"time":"2026-10-02T05:09:13.021636525Z","hostname":"w-01M3XG2YQ47DAN19ZT48ZEB7HJ","pid":1177,"":"downstairs","":"downstairs","session_id":"4e6cbc62-51c5-4515-97b7-337972dcf072"}
2682026-10-02T05:09:14.323Z{"msg":"[0]R generation: [31, 31, 31, 31, 31]","v":0,"name":"crucible","level":30,"time":"2026-10-02T05:09:13.021648032Z","hostname":"w-01M3XG2YQ47DAN19ZT48ZEB7HJ","pid":1177,"":"downstairs","":"downstairs","session_id":"4e6cbc62-51c5-4515-97b7-337972dcf072"}
2692026-10-02T05:09:14.323Z{"msg":"[0]R dirty: [false, false, false, false, false]","v":0,"name":"crucible","level":30,"time":"2026-10-02T05:09:13.02165871Z","hostname":"w-01M3XG2YQ47DAN19ZT48ZEB7HJ","pid":1177,"":"downstairs","":"downstairs","session_id":"4e6cbc62-51c5-4515-97b7-337972dcf072"}
2702026-10-02T05:09:14.323Z{"msg":"[1]R flush_numbers: [1501, 1501, 1501, 1501, 1501]","v":0,"name":"crucible","level":30,"time":"2026-10-02T05:09:13.021669957Z","hostname":"w-01M3XG2YQ47DAN19ZT48ZEB7HJ","pid":1177,"":"downstairs","":"downstairs","session_id":"4e6cbc62-51c5-4515-97b7-337972dcf072"}
2712026-10-02T05:09:14.323Z{"msg":"[1]R generation: [31, 31, 31, 31, 31]","v":0,"name":"crucible","level":30,"time":"2026-10-02T05:09:13.021680155Z","hostname":"w-01M3XG2YQ47DAN19ZT48ZEB7HJ","pid":1177,"":"downstairs","":"downstairs","session_id":"4e6cbc62-51c5-4515-97b7-337972dcf072"}
2722026-10-02T05:09:14.323Z{"msg":"[1]R dirty: [false, false, false, false, false]","v":0,"name":"crucible","level":30,"time":"2026-10-02T05:09:13.021691113Z","hostname":"w-01M3XG2YQ47DAN19ZT48ZEB7HJ","pid":1177,"":"downstairs","":"downstairs","session_id":"4e6cbc62-51c5-4515-97b7-337972dcf072"}
2732026-10-02T05:09:14.323Z{"msg":"[2]R flush_numbers: [1501, 1501, 1501, 1501, 1501]","v":0,"name":"crucible","level":30,"time":"2026-10-02T05:09:13.02170196Z","hostname":"w-01M3XG2YQ47DAN19ZT48ZEB7HJ","pid":1177,"":"downstairs","":"downstairs","session_id":"4e6cbc62-51c5-4515-97b7-337972dcf072"}
2742026-10-02T05:09:14.323Z{"msg":"[2]R generation: [31, 31, 31, 31, 31]","v":0,"name":"crucible","level":30,"time":"2026-10-02T05:09:13.021712538Z","hostname":"w-01M3XG2YQ47DAN19ZT48ZEB7HJ","pid":1177,"":"downstairs","":"downstairs","session_id":"4e6cbc62-51c5-4515-97b7-337972dcf072"}
2752026-10-02T05:09:14.323Z{"msg":"[2]R dirty: [false, false, false, false, false]","v":0,"name":"crucible","level":30,"time":"2026-10-02T05:09:13.021723135Z","hostname":"w-01M3XG2YQ47DAN19ZT48ZEB7HJ","pid":1177,"":"downstairs","":"downstairs","session_id":"4e6cbc62-51c5-4515-97b7-337972dcf072"}
2762026-10-02T05:09:14.323Z{"msg":"Max found gen is 32","v":0,"name":"crucible","level":30,"time":"2026-10-02T05:09:13.021733353Z","hostname":"w-01M3XG2YQ47DAN19ZT48ZEB7HJ","pid":1177,"":"downstairs","":"downstairs","session_id":"4e6cbc62-51c5-4515-97b7-337972dcf072"}
2772026-10-02T05:09:14.323Z{"msg":"Generation requested: 32 >= found:32","v":0,"name":"crucible","level":30,"time":"2026-10-02T05:09:13.021743771Z","hostname":"w-01M3XG2YQ47DAN19ZT48ZEB7HJ","pid":1177,"":"downstairs","":"downstairs","session_id":"4e6cbc62-51c5-4515-97b7-337972dcf072"}
2782026-10-02T05:09:14.323Z{"msg":"Next flush: 1502","v":0,"name":"crucible","level":30,"time":"2026-10-02T05:09:13.021753759Z","hostname":"w-01M3XG2YQ47DAN19ZT48ZEB7HJ","pid":1177,"":"downstairs","":"downstairs","session_id":"4e6cbc62-51c5-4515-97b7-337972dcf072"}
2792026-10-02T05:09:14.323Z{"msg":"All extents match","v":0,"name":"crucible","level":30,"time":"2026-10-02T05:09:13.021764336Z","hostname":"w-01M3XG2YQ47DAN19ZT48ZEB7HJ","pid":1177,"":"downstairs","":"downstairs","session_id":"4e6cbc62-51c5-4515-97b7-337972dcf072"}
2802026-10-02T05:09:14.323Z{"msg":"No downstairs reconciliation required","v":0,"name":"crucible","level":30,"time":"2026-10-02T05:09:13.021774654Z","hostname":"w-01M3XG2YQ47DAN19ZT48ZEB7HJ","pid":1177,"session_id":"4e6cbc62-51c5-4515-97b7-337972dcf072"}
2812026-10-02T05:09:14.323Z{"msg":"Transition from WaitQuorum to Active","v":0,"name":"crucible","level":30,"time":"2026-10-02T05:09:13.021784212Z","hostname":"w-01M3XG2YQ47DAN19ZT48ZEB7HJ","pid":1177,"client":"0","":"downstairs","session_id":"4e6cbc62-51c5-4515-97b7-337972dcf072"}
2822026-10-02T05:09:14.323Z{"msg":"Transition from WaitQuorum to Active","v":0,"name":"crucible","level":30,"time":"2026-10-02T05:09:13.021794609Z","hostname":"w-01M3XG2YQ47DAN19ZT48ZEB7HJ","pid":1177,"client":"1","":"downstairs","session_id":"4e6cbc62-51c5-4515-97b7-337972dcf072"}
2832026-10-02T05:09:14.323Z{"msg":"Transition from WaitQuorum to Active","v":0,"name":"crucible","level":30,"time":"2026-10-02T05:09:13.021804267Z","hostname":"w-01M3XG2YQ47DAN19ZT48ZEB7HJ","pid":1177,"client":"2","":"downstairs","session_id":"4e6cbc62-51c5-4515-97b7-337972dcf072"}
2842026-10-02T05:09:14.323Z{"msg":"All required reconciliation work is completed","v":0,"name":"crucible","level":30,"time":"2026-10-02T05:09:13.021814505Z","hostname":"w-01M3XG2YQ47DAN19ZT48ZEB7HJ","pid":1177,"session_id":"4e6cbc62-51c5-4515-97b7-337972dcf072"}
2852026-10-02T05:09:14.323Z{"msg":"Set Downstairs and Upstairs active after reconciliation","v":0,"name":"crucible","level":30,"time":"2026-10-02T05:09:13.021824643Z","hostname":"w-01M3XG2YQ47DAN19ZT48ZEB7HJ","pid":1177,"session_id":"4e6cbc62-51c5-4515-97b7-337972dcf072"}
2862026-10-02T05:09:14.323Z{"msg":"951dc8a7-43fb-40df-b5d0-9117db471eba is now active with session: 4e6cbc62-51c5-4515-97b7-337972dcf072","v":0,"name":"crucible","level":30,"time":"2026-10-02T05:09:13.0218353Z","hostname":"w-01M3XG2YQ47DAN19ZT48ZEB7HJ","pid":1177,"session_id":"4e6cbc62-51c5-4515-97b7-337972dcf072"}
2872026-10-02T05:09:14.323Z{"msg":"Set Active after no reconciliation","v":0,"name":"crucible","level":30,"time":"2026-10-02T05:09:13.021844988Z","hostname":"w-01M3XG2YQ47DAN19ZT48ZEB7HJ","pid":1177,"session_id":"4e6cbc62-51c5-4515-97b7-337972dcf072"}
2882026-10-02T05:09:14.323Z{"msg":"The guest has finished waiting for activation with:32","v":0,"name":"crucible","level":30,"time":"2026-10-02T05:09:13.021854446Z","hostname":"w-01M3XG2YQ47DAN19ZT48ZEB7HJ","pid":1177}
2892026-10-02T05:09:14.323Z{"msg":"Activated sub_volume 951dc8a7-43fb-40df-b5d0-9117db471eba","v":0,"name":"crucible","level":30,"time":"2026-10-02T05:09:13.021863574Z","hostname":"w-01M3XG2YQ47DAN19ZT48ZEB7HJ","pid":1177}
2902026-10-02T05:09:14.323Z{"msg":"Wait for a query_work_queue command to finish before sending IO","v":0,"name":"crucible","level":30,"time":"2026-10-02T05:09:13.021872162Z","hostname":"w-01M3XG2YQ47DAN19ZT48ZEB7HJ","pid":1177,"task":"crutest"}
2912026-10-02T05:09:14.323ZDisk: sv:1 bs:4096 ts:204800 tb:50 max_io:50 or 204800
2922026-10-02T05:09:14.323ZLoading write count information from file "/var/tmp/test_up-build/verify_file"
2932026-10-02T05:09:14.324Z{"msg":"Fill test","v":0,"name":"crucible","level":30,"time":"2026-10-02T05:09:13.02228405Z","hostname":"w-01M3XG2YQ47DAN19ZT48ZEB7HJ","pid":1177,"task":"crutest"}
2942026-10-02T05:09:14.343ZRead and Verify all blocks (0..50 range:false)
2952026-10-02T05:09:14.366Z{"msg":"Wrote out file \"/var/tmp/test_up-build/verify_file\"","v":0,"name":"crucible","level":30,"time":"2026-10-02T05:09:13.069183153Z","hostname":"w-01M3XG2YQ47DAN19ZT48ZEB7HJ","pid":1177,"task":"crutest"}
2962026-10-02T05:09:14.367Z{"msg":"CLIENT: Tests done. All submitted work has been ACK'd","v":0,"name":"crucible","level":30,"time":"2026-10-02T05:09:13.069201109Z","hostname":"w-01M3XG2YQ47DAN19ZT48ZEB7HJ","pid":1177,"task":"crutest"}
2972026-10-02T05:09:14.367Z----------------------------------------------------------------
2982026-10-02T05:09:14.367Z Crucible gen:32 GIO:true work queues: Upstairs:0 downstairs:1
2992026-10-02T05:09:14.367ZStates: Active Active Active
3002026-10-02T05:09:14.367ZJOBID ACK TYPE BKS/EXT DS:0 DS:1 DS:2 REPLAY
3012026-10-02T05:09:14.367Z 1002 Acked Read 50 Done Done Done false
3022026-10-02T05:09:14.367Z STATES DS:0 DS:1 DS:2 TOTAL
3032026-10-02T05:09:14.367Z Sent 0 0 0 0
3042026-10-02T05:09:14.367Z Done 1 1 1 3
3052026-10-02T05:09:14.367Z Skipped 0 0 0 0
3062026-10-02T05:09:14.367Z Error 0 0 0 0
3072026-10-02T05:09:14.370ZLast Flush: Some(JobId(1001)) Some(JobId(1001)) Some(JobId(1001))
3082026-10-02T05:09:14.370ZDownstairs last five completed: 1001 1000
3092026-10-02T05:09:14.370ZUpstairs last five completed: 1002 1001 1000
3102026-10-02T05:09:14.370Z{"msg":"CLIENT: Up:0 ds:1 act:3","v":0,"name":"crucible","level":30,"time":"2026-10-02T05:09:13.06928403Z","hostname":"w-01M3XG2YQ47DAN19ZT48ZEB7HJ","pid":1177,"task":"crutest"}
3112026-10-02T05:09:18.369Z----------------------------------------------------------------
3122026-10-02T05:09:18.369Z Crucible gen:32 GIO:true work queues: Upstairs:0 downstairs:0
3132026-10-02T05:09:18.369ZDownstairs last five completed: 1003 1002 1001 1000
3142026-10-02T05:09:18.369ZUpstairs last five completed: 1003 1002 1001 1000
3152026-10-02T05:09:18.372Z{"msg":"CLIENT: Up:0 ds:0 act:3","v":0,"name":"crucible","level":30,"time":"2026-10-02T05:09:17.07072883Z","hostname":"w-01M3XG2YQ47DAN19ZT48ZEB7HJ","pid":1177,"task":"crutest"}
3162026-10-02T05:09:18.372Z{"msg":"CLIENT: All crucible jobs finished, exiting program","v":0,"name":"crucible","level":30,"time":"2026-10-02T05:09:17.070781719Z","hostname":"w-01M3XG2YQ47DAN19ZT48ZEB7HJ","pid":1177,"task":"crutest"}
3172026-10-02T05:09:18.374ZRepair part 1 passed
3182026-10-02T05:09:18.374Z
3192026-10-02T05:09:18.375ZKill the current downstairs
3202026-10-02T05:09:18.416ZDownstairs 2 stopped
3212026-10-02T05:09:18.417Zmv /var/tmp/test_up-build/8830 /var/tmp/test_up-build/new
3222026-10-02T05:09:18.419ZNow put back the original so we have a mismatch
3232026-10-02T05:09:18.419Zmv /var/tmp/test_up-build/previous /var/tmp/test_up-build/8830
3242026-10-02T05:09:18.419ZRestart downstairs with old directory
3252026-10-02T05:09:18.432Z/var/tmp/bins/crucible-downstairs dump --no-color -d /var/tmp/test_up-build/8810 -d /var/tmp/test_up-build/8820 -d /var/tmp/test_up-build/8830
3262026-10-02T05:09:18.444ZEXT BLOCKS GEN0 GEN1 GEN2 FL0 FL1 FL2 D0 D1 D2 DIFF
3272026-10-02T05:09:18.446Z 0 000-009 32 32 31 1502 1502 1501 F F F <---
3282026-10-02T05:09:18.446Z 1 010-019 32 32 31 1502 1502 1501 F F F <---
3292026-10-02T05:09:18.446Z 2 020-029 32 32 31 1502 1502 1501 F F F <---
3302026-10-02T05:09:18.446Z 3 030-039 32 32 31 1502 1502 1501 F F F <---
3312026-10-02T05:09:18.446Z 4 040-049 32 32 31 1502 1502 1501 F F F <---
3322026-10-02T05:09:18.446ZMax gen: 32, Max flush: 1502
3332026-10-02T05:09:18.664ZError: Difference in extent metadata found!
3342026-10-02T05:09:18.664Z
3352026-10-02T05:09:18.664ZStack backtrace:
3362026-10-02T05:09:18.664Z 0: anyhow::error::<impl anyhow::Error>::msg
3372026-10-02T05:09:18.664Z at /home/build/.cargo/registry/src/index.crates.io-1949cf8c6b5b557f/anyhow-1.0.102/src/backtrace.rs:10:14
3382026-10-02T05:09:18.664Z 1: anyhow::__private::format_err
3392026-10-02T05:09:18.664Z at /home/build/.cargo/registry/src/index.crates.io-1949cf8c6b5b557f/anyhow-1.0.102/src/lib.rs:687:13
3402026-10-02T05:09:18.682Zdump test found error as expected
3412026-10-02T05:09:18.682Z
3422026-10-02T05:09:18.682Z
3432026-10-02T05:09:18.685Z/var/tmp/bins/crutest verify --range -g 33 -q --key 56ZdSM6FT+QfRRl60PClQFCd8eE7r61dV2c3E4xGAJ4= --dsc 127.0.0.1:9998 --verify-out /var/tmp/test_up-build/verify_file --verify-in /var/tmp/test_up-build/verify_file
3442026-10-02T05:09:18.701Z{"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":"2026-10-02T05:09:17.402816304Z","hostname":"w-01M3XG2YQ47DAN19ZT48ZEB7HJ","pid":1185,"task":"crutest"}
3452026-10-02T05:09:18.704Z{"msg":"dsc has 3 regions. This means 1 sub_volumes","v":0,"name":"crucible","level":30,"time":"2026-10-02T05:09:17.403200788Z","hostname":"w-01M3XG2YQ47DAN19ZT48ZEB7HJ","pid":1185,"task":"crutest"}
3462026-10-02T05:09:18.704Z{"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":"2026-10-02T05:09:17.403965316Z","hostname":"w-01M3XG2YQ47DAN19ZT48ZEB7HJ","pid":1185,"task":"crutest"}
3472026-10-02T05:09:18.704Z{"msg":"Upstairs starts","v":0,"name":"crucible","level":30,"time":"2026-10-02T05:09:17.404222818Z","hostname":"w-01M3XG2YQ47DAN19ZT48ZEB7HJ","pid":1185}
3482026-10-02T05:09:18.704Z{"msg":"Crucible Version: BuildInfo {\n version: \"0.0.1\",\n git_sha: \"f17e50f6faf759d2ca3282ac1efe39527caf16d9\",\n git_commit_timestamp: \"2026-10-02T04:51:42.000000000Z\",\n git_branch: \"renovate/tokio-rustls-0.x\",\n rustc_semver: \"1.90.0\",\n rustc_channel: \"stable\",\n rustc_host_triple: \"x86_64-unknown-illumos\",\n rustc_commit_sha: \"1159e78c4747b02ef996e55082b704c09b970588\",\n cargo_triple: \"x86_64-unknown-illumos\",\n debug: true,\n opt_level: 0,\n}","v":0,"name":"crucible","level":30,"time":"2026-10-02T05:09:17.40426028Z","hostname":"w-01M3XG2YQ47DAN19ZT48ZEB7HJ","pid":1185}
3492026-10-02T05:09:18.704Z{"msg":"Upstairs <-> Downstairs Message Version: 13","v":0,"name":"crucible","level":30,"time":"2026-10-02T05:09:17.404270308Z","hostname":"w-01M3XG2YQ47DAN19ZT48ZEB7HJ","pid":1185}
3502026-10-02T05:09:18.704Z{"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":"2026-10-02T05:09:17.404282795Z","hostname":"w-01M3XG2YQ47DAN19ZT48ZEB7HJ","pid":1185}
3512026-10-02T05:09:18.704Z{"msg":"Crucible 9d2cda74-9670-44d6-ae5e-2acc3fb79c0c has session id: 8af8420b-0db8-4e1d-af0c-e8e8f844d8f3","v":0,"name":"crucible","level":30,"time":"2026-10-02T05:09:17.404702081Z","hostname":"w-01M3XG2YQ47DAN19ZT48ZEB7HJ","pid":1185,"session_id":"8af8420b-0db8-4e1d-af0c-e8e8f844d8f3"}
3522026-10-02T05:09:18.704Z{"msg":"Upstairs opts: Upstairs UUID: 9d2cda74-9670-44d6-ae5e-2acc3fb79c0c, 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":"2026-10-02T05:09:17.404738913Z","hostname":"w-01M3XG2YQ47DAN19ZT48ZEB7HJ","pid":1185,"session_id":"8af8420b-0db8-4e1d-af0c-e8e8f844d8f3"}
3532026-10-02T05:09:18.704Z{"msg":"Crucible stats registered with UUID: 9d2cda74-9670-44d6-ae5e-2acc3fb79c0c","v":0,"name":"crucible","level":30,"time":"2026-10-02T05:09:17.40475065Z","hostname":"w-01M3XG2YQ47DAN19ZT48ZEB7HJ","pid":1185,"session_id":"8af8420b-0db8-4e1d-af0c-e8e8f844d8f3"}
3542026-10-02T05:09:18.704Z{"msg":"could not find Downstairs address for Nexus","v":0,"name":"crucible","level":40,"time":"2026-10-02T05:09:17.404760628Z","hostname":"w-01M3XG2YQ47DAN19ZT48ZEB7HJ","pid":1185,"session_id":"8af8420b-0db8-4e1d-af0c-e8e8f844d8f3"}
3552026-10-02T05:09:18.704Z{"msg":"client is waiting for oneshot","v":0,"name":"crucible","level":30,"time":"2026-10-02T05:09:17.404895538Z","hostname":"w-01M3XG2YQ47DAN19ZT48ZEB7HJ","pid":1185,"":"io task","client":"1","":"downstairs","session_id":"8af8420b-0db8-4e1d-af0c-e8e8f844d8f3"}
3562026-10-02T05:09:18.704Z{"msg":"client is waiting for oneshot","v":0,"name":"crucible","level":30,"time":"2026-10-02T05:09:17.404914193Z","hostname":"w-01M3XG2YQ47DAN19ZT48ZEB7HJ","pid":1185,"":"io task","client":"0","":"downstairs","session_id":"8af8420b-0db8-4e1d-af0c-e8e8f844d8f3"}
3572026-10-02T05:09:18.704Z{"msg":"client is waiting for oneshot","v":0,"name":"crucible","level":30,"time":"2026-10-02T05:09:17.404932759Z","hostname":"w-01M3XG2YQ47DAN19ZT48ZEB7HJ","pid":1185,"":"io task","client":"2","":"downstairs","session_id":"8af8420b-0db8-4e1d-af0c-e8e8f844d8f3"}
3582026-10-02T05:09:18.704Z{"msg":"Downstairs in volume = 3","v":0,"name":"crucible","level":30,"time":"2026-10-02T05:09:17.405112469Z","hostname":"w-01M3XG2YQ47DAN19ZT48ZEB7HJ","pid":1185,"task":"crutest"}
3592026-10-02T05:09:18.704Z{"msg":"The guest has requested activation with gen:33","v":0,"name":"crucible","level":30,"time":"2026-10-02T05:09:17.405139473Z","hostname":"w-01M3XG2YQ47DAN19ZT48ZEB7HJ","pid":1185}
3602026-10-02T05:09:18.704Z{"msg":"9d2cda74-9670-44d6-ae5e-2acc3fb79c0c active request set","v":0,"name":"crucible","level":30,"time":"2026-10-02T05:09:17.40515195Z","hostname":"w-01M3XG2YQ47DAN19ZT48ZEB7HJ","pid":1185,"session_id":"8af8420b-0db8-4e1d-af0c-e8e8f844d8f3"}
3612026-10-02T05:09:18.704Z{"msg":"sending connect oneshot to client","v":0,"name":"crucible","level":30,"time":"2026-10-02T05:09:17.405161338Z","hostname":"w-01M3XG2YQ47DAN19ZT48ZEB7HJ","pid":1185,"client":"0","":"downstairs","session_id":"8af8420b-0db8-4e1d-af0c-e8e8f844d8f3"}
3622026-10-02T05:09:18.704Z{"msg":"sending connect oneshot to client","v":0,"name":"crucible","level":30,"time":"2026-10-02T05:09:17.405172066Z","hostname":"w-01M3XG2YQ47DAN19ZT48ZEB7HJ","pid":1185,"client":"1","":"downstairs","session_id":"8af8420b-0db8-4e1d-af0c-e8e8f844d8f3"}
3632026-10-02T05:09:18.704Z{"msg":"sending connect oneshot to client","v":0,"name":"crucible","level":30,"time":"2026-10-02T05:09:17.405182163Z","hostname":"w-01M3XG2YQ47DAN19ZT48ZEB7HJ","pid":1185,"client":"2","":"downstairs","session_id":"8af8420b-0db8-4e1d-af0c-e8e8f844d8f3"}
3642026-10-02T05:09:18.705Z{"msg":"connecting to 127.0.0.1:8810","v":0,"name":"crucible","level":30,"time":"2026-10-02T05:09:17.405192171Z","hostname":"w-01M3XG2YQ47DAN19ZT48ZEB7HJ","pid":1185,"":"io task","client":"0","":"downstairs","session_id":"8af8420b-0db8-4e1d-af0c-e8e8f844d8f3"}
3652026-10-02T05:09:18.705Z{"msg":"connecting to 127.0.0.1:8830","v":0,"name":"crucible","level":30,"time":"2026-10-02T05:09:17.405207278Z","hostname":"w-01M3XG2YQ47DAN19ZT48ZEB7HJ","pid":1185,"":"io task","client":"2","":"downstairs","session_id":"8af8420b-0db8-4e1d-af0c-e8e8f844d8f3"}
3662026-10-02T05:09:18.705Z{"msg":"connecting to 127.0.0.1:8820","v":0,"name":"crucible","level":30,"time":"2026-10-02T05:09:17.405217855Z","hostname":"w-01M3XG2YQ47DAN19ZT48ZEB7HJ","pid":1185,"":"io task","client":"1","":"downstairs","session_id":"8af8420b-0db8-4e1d-af0c-e8e8f844d8f3"}
3672026-10-02T05:09:18.705Z{"msg":"ds_connection connected from Ok(127.0.0.1:43328)","v":0,"name":"crucible","level":30,"time":"2026-10-02T05:09:17.405292918Z","hostname":"w-01M3XG2YQ47DAN19ZT48ZEB7HJ","pid":1185,"":"io task","client":"1","":"downstairs","session_id":"8af8420b-0db8-4e1d-af0c-e8e8f844d8f3"}
3682026-10-02T05:09:18.705Z{"msg":"ds_connection connected from Ok(127.0.0.1:56571)","v":0,"name":"crucible","level":30,"time":"2026-10-02T05:09:17.405318743Z","hostname":"w-01M3XG2YQ47DAN19ZT48ZEB7HJ","pid":1185,"":"io task","client":"0","":"downstairs","session_id":"8af8420b-0db8-4e1d-af0c-e8e8f844d8f3"}
3692026-10-02T05:09:18.705Z{"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":"2026-10-02T05:09:17.405336109Z","hostname":"w-01M3XG2YQ47DAN19ZT48ZEB7HJ","pid":1185,"":"io task","client":"2","":"downstairs","session_id":"8af8420b-0db8-4e1d-af0c-e8e8f844d8f3"}
3702026-10-02T05:09:18.705Z{"msg":"client task is sending Done(ConnectionFailed(Os { code: 146, kind: ConnectionRefused, message: \"Connection refused\" }))","v":0,"name":"crucible","level":40,"time":"2026-10-02T05:09:17.405353155Z","hostname":"w-01M3XG2YQ47DAN19ZT48ZEB7HJ","pid":1185,"":"io task","client":"2","":"downstairs","session_id":"8af8420b-0db8-4e1d-af0c-e8e8f844d8f3"}
3712026-10-02T05:09:18.705Z{"msg":"downstairs task for 2 stopped due to ConnectionFailed(Os { code: 146, kind: ConnectionRefused, message: \"Connection refused\" })","v":0,"name":"crucible","level":40,"time":"2026-10-02T05:09:17.405365532Z","hostname":"w-01M3XG2YQ47DAN19ZT48ZEB7HJ","pid":1185,"session_id":"8af8420b-0db8-4e1d-af0c-e8e8f844d8f3"}
3722026-10-02T05:09:18.705Z{"msg":"sleeping for 10s before connecting","v":0,"name":"crucible","level":30,"time":"2026-10-02T05:09:17.405435207Z","hostname":"w-01M3XG2YQ47DAN19ZT48ZEB7HJ","pid":1185,"":"io task","client":"2","":"downstairs","session_id":"8af8420b-0db8-4e1d-af0c-e8e8f844d8f3"}
3732026-10-02T05:09:18.705Z{"msg":"client task is exiting","v":0,"name":"crucible","level":30,"time":"2026-10-02T05:09:17.405461981Z","hostname":"w-01M3XG2YQ47DAN19ZT48ZEB7HJ","pid":1185,"":"io task","client":"2","":"downstairs","session_id":"8af8420b-0db8-4e1d-af0c-e8e8f844d8f3"}
3742026-10-02T05:09:18.708Z{"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":"2026-10-02T05:09:17.405995601Z","hostname":"w-01M3XG2YQ47DAN19ZT48ZEB7HJ","pid":1185,"client":"1","":"downstairs","session_id":"8af8420b-0db8-4e1d-af0c-e8e8f844d8f3"}
3752026-10-02T05:09:18.708Z{"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":"2026-10-02T05:09:17.406018356Z","hostname":"w-01M3XG2YQ47DAN19ZT48ZEB7HJ","pid":1185,"client":"0","":"downstairs","session_id":"8af8420b-0db8-4e1d-af0c-e8e8f844d8f3"}
3762026-10-02T05:09:18.708Z{"msg":"Waiting for more clients to be ready","v":0,"name":"crucible","level":30,"time":"2026-10-02T05:09:17.40617695Z","hostname":"w-01M3XG2YQ47DAN19ZT48ZEB7HJ","pid":1185,"session_id":"8af8420b-0db8-4e1d-af0c-e8e8f844d8f3"}
3772026-10-02T05:09:18.708Z{"msg":"Waiting for more clients to be ready","v":0,"name":"crucible","level":30,"time":"2026-10-02T05:09:17.406191297Z","hostname":"w-01M3XG2YQ47DAN19ZT48ZEB7HJ","pid":1185,"session_id":"8af8420b-0db8-4e1d-af0c-e8e8f844d8f3"}
3782026-10-02T05:09:28.707Z{"msg":"connecting to 127.0.0.1:8830","v":0,"name":"crucible","level":30,"time":"2026-10-02T05:09:27.4063131Z","hostname":"w-01M3XG2YQ47DAN19ZT48ZEB7HJ","pid":1185,"":"io task","client":"2","":"downstairs","session_id":"8af8420b-0db8-4e1d-af0c-e8e8f844d8f3"}
3792026-10-02T05:09:28.707Z{"msg":"ds_connection connected from Ok(127.0.0.1:54858)","v":0,"name":"crucible","level":30,"time":"2026-10-02T05:09:27.406371147Z","hostname":"w-01M3XG2YQ47DAN19ZT48ZEB7HJ","pid":1185,"":"io task","client":"2","":"downstairs","session_id":"8af8420b-0db8-4e1d-af0c-e8e8f844d8f3"}
3802026-10-02T05:09:28.711Z{"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":"2026-10-02T05:09:27.40711296Z","hostname":"w-01M3XG2YQ47DAN19ZT48ZEB7HJ","pid":1185,"client":"2","":"downstairs","session_id":"8af8420b-0db8-4e1d-af0c-e8e8f844d8f3"}
3812026-10-02T05:09:28.711Z{"msg":"[0]R flush_numbers: [1502, 1502, 1502, 1502, 1502]","v":0,"name":"crucible","level":30,"time":"2026-10-02T05:09:27.407366923Z","hostname":"w-01M3XG2YQ47DAN19ZT48ZEB7HJ","pid":1185,"":"downstairs","":"downstairs","session_id":"8af8420b-0db8-4e1d-af0c-e8e8f844d8f3"}
3822026-10-02T05:09:28.711Z{"msg":"[0]R generation: [32, 32, 32, 32, 32]","v":0,"name":"crucible","level":30,"time":"2026-10-02T05:09:27.40738259Z","hostname":"w-01M3XG2YQ47DAN19ZT48ZEB7HJ","pid":1185,"":"downstairs","":"downstairs","session_id":"8af8420b-0db8-4e1d-af0c-e8e8f844d8f3"}
3832026-10-02T05:09:28.711Z{"msg":"[0]R dirty: [false, false, false, false, false]","v":0,"name":"crucible","level":30,"time":"2026-10-02T05:09:27.407393137Z","hostname":"w-01M3XG2YQ47DAN19ZT48ZEB7HJ","pid":1185,"":"downstairs","":"downstairs","session_id":"8af8420b-0db8-4e1d-af0c-e8e8f844d8f3"}
3842026-10-02T05:09:28.711Z{"msg":"[1]R flush_numbers: [1502, 1502, 1502, 1502, 1502]","v":0,"name":"crucible","level":30,"time":"2026-10-02T05:09:27.407407854Z","hostname":"w-01M3XG2YQ47DAN19ZT48ZEB7HJ","pid":1185,"":"downstairs","":"downstairs","session_id":"8af8420b-0db8-4e1d-af0c-e8e8f844d8f3"}
3852026-10-02T05:09:28.711Z{"msg":"[1]R generation: [32, 32, 32, 32, 32]","v":0,"name":"crucible","level":30,"time":"2026-10-02T05:09:27.407417672Z","hostname":"w-01M3XG2YQ47DAN19ZT48ZEB7HJ","pid":1185,"":"downstairs","":"downstairs","session_id":"8af8420b-0db8-4e1d-af0c-e8e8f844d8f3"}
3862026-10-02T05:09:28.711Z{"msg":"[1]R dirty: [false, false, false, false, false]","v":0,"name":"crucible","level":30,"time":"2026-10-02T05:09:27.407432019Z","hostname":"w-01M3XG2YQ47DAN19ZT48ZEB7HJ","pid":1185,"":"downstairs","":"downstairs","session_id":"8af8420b-0db8-4e1d-af0c-e8e8f844d8f3"}
3872026-10-02T05:09:28.711Z{"msg":"[2]R flush_numbers: [1501, 1501, 1501, 1501, 1501]","v":0,"name":"crucible","level":30,"time":"2026-10-02T05:09:27.407442386Z","hostname":"w-01M3XG2YQ47DAN19ZT48ZEB7HJ","pid":1185,"":"downstairs","":"downstairs","session_id":"8af8420b-0db8-4e1d-af0c-e8e8f844d8f3"}
3882026-10-02T05:09:28.712Z{"msg":"[2]R generation: [31, 31, 31, 31, 31]","v":0,"name":"crucible","level":30,"time":"2026-10-02T05:09:27.407456413Z","hostname":"w-01M3XG2YQ47DAN19ZT48ZEB7HJ","pid":1185,"":"downstairs","":"downstairs","session_id":"8af8420b-0db8-4e1d-af0c-e8e8f844d8f3"}
3892026-10-02T05:09:28.712Z{"msg":"[2]R dirty: [false, false, false, false, false]","v":0,"name":"crucible","level":30,"time":"2026-10-02T05:09:27.407466271Z","hostname":"w-01M3XG2YQ47DAN19ZT48ZEB7HJ","pid":1185,"":"downstairs","":"downstairs","session_id":"8af8420b-0db8-4e1d-af0c-e8e8f844d8f3"}
3902026-10-02T05:09:28.712Z{"msg":"Max found gen is 33","v":0,"name":"crucible","level":30,"time":"2026-10-02T05:09:27.407479918Z","hostname":"w-01M3XG2YQ47DAN19ZT48ZEB7HJ","pid":1185,"":"downstairs","":"downstairs","session_id":"8af8420b-0db8-4e1d-af0c-e8e8f844d8f3"}
3912026-10-02T05:09:28.712Z{"msg":"Generation requested: 33 >= found:33","v":0,"name":"crucible","level":30,"time":"2026-10-02T05:09:27.407490326Z","hostname":"w-01M3XG2YQ47DAN19ZT48ZEB7HJ","pid":1185,"":"downstairs","":"downstairs","session_id":"8af8420b-0db8-4e1d-af0c-e8e8f844d8f3"}
3922026-10-02T05:09:28.712Z{"msg":"Next flush: 1503","v":0,"name":"crucible","level":30,"time":"2026-10-02T05:09:27.407503873Z","hostname":"w-01M3XG2YQ47DAN19ZT48ZEB7HJ","pid":1185,"":"downstairs","":"downstairs","session_id":"8af8420b-0db8-4e1d-af0c-e8e8f844d8f3"}
3932026-10-02T05:09:28.712Z{"msg":"extent 0 needs reconciliation: ClientMap(ClientData([Some(ExtentMetadata { generation: 32, flush: 1502, dirty: false }), Some(ExtentMetadata { generation: 32, flush: 1502, dirty: false }), Some(ExtentMetadata { generation: 31, flush: 1501, dirty: false })]))","v":0,"name":"crucible","level":30,"time":"2026-10-02T05:09:27.407518129Z","hostname":"w-01M3XG2YQ47DAN19ZT48ZEB7HJ","pid":1185,"":"mend","":"downstairs","":"downstairs","session_id":"8af8420b-0db8-4e1d-af0c-e8e8f844d8f3"}
3942026-10-02T05:09:28.712Z{"msg":"extent:0 ClientMap(ClientData([Some(ExtentMetadata { generation: 32, flush: 1502, dirty: false }), Some(ExtentMetadata { generation: 32, flush: 1502, dirty: false }), Some(ExtentMetadata { generation: 31, flush: 1501, dirty: false })])) => 0","v":0,"name":"crucible","level":30,"time":"2026-10-02T05:09:27.407537185Z","hostname":"w-01M3XG2YQ47DAN19ZT48ZEB7HJ","pid":1185,"":"mend","":"downstairs","":"downstairs","session_id":"8af8420b-0db8-4e1d-af0c-e8e8f844d8f3"}
3952026-10-02T05:09:28.712Z{"msg":"found dest for source 0 for extent at index 0 => [ClientId(2)]","v":0,"name":"crucible","level":30,"time":"2026-10-02T05:09:27.407548523Z","hostname":"w-01M3XG2YQ47DAN19ZT48ZEB7HJ","pid":1185,"":"mend","":"downstairs","":"downstairs","session_id":"8af8420b-0db8-4e1d-af0c-e8e8f844d8f3"}
3962026-10-02T05:09:28.712Z{"msg":"extent 1 needs reconciliation: ClientMap(ClientData([Some(ExtentMetadata { generation: 32, flush: 1502, dirty: false }), Some(ExtentMetadata { generation: 32, flush: 1502, dirty: false }), Some(ExtentMetadata { generation: 31, flush: 1501, dirty: false })]))","v":0,"name":"crucible","level":30,"time":"2026-10-02T05:09:27.407566889Z","hostname":"w-01M3XG2YQ47DAN19ZT48ZEB7HJ","pid":1185,"":"mend","":"downstairs","":"downstairs","session_id":"8af8420b-0db8-4e1d-af0c-e8e8f844d8f3"}
3972026-10-02T05:09:28.712Z{"msg":"extent:1 ClientMap(ClientData([Some(ExtentMetadata { generation: 32, flush: 1502, dirty: false }), Some(ExtentMetadata { generation: 32, flush: 1502, dirty: false }), Some(ExtentMetadata { generation: 31, flush: 1501, dirty: false })])) => 0","v":0,"name":"crucible","level":30,"time":"2026-10-02T05:09:27.407584944Z","hostname":"w-01M3XG2YQ47DAN19ZT48ZEB7HJ","pid":1185,"":"mend","":"downstairs","":"downstairs","session_id":"8af8420b-0db8-4e1d-af0c-e8e8f844d8f3"}
3982026-10-02T05:09:28.712Z{"msg":"found dest for source 0 for extent at index 1 => [ClientId(2)]","v":0,"name":"crucible","level":30,"time":"2026-10-02T05:09:27.407596252Z","hostname":"w-01M3XG2YQ47DAN19ZT48ZEB7HJ","pid":1185,"":"mend","":"downstairs","":"downstairs","session_id":"8af8420b-0db8-4e1d-af0c-e8e8f844d8f3"}
3992026-10-02T05:09:28.712Z{"msg":"extent 2 needs reconciliation: ClientMap(ClientData([Some(ExtentMetadata { generation: 32, flush: 1502, dirty: false }), Some(ExtentMetadata { generation: 32, flush: 1502, dirty: false }), Some(ExtentMetadata { generation: 31, flush: 1501, dirty: false })]))","v":0,"name":"crucible","level":30,"time":"2026-10-02T05:09:27.407614508Z","hostname":"w-01M3XG2YQ47DAN19ZT48ZEB7HJ","pid":1185,"":"mend","":"downstairs","":"downstairs","session_id":"8af8420b-0db8-4e1d-af0c-e8e8f844d8f3"}
4002026-10-02T05:09:28.712Z{"msg":"extent:2 ClientMap(ClientData([Some(ExtentMetadata { generation: 32, flush: 1502, dirty: false }), Some(ExtentMetadata { generation: 32, flush: 1502, dirty: false }), Some(ExtentMetadata { generation: 31, flush: 1501, dirty: false })])) => 0","v":0,"name":"crucible","level":30,"time":"2026-10-02T05:09:27.407628985Z","hostname":"w-01M3XG2YQ47DAN19ZT48ZEB7HJ","pid":1185,"":"mend","":"downstairs","":"downstairs","session_id":"8af8420b-0db8-4e1d-af0c-e8e8f844d8f3"}
4012026-10-02T05:09:28.712Z{"msg":"found dest for source 0 for extent at index 2 => [ClientId(2)]","v":0,"name":"crucible","level":30,"time":"2026-10-02T05:09:27.407643771Z","hostname":"w-01M3XG2YQ47DAN19ZT48ZEB7HJ","pid":1185,"":"mend","":"downstairs","":"downstairs","session_id":"8af8420b-0db8-4e1d-af0c-e8e8f844d8f3"}
4022026-10-02T05:09:28.712Z{"msg":"extent 3 needs reconciliation: ClientMap(ClientData([Some(ExtentMetadata { generation: 32, flush: 1502, dirty: false }), Some(ExtentMetadata { generation: 32, flush: 1502, dirty: false }), Some(ExtentMetadata { generation: 31, flush: 1501, dirty: false })]))","v":0,"name":"crucible","level":30,"time":"2026-10-02T05:09:27.407657678Z","hostname":"w-01M3XG2YQ47DAN19ZT48ZEB7HJ","pid":1185,"":"mend","":"downstairs","":"downstairs","session_id":"8af8420b-0db8-4e1d-af0c-e8e8f844d8f3"}
4032026-10-02T05:09:28.712Z{"msg":"extent:3 ClientMap(ClientData([Some(ExtentMetadata { generation: 32, flush: 1502, dirty: false }), Some(ExtentMetadata { generation: 32, flush: 1502, dirty: false }), Some(ExtentMetadata { generation: 31, flush: 1501, dirty: false })])) => 0","v":0,"name":"crucible","level":30,"time":"2026-10-02T05:09:27.407675644Z","hostname":"w-01M3XG2YQ47DAN19ZT48ZEB7HJ","pid":1185,"":"mend","":"downstairs","":"downstairs","session_id":"8af8420b-0db8-4e1d-af0c-e8e8f844d8f3"}
4042026-10-02T05:09:28.712Z{"msg":"found dest for source 0 for extent at index 3 => [ClientId(2)]","v":0,"name":"crucible","level":30,"time":"2026-10-02T05:09:27.407686352Z","hostname":"w-01M3XG2YQ47DAN19ZT48ZEB7HJ","pid":1185,"":"mend","":"downstairs","":"downstairs","session_id":"8af8420b-0db8-4e1d-af0c-e8e8f844d8f3"}
4052026-10-02T05:09:28.712Z{"msg":"extent 4 needs reconciliation: ClientMap(ClientData([Some(ExtentMetadata { generation: 32, flush: 1502, dirty: false }), Some(ExtentMetadata { generation: 32, flush: 1502, dirty: false }), Some(ExtentMetadata { generation: 31, flush: 1501, dirty: false })]))","v":0,"name":"crucible","level":30,"time":"2026-10-02T05:09:27.407700399Z","hostname":"w-01M3XG2YQ47DAN19ZT48ZEB7HJ","pid":1185,"":"mend","":"downstairs","":"downstairs","session_id":"8af8420b-0db8-4e1d-af0c-e8e8f844d8f3"}
4062026-10-02T05:09:28.712Z{"msg":"extent:4 ClientMap(ClientData([Some(ExtentMetadata { generation: 32, flush: 1502, dirty: false }), Some(ExtentMetadata { generation: 32, flush: 1502, dirty: false }), Some(ExtentMetadata { generation: 31, flush: 1501, dirty: false })])) => 0","v":0,"name":"crucible","level":30,"time":"2026-10-02T05:09:27.407718575Z","hostname":"w-01M3XG2YQ47DAN19ZT48ZEB7HJ","pid":1185,"":"mend","":"downstairs","":"downstairs","session_id":"8af8420b-0db8-4e1d-af0c-e8e8f844d8f3"}
4072026-10-02T05:09:28.712Z{"msg":"found dest for source 0 for extent at index 4 => [ClientId(2)]","v":0,"name":"crucible","level":30,"time":"2026-10-02T05:09:27.407729322Z","hostname":"w-01M3XG2YQ47DAN19ZT48ZEB7HJ","pid":1185,"":"mend","":"downstairs","":"downstairs","session_id":"8af8420b-0db8-4e1d-af0c-e8e8f844d8f3"}
4082026-10-02T05:09:28.712Z{"msg":"Transition from Connecting { state: WaitQuorum, mode: New } to Reconcile","v":0,"name":"crucible","level":30,"time":"2026-10-02T05:09:27.407748548Z","hostname":"w-01M3XG2YQ47DAN19ZT48ZEB7HJ","pid":1185,"client":"0","":"downstairs","session_id":"8af8420b-0db8-4e1d-af0c-e8e8f844d8f3"}
4092026-10-02T05:09:28.712Z{"msg":"Transition from Connecting { state: WaitQuorum, mode: New } to Reconcile","v":0,"name":"crucible","level":30,"time":"2026-10-02T05:09:27.407763574Z","hostname":"w-01M3XG2YQ47DAN19ZT48ZEB7HJ","pid":1185,"client":"1","":"downstairs","session_id":"8af8420b-0db8-4e1d-af0c-e8e8f844d8f3"}
4102026-10-02T05:09:28.712Z{"msg":"Transition from Connecting { state: WaitQuorum, mode: New } to Reconcile","v":0,"name":"crucible","level":30,"time":"2026-10-02T05:09:27.407773852Z","hostname":"w-01M3XG2YQ47DAN19ZT48ZEB7HJ","pid":1185,"client":"2","":"downstairs","session_id":"8af8420b-0db8-4e1d-af0c-e8e8f844d8f3"}
4112026-10-02T05:09:28.712Z{"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":"2026-10-02T05:09:27.407793858Z","hostname":"w-01M3XG2YQ47DAN19ZT48ZEB7HJ","pid":1185,"":"downstairs","":"downstairs","session_id":"8af8420b-0db8-4e1d-af0c-e8e8f844d8f3"}
4122026-10-02T05:09:28.712Z{"msg":"Task list: [ReconcileIO { id: ReconciliationId(0), op: ExtentFlush { repair_id: ReconciliationId(0), extent_id: ExtentId(1), client_id: ClientId(0), flush_number: 1503, 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: 1503, 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: 1503, 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: 1503, 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: 1503, 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":"2026-10-02T05:09:27.407936386Z","hostname":"w-01M3XG2YQ47DAN19ZT48ZEB7HJ","pid":1185,"":"downstairs","":"downstairs","session_id":"8af8420b-0db8-4e1d-af0c-e8e8f844d8f3"}
4132026-10-02T05:09:28.712Z{"msg":"starting reconciliation b6d03bdb-b3b5-4de6-9cb1-ad5c33fc06ac: found 20 extents that need repair","v":0,"name":"crucible","level":30,"time":"2026-10-02T05:09:27.407952292Z","hostname":"w-01M3XG2YQ47DAN19ZT48ZEB7HJ","pid":1185,"":"downstairs","":"downstairs","session_id":"8af8420b-0db8-4e1d-af0c-e8e8f844d8f3"}
4142026-10-02T05:09:28.712Z{"msg":"sending reconcile request ReconciliationId(2)","v":0,"name":"crucible","level":30,"time":"2026-10-02T05:09:27.40796234Z","hostname":"w-01M3XG2YQ47DAN19ZT48ZEB7HJ","pid":1185,"client":"2","":"downstairs","session_id":"8af8420b-0db8-4e1d-af0c-e8e8f844d8f3"}
4152026-10-02T05:09:28.720Z{"msg":"sending reconcile request ReconciliationId(6)","v":0,"name":"crucible","level":30,"time":"2026-10-02T05:09:27.4191567Z","hostname":"w-01M3XG2YQ47DAN19ZT48ZEB7HJ","pid":1185,"client":"2","":"downstairs","session_id":"8af8420b-0db8-4e1d-af0c-e8e8f844d8f3"}
4162026-10-02T05:09:28.722Z{"msg":"sending reconcile request ReconciliationId(10)","v":0,"name":"crucible","level":30,"time":"2026-10-02T05:09:27.421363425Z","hostname":"w-01M3XG2YQ47DAN19ZT48ZEB7HJ","pid":1185,"client":"2","":"downstairs","session_id":"8af8420b-0db8-4e1d-af0c-e8e8f844d8f3"}
4172026-10-02T05:09:28.726Z{"msg":"sending reconcile request ReconciliationId(14)","v":0,"name":"crucible","level":30,"time":"2026-10-02T05:09:27.423217039Z","hostname":"w-01M3XG2YQ47DAN19ZT48ZEB7HJ","pid":1185,"client":"2","":"downstairs","session_id":"8af8420b-0db8-4e1d-af0c-e8e8f844d8f3"}
4182026-10-02T05:09:28.729Z{"msg":"sending reconcile request ReconciliationId(18)","v":0,"name":"crucible","level":30,"time":"2026-10-02T05:09:27.42522205Z","hostname":"w-01M3XG2YQ47DAN19ZT48ZEB7HJ","pid":1185,"client":"2","":"downstairs","session_id":"8af8420b-0db8-4e1d-af0c-e8e8f844d8f3"}
4192026-10-02T05:09:28.729Z{"msg":"done with reconciliation","v":0,"name":"crucible","level":30,"time":"2026-10-02T05:09:27.426926207Z","hostname":"w-01M3XG2YQ47DAN19ZT48ZEB7HJ","pid":1185,"":"downstairs","":"downstairs","session_id":"8af8420b-0db8-4e1d-af0c-e8e8f844d8f3"}
4202026-10-02T05:09:28.729Z{"msg":"Transition from Reconcile to Active","v":0,"name":"crucible","level":30,"time":"2026-10-02T05:09:27.426954241Z","hostname":"w-01M3XG2YQ47DAN19ZT48ZEB7HJ","pid":1185,"client":"0","":"downstairs","session_id":"8af8420b-0db8-4e1d-af0c-e8e8f844d8f3"}
4212026-10-02T05:09:28.729Z{"msg":"Transition from Reconcile to Active","v":0,"name":"crucible","level":30,"time":"2026-10-02T05:09:27.426964949Z","hostname":"w-01M3XG2YQ47DAN19ZT48ZEB7HJ","pid":1185,"client":"1","":"downstairs","session_id":"8af8420b-0db8-4e1d-af0c-e8e8f844d8f3"}
4222026-10-02T05:09:28.729Z{"msg":"Transition from Reconcile to Active","v":0,"name":"crucible","level":30,"time":"2026-10-02T05:09:27.426979825Z","hostname":"w-01M3XG2YQ47DAN19ZT48ZEB7HJ","pid":1185,"client":"2","":"downstairs","session_id":"8af8420b-0db8-4e1d-af0c-e8e8f844d8f3"}
4232026-10-02T05:09:28.729Z{"msg":"All required reconciliation work is completed","v":0,"name":"crucible","level":30,"time":"2026-10-02T05:09:27.426990103Z","hostname":"w-01M3XG2YQ47DAN19ZT48ZEB7HJ","pid":1185,"session_id":"8af8420b-0db8-4e1d-af0c-e8e8f844d8f3"}
4242026-10-02T05:09:28.729Z{"msg":"Set Downstairs and Upstairs active after reconciliation","v":0,"name":"crucible","level":30,"time":"2026-10-02T05:09:27.42700347Z","hostname":"w-01M3XG2YQ47DAN19ZT48ZEB7HJ","pid":1185,"session_id":"8af8420b-0db8-4e1d-af0c-e8e8f844d8f3"}
4252026-10-02T05:09:28.729Z{"msg":"9d2cda74-9670-44d6-ae5e-2acc3fb79c0c is now active with session: 8af8420b-0db8-4e1d-af0c-e8e8f844d8f3","v":0,"name":"crucible","level":30,"time":"2026-10-02T05:09:27.427013818Z","hostname":"w-01M3XG2YQ47DAN19ZT48ZEB7HJ","pid":1185,"session_id":"8af8420b-0db8-4e1d-af0c-e8e8f844d8f3"}
4262026-10-02T05:09:28.729Z{"msg":"The guest has finished waiting for activation with:33","v":0,"name":"crucible","level":30,"time":"2026-10-02T05:09:27.427027485Z","hostname":"w-01M3XG2YQ47DAN19ZT48ZEB7HJ","pid":1185}
4272026-10-02T05:09:28.729Z{"msg":"Activated sub_volume 9d2cda74-9670-44d6-ae5e-2acc3fb79c0c","v":0,"name":"crucible","level":30,"time":"2026-10-02T05:09:27.42704686Z","hostname":"w-01M3XG2YQ47DAN19ZT48ZEB7HJ","pid":1185}
4282026-10-02T05:09:28.729Z{"msg":"Wait for a query_work_queue command to finish before sending IO","v":0,"name":"crucible","level":30,"time":"2026-10-02T05:09:27.427103968Z","hostname":"w-01M3XG2YQ47DAN19ZT48ZEB7HJ","pid":1185,"task":"crutest"}
4292026-10-02T05:09:28.729ZDisk: sv:1 bs:4096 ts:204800 tb:50 max_io:50 or 204800
4302026-10-02T05:09:28.729ZLoading write count information from file "/var/tmp/test_up-build/verify_file"
4312026-10-02T05:09:28.729ZRead and Verify all blocks (0..50 range:true)
4322026-10-02T05:09:28.752Z{"msg":"Wrote out file \"/var/tmp/test_up-build/verify_file\"","v":0,"name":"crucible","level":30,"time":"2026-10-02T05:09:27.451770816Z","hostname":"w-01M3XG2YQ47DAN19ZT48ZEB7HJ","pid":1185,"task":"crutest"}
4332026-10-02T05:09:28.752Z{"msg":"Verify test completed","v":0,"name":"crucible","level":30,"time":"2026-10-02T05:09:27.451795401Z","hostname":"w-01M3XG2YQ47DAN19ZT48ZEB7HJ","pid":1185,"task":"crutest"}
4342026-10-02T05:09:28.752Z{"msg":"Wrote out file \"/var/tmp/test_up-build/verify_file\"","v":0,"name":"crucible","level":30,"time":"2026-10-02T05:09:27.451805269Z","hostname":"w-01M3XG2YQ47DAN19ZT48ZEB7HJ","pid":1185,"task":"crutest"}
4352026-10-02T05:09:28.752Z{"msg":"CLIENT: Tests done. All submitted work has been ACK'd","v":0,"name":"crucible","level":30,"time":"2026-10-02T05:09:27.451818396Z","hostname":"w-01M3XG2YQ47DAN19ZT48ZEB7HJ","pid":1185,"task":"crutest"}
4362026-10-02T05:09:28.757Z----------------------------------------------------------------
4372026-10-02T05:09:28.757Z Crucible gen:33 GIO:true work queues: Upstairs:0 downstairs:1
4382026-10-02T05:09:28.757ZStates: Active Active Active
4392026-10-02T05:09:28.757ZJOBID ACK TYPE BKS/EXT DS:0 DS:1 DS:2 REPLAY
4402026-10-02T05:09:28.757Z 1000 Acked Read 50 Done Done Done false
4412026-10-02T05:09:28.757Z STATES DS:0 DS:1 DS:2 TOTAL
4422026-10-02T05:09:28.757Z Sent 0 0 0 0
4432026-10-02T05:09:28.757Z Done 1 1 1 3
4442026-10-02T05:09:28.757Z Skipped 0 0 0 0
4452026-10-02T05:09:28.757Z Error 0 0 0 0
4462026-10-02T05:09:28.757ZLast Flush: None None None
4472026-10-02T05:09:28.757ZDownstairs last five completed:
4482026-10-02T05:09:28.758ZUpstairs last five completed: 1000
4492026-10-02T05:09:28.758Z{"msg":"CLIENT: Up:0 ds:1 act:3","v":0,"name":"crucible","level":30,"time":"2026-10-02T05:09:27.451918673Z","hostname":"w-01M3XG2YQ47DAN19ZT48ZEB7HJ","pid":1185,"task":"crutest"}
4502026-10-02T05:09:32.754Z----------------------------------------------------------------
4512026-10-02T05:09:32.754Z Crucible gen:33 GIO:true work queues: Upstairs:0 downstairs:0
4522026-10-02T05:09:32.754ZDownstairs last five completed: 1001 1000
4532026-10-02T05:09:32.754ZUpstairs last five completed: 1001 1000
4542026-10-02T05:09:32.757Z{"msg":"CLIENT: Up:0 ds:0 act:3","v":0,"name":"crucible","level":30,"time":"2026-10-02T05:09:31.453010562Z","hostname":"w-01M3XG2YQ47DAN19ZT48ZEB7HJ","pid":1185,"task":"crutest"}
4552026-10-02T05:09:32.757Z{"msg":"CLIENT: All crucible jobs finished, exiting program","v":0,"name":"crucible","level":30,"time":"2026-10-02T05:09:31.453050003Z","hostname":"w-01M3XG2YQ47DAN19ZT48ZEB7HJ","pid":1185,"task":"crutest"}
4562026-10-02T05:09:32.760ZRepair part 2 passed
4572026-10-02T05:09:32.760Z/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
4582026-10-02T05:09:32.772ZEXT BLOCKS GEN0 GEN1 GEN2 FL0 FL1 FL2 D0 D1 D2 DIFF
4592026-10-02T05:09:32.772Z 0 000-009 32 32 32 1502 1502 1502 F F F
4602026-10-02T05:09:32.772Z 1 010-019 32 32 32 1502 1502 1502 F F F
4612026-10-02T05:09:32.772Z 2 020-029 32 32 32 1502 1502 1502 F F F
4622026-10-02T05:09:32.772Z 3 030-039 32 32 32 1502 1502 1502 F F F
4632026-10-02T05:09:32.772Z 4 040-049 32 32 32 1502 1502 1502 F F F
4642026-10-02T05:09:32.774ZMax gen: 32, Max flush: 1502
4652026-10-02T05:09:32.777Zdump test passed
4662026-10-02T05:09:32.777Z/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
4672026-10-02T05:09:32.786Z Extent 1
4682026-10-02T05:09:32.788ZGEN 32 32 32
4692026-10-02T05:09:32.788ZFLUSH_ID 1502 1502 1502
4702026-10-02T05:09:32.788ZDIRTY
4712026-10-02T05:09:32.788Z
4722026-10-02T05:09:32.788ZBLOCK D0 D1 D2 C0 C1 C2 DIFF
4732026-10-02T05:09:32.788Z010 A A A A A A
4742026-10-02T05:09:32.788Z011 A A A A A A
4752026-10-02T05:09:32.788Z012 A A A A A A
4762026-10-02T05:09:32.791Z013 A A A A A A
4772026-10-02T05:09:32.791Z014 A A A A A A
4782026-10-02T05:09:32.791Z015 A A A A A A
4792026-10-02T05:09:32.791Z016 A A A A A A
4802026-10-02T05:09:32.791Z017 A A A A A A
4812026-10-02T05:09:32.794Z018 A A A A A A
4822026-10-02T05:09:32.794Z019 A A A A A A
4832026-10-02T05:09:32.796Zdump extent test passed
4842026-10-02T05:09:32.797Z/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
4852026-10-02T05:09:32.805ZExtent 2 Block in extent 0 Actual block 20
4862026-10-02T05:09:32.805Z
4872026-10-02T05:09:32.807Z DATA SHA256 VER
4882026-10-02T05:09:32.807Z------ ---------------------------------------------------------------- ---
4892026-10-02T05:09:32.807Z 0 dd48c119bf12204cec987b00879e15b2c8d5e5208d2856ace2f1e53ea07e6409 A
4902026-10-02T05:09:32.807Z 1 dd48c119bf12204cec987b00879e15b2c8d5e5208d2856ace2f1e53ea07e6409 A
4912026-10-02T05:09:32.807Z 2 dd48c119bf12204cec987b00879e15b2c8d5e5208d2856ace2f1e53ea07e6409 A
4922026-10-02T05:09:32.807Z
4932026-10-02T05:09:32.807ZNONCES 0 1 2 DIFF
4942026-10-02T05:09:32.808Z------ ------------------------ ------------------------ ------------------------ -----
4952026-10-02T05:09:32.808Z 0 8f839acab307b0c49df1b869 8f839acab307b0c49df1b869 8f839acab307b0c49df1b869
4962026-10-02T05:09:32.808Z
4972026-10-02T05:09:32.808Z TAGS 0 1 2 DIFF
4982026-10-02T05:09:32.808Z------ -------------------------------- -------------------------------- -------------------------------- -----
4992026-10-02T05:09:32.808Z 0 5b8f810f52994a026323cd84ef8a43c5 5b8f810f52994a026323cd84ef8a43c5 5b8f810f52994a026323cd84ef8a43c5
5002026-10-02T05:09:32.808Z
5012026-10-02T05:09:32.808ZHASHES 0 1 2 DIFF
5022026-10-02T05:09:32.808Z------ ---------------- ---------------- ---------------- -----
5032026-10-02T05:09:32.808Z
5042026-10-02T05:09:32.811Zdump block test passed
5052026-10-02T05:09:32.811ZInitial upstairs tests have completed, stopping all downstairs
5062026-10-02T05:09:37.829ZCreating 4 larger downstairs regions
5072026-10-02T05:09:37.945ZStarting 4 downstairs
5082026-10-02T05:09:42.951Zdsc restarted at PID: 1198
5092026-10-02T05:09:43.009ZNow do the replace-reconcile test
5102026-10-02T05:09:43.023ZUsing 8840 for the replacement port
5112026-10-02T05:13:15.322ZCompleted test: replace-reconcile
5122026-10-02T05:13:15.323ZNow do the replace-before-active test
5132026-10-02T05:16:32.621ZCompleted test: replace-before-active
5142026-10-02T05:16:32.621ZAll tests have completed, stopping all downstairs
5152026-10-02T05:16:32.628Z
5162026-10-02T05:16:32.628ZAll Tests have passed
5172026-10-02T05:16:32.628Z9:09 Test duration
5182026-10-02T05:16:32.628Z
5192026-10-02T05:16:32.629Zreal 9:08.556369053
5202026-10-02T05:16:32.629Zuser 6:48.642252208
5212026-10-02T05:16:32.629Zsys 5.563923672
5222026-10-02T05:16:32.629Ztrap 0.186392073
5232026-10-02T05:16:32.629Ztflt 0.027291215
5242026-10-02T05:16:32.629Zdflt 0.017456293
5252026-10-02T05:16:32.629Zkflt 0.009223190
5262026-10-02T05:16:32.629Zlock 5:45:46.829461966
5272026-10-02T05:16:32.629Zslp 26:30.513123311
5282026-10-02T05:16:32.629Zlat 29.519593267
5292026-10-02T05:16:32.629Zstop 0.012047718
5302026-10-02T05:16:32.629Z+ echo 'test-up-encrypted ends'
5312026-10-02T05:16:32.629Ztest-up-encrypted ends
5322026-10-02T05:16:37.553Zprocess exited: duration 557369 ms, exit code 0
5332026-10-02T05:16:37.553Zexec warning: : stdio descriptors remain open after task exit; waiting 60 seconds for them to close
5342026-10-02T05:17:37.592Zexec warning: : stdout descriptor may be held open by a background process; giving up!
5352026-10-02T05:17:37.592Zexec warning: : stderr descriptor may be held open by a background process; giving up!
 
5362026-10-02T05:17:37.603Zfound 14 output files
5372026-10-02T05:17:37.603Zuploading: /tmp/test_up-build/dsc-out.txt (47601 bytes)
5382026-10-02T05:17:38.618Zuploaded: /tmp/test_up-build/dsc-out.txt
5392026-10-02T05:17:38.618Zuploading: /tmp/test_up-build/test_up_out.txt (22019418 bytes)
5402026-10-02T05:17:39.834Zuploaded: /tmp/test_up-build/test_up_out.txt
5412026-10-02T05:17:39.834Zuploading: /tmp/test_up-build/dsc/downstairs-8810.txt (2500 bytes)
5422026-10-02T05:17:40.842Zuploaded: /tmp/test_up-build/dsc/downstairs-8810.txt
5432026-10-02T05:17:40.842Zuploading: /tmp/test_up-build/dsc/downstairs-8820.txt (548358 bytes)
5442026-10-02T05:17:41.875Zuploaded: /tmp/test_up-build/dsc/downstairs-8820.txt
5452026-10-02T05:17:41.875Zuploading: /tmp/test_up-build/dsc/downstairs-8830.txt (978664 bytes)
5462026-10-02T05:17:42.915Zuploaded: /tmp/test_up-build/dsc/downstairs-8830.txt
5472026-10-02T05:17:42.915Zuploading: /tmp/test_up-build/dsc/downstairs-8840.txt (543070 bytes)
5482026-10-02T05:17:43.946Zuploaded: /tmp/test_up-build/dsc/downstairs-8840.txt
5492026-10-02T05:17:43.946Zuploading: /tmp/debug/df.txt (1270 bytes)
5502026-10-02T05:17:44.954Zuploaded: /tmp/debug/df.txt
5512026-10-02T05:17:44.954Zuploading: /tmp/debug/dtrace.txt (631835 bytes)
5522026-10-02T05:17:45.988Zuploaded: /tmp/debug/dtrace.txt
5532026-10-02T05:17:45.988Zuploading: /tmp/debug/iostat.txt (184372 bytes)
5542026-10-02T05:17:46.003Zupload warning: file "/tmp/debug/iostat.txt" changed size mid upload: 184372 -> 186772
5552026-10-02T05:17:47.010Zuploaded: /tmp/debug/iostat.txt
5562026-10-02T05:17:47.010Zuploading: /tmp/debug/mpstat.txt (447779 bytes)
5572026-10-02T05:17:47.034Zupload warning: file "/tmp/debug/mpstat.txt" changed size mid upload: 447779 -> 455069
5582026-10-02T05:17:48.042Zuploaded: /tmp/debug/mpstat.txt
5592026-10-02T05:17:48.042Zuploading: /tmp/debug/paging.txt (80406 bytes)
5602026-10-02T05:17:48.051Zupload warning: file "/tmp/debug/paging.txt" changed size mid upload: 80406 -> 81829
5612026-10-02T05:17:49.058Zuploaded: /tmp/debug/paging.txt
5622026-10-02T05:17:49.058Zuploading: /tmp/debug/prstat.txt (852918 bytes)
5632026-10-02T05:17:49.091Zupload warning: file "/tmp/debug/prstat.txt" changed size mid upload: 852918 -> 867213
5642026-10-02T05:17:50.099Zuploaded: /tmp/debug/prstat.txt
5652026-10-02T05:17:50.099Zuploading: /tmp/debug/psrinfo.txt (1528 bytes)
5662026-10-02T05:17:51.107Zuploaded: /tmp/debug/psrinfo.txt
5672026-10-02T05:17:51.108Zuploading: /tmp/debug/upstairs-info.txt (66283 bytes)
5682026-10-02T05:17:52.122Zuploaded: /tmp/debug/upstairs-info.txt