01J4HXWY5FEQCVXVJFDSW3XEYB: test-up-unencrypted

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

Buildomat Job: 01J4HXX7VMJA1GX1B0ZF092EFC

Tags:

Artefacts:

Output:

SEQ GLOBAL TIME DETAILS
12024-08-05T19:07:57.810Zjob dependencies complete; ready to run (waiting for 19 m 59 s)
22024-08-05T19:09:05.211Zjob assigned to worker 01J4HZ22M1CAY0GA8Y82EE8T1F (queued for 1 m 7 s)
32024-08-05T19:09:12.643Zdownloading input: /input/build/work/bins/crucible-downstairs.gz
42024-08-05T19:09:13.703Zdownloaded input: /input/build/work/bins/crucible-downstairs.gz
52024-08-05T19:09:13.703Zdownloading input: /input/build/work/bins/crucible-hammer.gz
62024-08-05T19:09:14.553Zdownloaded input: /input/build/work/bins/crucible-hammer.gz
72024-08-05T19:09:14.553Zdownloading input: /input/build/work/bins/crutest.gz
82024-08-05T19:09:15.609Zdownloaded input: /input/build/work/bins/crutest.gz
92024-08-05T19:09:15.609Zdownloading input: /input/build/work/bins/dsc.gz
102024-08-05T19:09:16.261Zdownloaded input: /input/build/work/bins/dsc.gz
112024-08-05T19:09:16.264Zdownloading input: /input/build/work/scripts/perf-downstairs-tick.d
122024-08-05T19:09:16.283Zdownloaded input: /input/build/work/scripts/perf-downstairs-tick.d
132024-08-05T19:09:16.283Zdownloading input: /input/build/work/scripts/test_ds.sh
142024-08-05T19:09:16.302Zdownloaded input: /input/build/work/scripts/test_ds.sh
152024-08-05T19:09:16.302Zdownloading input: /input/build/work/scripts/test_live_repair.sh
162024-08-05T19:09:16.320Zdownloaded input: /input/build/work/scripts/test_live_repair.sh
172024-08-05T19:09:16.320Zdownloading input: /input/build/work/scripts/test_repair.sh
182024-08-05T19:09:16.341Zdownloaded input: /input/build/work/scripts/test_repair.sh
192024-08-05T19:09:16.341Zdownloading input: /input/build/work/scripts/test_replay.sh
202024-08-05T19:09:16.356Zdownloaded input: /input/build/work/scripts/test_replay.sh
212024-08-05T19:09:16.356Zdownloading input: /input/build/work/scripts/test_up.sh
222024-08-05T19:09:16.374Zdownloaded input: /input/build/work/scripts/test_up.sh
232024-08-05T19:09:16.375Zdownloading input: /input/build/work/scripts/upstairs_info.d
242024-08-05T19:09:16.406Zdownloaded input: /input/build/work/scripts/upstairs_info.d
252024-08-05T19:09:16.425Zdownloading input: /input/build/tmp/cargo-test-out.log
262024-08-05T19:09:17.281Zdownloaded input: /input/build/tmp/cargo-test-out.log
 
272024-08-05T19:09:17.281Zstarting task 0: "setup"
282024-08-05T19:09:17.352Z++ uname -s
292024-08-05T19:09:17.355Z+ kern=SunOS
302024-08-05T19:09:17.355Z+ case "$kern" in
312024-08-05T19:09:17.355Z+ groupadd -g 12345 build
322024-08-05T19:09:17.358Z+ useradd -u 12345 -g build -d /home/build -s /bin/bash -c build -P 'Primary Administrator' build
332024-08-05T19:09:19.375Z+ zfs create -o mountpoint=/work rpool/work
342024-08-05T19:09:20.089Z++ awk '$2 == "/home" { print $3 }' /etc/mnttab
352024-08-05T19:09:20.091Z+ home_fs=zfs
362024-08-05T19:09:20.091Z+ [[ zfs == autofs ]]
372024-08-05T19:09:20.092Z+ mkdir -p /home/build
382024-08-05T19:09:20.094Z+ chown build:build /home/build /work
392024-08-05T19:09:21.095Z+ chmod 0700 /home/build /work
402024-08-05T19:09:21.098Zprocess exited: duration 3819 ms, exit code 0
 
412024-08-05T19:09:21.104Zstarting task 1: "authentication"
422024-08-05T19:09:21.123Zprocess exited: duration 17 ms, exit code 0
 
432024-08-05T19:09:21.129Zstarting task 2: "build"
442024-08-05T19:09:21.134Z+ banner cores
452024-08-05T19:09:21.152Z
462024-08-05T19:09:21.152Z #### #### ##### ###### ####
472024-08-05T19:09:21.152Z # # # # # # # #
482024-08-05T19:09:21.152Z # # # # # ##### ####
492024-08-05T19:09:21.153Z # # # ##### # #
502024-08-05T19:09:21.153Z # # # # # # # # #
512024-08-05T19:09:21.153Z #### #### # # ###### ####
522024-08-05T19:09:21.153Z
532024-08-05T19:09:21.155Z+ pfexec coreadm -i /tmp/core.%f.%p -g /tmp/core.%f.%p -e global -e log -e proc-setid -e global-setid
542024-08-05T19:09:21.173Z+ echo 'input bins dir contains:'
552024-08-05T19:09:21.176Zinput bins dir contains:
562024-08-05T19:09:21.176Z+ ls -ltr /input/build/work/bins
572024-08-05T19:09:21.176Ztotal 697383
582024-08-05T19:09:21.176Z-rw-r--r-- 1 root root 105756823 Aug 5 19:09 crucible-downstairs.gz
592024-08-05T19:09:21.176Z-rw-r--r-- 1 root root 83355941 Aug 5 19:09 crucible-hammer.gz
602024-08-05T19:09:21.176Z-rw-r--r-- 1 root root 103298177 Aug 5 19:09 crutest.gz
612024-08-05T19:09:21.176Z-rw-r--r-- 1 root root 64414616 Aug 5 19:09 dsc.gz
622024-08-05T19:09:21.176Z+ banner unpack
632024-08-05T19:09:21.179Z
642024-08-05T19:09:21.179Z # # # # ##### ## #### # #
652024-08-05T19:09:21.179Z # # ## # # # # # # # # #
662024-08-05T19:09:21.179Z # # # # # # # # # # ####
672024-08-05T19:09:21.179Z # # # # # ##### ###### # # #
682024-08-05T19:09:21.179Z # # # ## # # # # # # #
692024-08-05T19:09:21.179Z #### # # # # # #### # #
702024-08-05T19:09:21.179Z
712024-08-05T19:09:21.179Z+ mkdir -p /var/tmp/bins
722024-08-05T19:09:21.182Z+ for t in "$input/bins/"*.gz
732024-08-05T19:09:21.182Z++ basename /input/build/work/bins/crucible-downstairs.gz
742024-08-05T19:09:21.182Z+ b=crucible-downstairs.gz
752024-08-05T19:09:21.182Z+ b=crucible-downstairs
762024-08-05T19:09:21.182Z+ gunzip
772024-08-05T19:09:23.419Z+ chmod +x /var/tmp/bins/crucible-downstairs
782024-08-05T19:09:23.422Z+ for t in "$input/bins/"*.gz
792024-08-05T19:09:23.425Z++ basename /input/build/work/bins/crucible-hammer.gz
802024-08-05T19:09:23.425Z+ b=crucible-hammer.gz
812024-08-05T19:09:23.425Z+ b=crucible-hammer
822024-08-05T19:09:23.425Z+ gunzip
832024-08-05T19:09:25.234Z+ chmod +x /var/tmp/bins/crucible-hammer
842024-08-05T19:09:25.237Z+ for t in "$input/bins/"*.gz
852024-08-05T19:09:25.240Z++ basename /input/build/work/bins/crutest.gz
862024-08-05T19:09:25.240Z+ b=crutest.gz
872024-08-05T19:09:25.240Z+ b=crutest
882024-08-05T19:09:25.240Z+ gunzip
892024-08-05T19:09:27.376Z+ chmod +x /var/tmp/bins/crutest
902024-08-05T19:09:27.380Z+ for t in "$input/bins/"*.gz
912024-08-05T19:09:27.380Z++ basename /input/build/work/bins/dsc.gz
922024-08-05T19:09:27.380Z+ b=dsc.gz
932024-08-05T19:09:27.380Z+ b=dsc
942024-08-05T19:09:27.380Z+ gunzip
952024-08-05T19:09:28.750Z+ chmod +x /var/tmp/bins/dsc
962024-08-05T19:09:28.759Z+ export BINDIR=/var/tmp/bins
972024-08-05T19:09:28.759Z+ BINDIR=/var/tmp/bins
982024-08-05T19:09:28.759Z+ jobpid=1137
992024-08-05T19:09:28.759Z+ echo 'Setup debug logging'
1002024-08-05T19:09:28.759Z+ mkdir /tmp/debug
1012024-08-05T19:09:28.759Z+ sleep 7200
1022024-08-05T19:09:28.759ZSetup debug logging
1032024-08-05T19:09:28.759Z+ psrinfo -v
1042024-08-05T19:09:28.768Z+ df -h
1052024-08-05T19:09:28.772Z+ prstat -d d -mLc 1
1062024-08-05T19:09:28.772Z+ iostat -T d -xn 1
1072024-08-05T19:09:28.772Z+ mpstat -T d 1
1082024-08-05T19:09:28.772Z+ vmstat -T d -p 1
1092024-08-05T19:09:28.772Z+ pfexec dtrace -Z -s /input/build/work/scripts/perf-downstairs-tick.d
1102024-08-05T19:09:28.772Z+ pfexec dtrace -Z -s /input/build/work/scripts/upstairs_info.d
1112024-08-05T19:09:28.778Z+ banner test_up_unencrypted
1122024-08-05T19:09:28.778Z
1132024-08-05T19:09:28.778Z ##### ###### #### ##### # # ##### # # # #
1142024-08-05T19:09:28.778Z # # # # # # # # # # ## #
1152024-08-05T19:09:28.778Z # ##### #### # # # # # # # # # #
1162024-08-05T19:09:28.778Z # # # # # # ##### # # # # #
1172024-08-05T19:09:28.779Z # # # # # # # # # # # ##
1182024-08-05T19:09:28.779Z # ###### #### # ####### #### # ####### #### # #
1192024-08-05T19:09:28.779Z
1202024-08-05T19:09:28.779Z+ ptime -m bash /input/build/work/scripts/test_up.sh -N unencrypted
1212024-08-05T19:09:28.812Z/input/build/work
1222024-08-05T19:09:28.826ZTurn off color for downstairs dump
1232024-08-05T19:09:28.832Zdsc output goes to /tmp/test_up/dsc-out.txt
1242024-08-05T19:09:28.832ZCreating three downstairs regions
1252024-08-05T19:09:29.226ZStarting three downstairs
1262024-08-05T19:09:34.233ZDisable automatic restart on all downstairs
1272024-08-05T19:09:34.295Z
1282024-08-05T19:09:34.295ZBegin tests, output goes to /tmp/test_up/test_up_out.txt
1292024-08-05T19:09:34.299ZRunning test: span
1302024-08-05T19:09:38.349ZCompleted test: span
1312024-08-05T19:09:43.356ZRunning test: big
1322024-08-05T19:09:47.505ZCompleted test: big
1332024-08-05T19:09:52.511ZRunning test: dep
1342024-08-05T19:10:06.382ZCompleted test: dep
1352024-08-05T19:10:11.389ZRunning test: balloon
1362024-08-05T19:10:23.196ZCompleted test: balloon
1372024-08-05T19:10:28.203ZRunning test: deactivate
1382024-08-05T19:11:22.386ZCompleted test: deactivate
1392024-08-05T19:11:27.392ZRunning hammer
1402024-08-05T19:11:30.865ZRun repair tests
1412024-08-05T19:11:30.868Z/var/tmp/bins/crutest fill -g 31 -q -t 127.0.0.1:8810 -t 127.0.0.1:8820 -t 127.0.0.1:8830 --verify-out /var/tmp/test_up/verify_file
1422024-08-05T19:11:30.884Z{"msg":"Upstairs starts","v":0,"name":"crucible","level":30,"time":"2024-08-05T19:11:30.454302757Z","hostname":"w-01J4HZ22M1CAY0GA8Y82EE8T1F","pid":1215}
1432024-08-05T19:11:30.889Z{"msg":"Crucible Version: BuildInfo {\n version: \"0.0.1\",\n git_sha: \"955d5f2fb08fa12300fcdaa7dafdc9edb7db9942\",\n git_commit_timestamp: \"2024-08-01T19:59:22.000000000Z\",\n git_branch: \"fioffs-redux\",\n rustc_semver: \"1.76.0\",\n rustc_channel: \"stable\",\n rustc_host_triple: \"x86_64-unknown-illumos\",\n rustc_commit_sha: \"07dca489ac2d933c78d3c5158e3f43beefeb02ce\",\n cargo_triple: \"x86_64-unknown-illumos\",\n debug: true,\n opt_level: 0,\n}","v":0,"name":"crucible","level":30,"time":"2024-08-05T19:11:30.454929471Z","hostname":"w-01J4HZ22M1CAY0GA8Y82EE8T1F","pid":1215}
1442024-08-05T19:11:30.889Z{"msg":"Upstairs <-> Downstairs Message Version: 11","v":0,"name":"crucible","level":30,"time":"2024-08-05T19:11:30.454974645Z","hostname":"w-01J4HZ22M1CAY0GA8Y82EE8T1F","pid":1215}
1452024-08-05T19:11:30.889Z{"msg":"Crucible bbfcec52-81c4-4a50-af4a-da3afb459b5d has session id: 63542410-43e9-4fd5-8062-9d7d09e35541","v":0,"name":"crucible","level":30,"time":"2024-08-05T19:11:30.455025218Z","hostname":"w-01J4HZ22M1CAY0GA8Y82EE8T1F","pid":1215,"session_id":"63542410-43e9-4fd5-8062-9d7d09e35541"}
1462024-08-05T19:11:30.889Z{"msg":"Upstairs opts: Upstairs UUID: bbfcec52-81c4-4a50-af4a-da3afb459b5d, Targets: [127.0.0.1:8810, 127.0.0.1:8820, 127.0.0.1:8830], lossy: false, flush_timeout: None, key populated: false, cert_pem populated: false, key_pem populated: false, root_cert_pem populated: false, Control: None, read_only: false","v":0,"name":"crucible","level":30,"time":"2024-08-05T19:11:30.455077682Z","hostname":"w-01J4HZ22M1CAY0GA8Y82EE8T1F","pid":1215,"session_id":"63542410-43e9-4fd5-8062-9d7d09e35541"}
1472024-08-05T19:11:30.889Z{"msg":"Crucible stats registered with UUID: bbfcec52-81c4-4a50-af4a-da3afb459b5d","v":0,"name":"crucible","level":30,"time":"2024-08-05T19:11:30.455108924Z","hostname":"w-01J4HZ22M1CAY0GA8Y82EE8T1F","pid":1215,"session_id":"63542410-43e9-4fd5-8062-9d7d09e35541"}
1482024-08-05T19:11:30.889ZCrucible runtime is spawned
1492024-08-05T19:11:30.889Z{"msg":"The guest has requested activation with gen:31","v":0,"name":"crucible","level":30,"time":"2024-08-05T19:11:30.455414016Z","hostname":"w-01J4HZ22M1CAY0GA8Y82EE8T1F","pid":1215}
1502024-08-05T19:11:30.889Z{"msg":"bbfcec52-81c4-4a50-af4a-da3afb459b5d active request set","v":0,"name":"crucible","level":30,"time":"2024-08-05T19:11:30.455457439Z","hostname":"w-01J4HZ22M1CAY0GA8Y82EE8T1F","pid":1215,"session_id":"63542410-43e9-4fd5-8062-9d7d09e35541"}
1512024-08-05T19:11:30.889Z{"msg":"sending connect oneshot to client","v":0,"name":"crucible","level":30,"time":"2024-08-05T19:11:30.455500272Z","hostname":"w-01J4HZ22M1CAY0GA8Y82EE8T1F","pid":1215,"client":"0","":"downstairs","session_id":"63542410-43e9-4fd5-8062-9d7d09e35541"}
1522024-08-05T19:11:30.889Z{"msg":"client set_active_request while in New; waiting...","v":0,"name":"crucible","level":30,"time":"2024-08-05T19:11:30.455548955Z","hostname":"w-01J4HZ22M1CAY0GA8Y82EE8T1F","pid":1215,"client":"0","":"downstairs","session_id":"63542410-43e9-4fd5-8062-9d7d09e35541"}
1532024-08-05T19:11:30.889Z{"msg":"sending connect oneshot to client","v":0,"name":"crucible","level":30,"time":"2024-08-05T19:11:30.455583728Z","hostname":"w-01J4HZ22M1CAY0GA8Y82EE8T1F","pid":1215,"client":"1","":"downstairs","session_id":"63542410-43e9-4fd5-8062-9d7d09e35541"}
1542024-08-05T19:11:30.889Z{"msg":"client set_active_request while in New; waiting...","v":0,"name":"crucible","level":30,"time":"2024-08-05T19:11:30.455630581Z","hostname":"w-01J4HZ22M1CAY0GA8Y82EE8T1F","pid":1215,"client":"1","":"downstairs","session_id":"63542410-43e9-4fd5-8062-9d7d09e35541"}
1552024-08-05T19:11:30.889Z{"msg":"sending connect oneshot to client","v":0,"name":"crucible","level":30,"time":"2024-08-05T19:11:30.455663863Z","hostname":"w-01J4HZ22M1CAY0GA8Y82EE8T1F","pid":1215,"client":"2","":"downstairs","session_id":"63542410-43e9-4fd5-8062-9d7d09e35541"}
1562024-08-05T19:11:30.889Z{"msg":"client set_active_request while in New; waiting...","v":0,"name":"crucible","level":30,"time":"2024-08-05T19:11:30.455704596Z","hostname":"w-01J4HZ22M1CAY0GA8Y82EE8T1F","pid":1215,"client":"2","":"downstairs","session_id":"63542410-43e9-4fd5-8062-9d7d09e35541"}
1572024-08-05T19:11:30.889Z{"msg":"connecting to 127.0.0.1:8810","v":0,"name":"crucible","level":30,"time":"2024-08-05T19:11:30.455731898Z","hostname":"w-01J4HZ22M1CAY0GA8Y82EE8T1F","pid":1215,"":"io task","client":"0","":"downstairs","session_id":"63542410-43e9-4fd5-8062-9d7d09e35541"}
1582024-08-05T19:11:30.889Z{"msg":"connecting to 127.0.0.1:8820","v":0,"name":"crucible","level":30,"time":"2024-08-05T19:11:30.455768461Z","hostname":"w-01J4HZ22M1CAY0GA8Y82EE8T1F","pid":1215,"":"io task","client":"1","":"downstairs","session_id":"63542410-43e9-4fd5-8062-9d7d09e35541"}
1592024-08-05T19:11:30.889Z{"msg":"connecting to 127.0.0.1:8830","v":0,"name":"crucible","level":30,"time":"2024-08-05T19:11:30.455795603Z","hostname":"w-01J4HZ22M1CAY0GA8Y82EE8T1F","pid":1215,"":"io task","client":"2","":"downstairs","session_id":"63542410-43e9-4fd5-8062-9d7d09e35541"}
1602024-08-05T19:11:30.889Z{"msg":"ds_connection connected from Ok(127.0.0.1:44708)","v":0,"name":"crucible","level":30,"time":"2024-08-05T19:11:30.455820465Z","hostname":"w-01J4HZ22M1CAY0GA8Y82EE8T1F","pid":1215,"":"io task","client":"2","":"downstairs","session_id":"63542410-43e9-4fd5-8062-9d7d09e35541"}
1612024-08-05T19:11:30.889Z{"msg":"ds_connection connected from Ok(127.0.0.1:63508)","v":0,"name":"crucible","level":30,"time":"2024-08-05T19:11:30.455908321Z","hostname":"w-01J4HZ22M1CAY0GA8Y82EE8T1F","pid":1215,"":"io task","client":"0","":"downstairs","session_id":"63542410-43e9-4fd5-8062-9d7d09e35541"}
1622024-08-05T19:11:30.889Z{"msg":"ds_connection connected from Ok(127.0.0.1:46211)","v":0,"name":"crucible","level":30,"time":"2024-08-05T19:11:30.456026139Z","hostname":"w-01J4HZ22M1CAY0GA8Y82EE8T1F","pid":1215,"":"io task","client":"1","":"downstairs","session_id":"63542410-43e9-4fd5-8062-9d7d09e35541"}
1632024-08-05T19:11:30.889Z{"msg":"ds_transition from New to WaitActive","v":0,"name":"crucible","level":30,"time":"2024-08-05T19:11:30.456670414Z","hostname":"w-01J4HZ22M1CAY0GA8Y82EE8T1F","pid":1215,"client":"2","":"downstairs","session_id":"63542410-43e9-4fd5-8062-9d7d09e35541"}
1642024-08-05T19:11:30.889Z{"msg":"[2] Transition from New to WaitActive","v":0,"name":"crucible","level":30,"time":"2024-08-05T19:11:30.456709767Z","hostname":"w-01J4HZ22M1CAY0GA8Y82EE8T1F","pid":1215,"client":"2","":"downstairs","session_id":"63542410-43e9-4fd5-8062-9d7d09e35541"}
1652024-08-05T19:11:30.889Z{"msg":"ds_transition from New to WaitActive","v":0,"name":"crucible","level":30,"time":"2024-08-05T19:11:30.456726469Z","hostname":"w-01J4HZ22M1CAY0GA8Y82EE8T1F","pid":1215,"client":"0","":"downstairs","session_id":"63542410-43e9-4fd5-8062-9d7d09e35541"}
1662024-08-05T19:11:30.889Z{"msg":"[0] Transition from New to WaitActive","v":0,"name":"crucible","level":30,"time":"2024-08-05T19:11:30.45674129Z","hostname":"w-01J4HZ22M1CAY0GA8Y82EE8T1F","pid":1215,"client":"0","":"downstairs","session_id":"63542410-43e9-4fd5-8062-9d7d09e35541"}
1672024-08-05T19:11:30.889Z{"msg":"ds_transition from New to WaitActive","v":0,"name":"crucible","level":30,"time":"2024-08-05T19:11:30.456843417Z","hostname":"w-01J4HZ22M1CAY0GA8Y82EE8T1F","pid":1215,"client":"1","":"downstairs","session_id":"63542410-43e9-4fd5-8062-9d7d09e35541"}
1682024-08-05T19:11:30.889Z{"msg":"[1] Transition from New to WaitActive","v":0,"name":"crucible","level":30,"time":"2024-08-05T19:11:30.45688632Z","hostname":"w-01J4HZ22M1CAY0GA8Y82EE8T1F","pid":1215,"client":"1","":"downstairs","session_id":"63542410-43e9-4fd5-8062-9d7d09e35541"}
1692024-08-05T19:11:30.889Z{"msg":"downstairs client at Some(127.0.0.1:8830) has region UUID 12345678-0000-0000-0000-000000008830","v":0,"name":"crucible","level":30,"time":"2024-08-05T19:11:30.457326991Z","hostname":"w-01J4HZ22M1CAY0GA8Y82EE8T1F","pid":1215,"client":"2","":"downstairs","session_id":"63542410-43e9-4fd5-8062-9d7d09e35541"}
1702024-08-05T19:11:30.889Z{"msg":"downstairs client at Some(127.0.0.1:8810) has region UUID 12345678-0000-0000-0000-000000008810","v":0,"name":"crucible","level":30,"time":"2024-08-05T19:11:30.45744594Z","hostname":"w-01J4HZ22M1CAY0GA8Y82EE8T1F","pid":1215,"client":"0","":"downstairs","session_id":"63542410-43e9-4fd5-8062-9d7d09e35541"}
1712024-08-05T19:11:30.889Z{"msg":"downstairs client at Some(127.0.0.1:8820) has region UUID 12345678-0000-0000-0000-000000008820","v":0,"name":"crucible","level":30,"time":"2024-08-05T19:11:30.457478272Z","hostname":"w-01J4HZ22M1CAY0GA8Y82EE8T1F","pid":1215,"client":"1","":"downstairs","session_id":"63542410-43e9-4fd5-8062-9d7d09e35541"}
1722024-08-05T19:11:30.889Z{"msg":"ds_transition from WaitActive to WaitQuorum","v":0,"name":"crucible","level":30,"time":"2024-08-05T19:11:30.457656134Z","hostname":"w-01J4HZ22M1CAY0GA8Y82EE8T1F","pid":1215,"client":"2","":"downstairs","session_id":"63542410-43e9-4fd5-8062-9d7d09e35541"}
1732024-08-05T19:11:30.889Z{"msg":"[2] Transition from WaitActive to WaitQuorum","v":0,"name":"crucible","level":30,"time":"2024-08-05T19:11:30.457692047Z","hostname":"w-01J4HZ22M1CAY0GA8Y82EE8T1F","pid":1215,"client":"2","":"downstairs","session_id":"63542410-43e9-4fd5-8062-9d7d09e35541"}
1742024-08-05T19:11:30.889Z{"msg":"Waiting for more clients to be ready","v":0,"name":"crucible","level":30,"time":"2024-08-05T19:11:30.457713598Z","hostname":"w-01J4HZ22M1CAY0GA8Y82EE8T1F","pid":1215,"session_id":"63542410-43e9-4fd5-8062-9d7d09e35541"}
1752024-08-05T19:11:30.889Z{"msg":"ds_transition from WaitActive to WaitQuorum","v":0,"name":"crucible","level":30,"time":"2024-08-05T19:11:30.457804455Z","hostname":"w-01J4HZ22M1CAY0GA8Y82EE8T1F","pid":1215,"client":"0","":"downstairs","session_id":"63542410-43e9-4fd5-8062-9d7d09e35541"}
1762024-08-05T19:11:30.889Z{"msg":"[0] Transition from WaitActive to WaitQuorum","v":0,"name":"crucible","level":30,"time":"2024-08-05T19:11:30.457844848Z","hostname":"w-01J4HZ22M1CAY0GA8Y82EE8T1F","pid":1215,"client":"0","":"downstairs","session_id":"63542410-43e9-4fd5-8062-9d7d09e35541"}
1772024-08-05T19:11:30.890Z{"msg":"Waiting for more clients to be ready","v":0,"name":"crucible","level":30,"time":"2024-08-05T19:11:30.45787169Z","hostname":"w-01J4HZ22M1CAY0GA8Y82EE8T1F","pid":1215,"session_id":"63542410-43e9-4fd5-8062-9d7d09e35541"}
1782024-08-05T19:11:30.890Z{"msg":"ds_transition from WaitActive to WaitQuorum","v":0,"name":"crucible","level":30,"time":"2024-08-05T19:11:30.457899261Z","hostname":"w-01J4HZ22M1CAY0GA8Y82EE8T1F","pid":1215,"client":"1","":"downstairs","session_id":"63542410-43e9-4fd5-8062-9d7d09e35541"}
1792024-08-05T19:11:30.890Z{"msg":"[1] Transition from WaitActive to WaitQuorum","v":0,"name":"crucible","level":30,"time":"2024-08-05T19:11:30.457924553Z","hostname":"w-01J4HZ22M1CAY0GA8Y82EE8T1F","pid":1215,"client":"1","":"downstairs","session_id":"63542410-43e9-4fd5-8062-9d7d09e35541"}
1802024-08-05T19:11:30.890Z{"msg":"[0]R flush_numbers: [1532, 1532, 1532, 1532, 1532]","v":0,"name":"crucible","level":30,"time":"2024-08-05T19:11:30.457952915Z","hostname":"w-01J4HZ22M1CAY0GA8Y82EE8T1F","pid":1215,"":"downstairs","":"downstairs","session_id":"63542410-43e9-4fd5-8062-9d7d09e35541"}
1812024-08-05T19:11:30.890Z{"msg":"[0]R generation: [25, 25, 25, 25, 25]","v":0,"name":"crucible","level":30,"time":"2024-08-05T19:11:30.457977287Z","hostname":"w-01J4HZ22M1CAY0GA8Y82EE8T1F","pid":1215,"":"downstairs","":"downstairs","session_id":"63542410-43e9-4fd5-8062-9d7d09e35541"}
1822024-08-05T19:11:30.890Z{"msg":"[0]R dirty: [false, false, false, false, false]","v":0,"name":"crucible","level":30,"time":"2024-08-05T19:11:30.458001649Z","hostname":"w-01J4HZ22M1CAY0GA8Y82EE8T1F","pid":1215,"":"downstairs","":"downstairs","Wait for a query_work_queue command to finish before sending IO
1832024-08-05T19:11:30.890Zsession_id":"63542410-43e9-4fd5-8062-9d7d09e35541"}
1842024-08-05T19:11:30.890Z{"msg":"[1]R flush_numbers: [1532, 1532, 1532, 1532, 1532]","v":0,"name":"crucible","level":30,"time":"2024-08-05T19:11:30.458039501Z","hostname":"w-01J4HZ22M1CAY0GA8Y82EE8T1F","pid":1215,"":"downstairs","":"downstairs","session_id":"63542410-43e9-4fd5-8062-9d7d09e35541"}
1852024-08-05T19:11:30.890Z{"msg":"[1]R generation: [25, 25, 25, 25, 25]","v":0,"name":"crucible","level":30,"time":"2024-08-05T19:11:30.458064943Z","hostname":"w-01J4HZ22M1CAY0GA8Y82EE8T1F","pid":1215,"":"downstairs","":"downstairs","session_id":"63542410-43e9-4fd5-8062-9d7d09e35541"}
1862024-08-05T19:11:30.890Z{"msg":"[1]R dirty: [false, false, false, false, false]","v":0,"name":"crucible","level":30,"time":"2024-08-05T19:11:30.458096355Z","hostname":"w-01J4HZ22M1CAY0GA8Y82EE8T1F","pid":1215,"":"downstairs","":"downstairs","session_id":"63542410-43e9-4fd5-8062-9d7d09e35541"}
1872024-08-05T19:11:30.890Z{"msg":"[2]R flush_numbers: [1532, 1532, 1532, 1532, 1532]","v":0,"name":"crucible","level":30,"time":"2024-08-05T19:11:30.458121557Z","hostname":"w-01J4HZ22M1CAY0GA8Y82EE8T1F","pid":1215,"":"downstairs","":"downstairs","session_id":"63542410-43e9-4fd5-8062-9d7d09e35541"}
1882024-08-05T19:11:30.890Z{"msg":"[2]R generation: [25, 25, 25, 25, 25]","v":0,"name":"crucible","level":30,"time":"2024-08-05T19:11:30.458149139Z","hostname":"w-01J4HZ22M1CAY0GA8Y82EE8T1F","pid":1215,"":"downstairs","":"downstairs","session_id":"63542410-43e9-4fd5-8062-9d7d09e35541"}
1892024-08-05T19:11:30.890Z{"msg":"[2]R dirty: [false, false, false, false, false]","v":0,"name":"crucible","level":30,"time":"2024-08-05T19:11:30.458173741Z","hostname":"w-01J4HZ22M1CAY0GA8Y82EE8T1F","pid":1215,"":"downstairs","":"downstairs","session_id":"63542410-43e9-4fd5-8062-9d7d09e35541"}
1902024-08-05T19:11:30.890Z{"msg":"Max found gen is 26","v":0,"name":"crucible","level":30,"time":"2024-08-05T19:11:30.458201223Z","hostname":"w-01J4HZ22M1CAY0GA8Y82EE8T1F","pid":1215,"":"downstairs","":"downstairs","session_id":"63542410-43e9-4fd5-8062-9d7d09e35541"}
1912024-08-05T19:11:30.890Z{"msg":"Generation requested: 31 >= found:26","v":0,"name":"crucible","level":30,"time":"2024-08-05T19:11:30.458225055Z","hostname":"w-01J4HZ22M1CAY0GA8Y82EE8T1F","pid":1215,"":"downstairs","":"downstairs","session_id":"63542410-43e9-4fd5-8062-9d7d09e35541"}
1922024-08-05T19:11:30.890Z{"msg":"Next flush: 1533","v":0,"name":"crucible","level":30,"time":"2024-08-05T19:11:30.458252937Z","hostname":"w-01J4HZ22M1CAY0GA8Y82EE8T1F","pid":1215,"":"downstairs","":"downstairs","session_id":"63542410-43e9-4fd5-8062-9d7d09e35541"}
1932024-08-05T19:11:30.890Z{"msg":"All extents match","Region: es:10 ec:5 bs:4096 ts:204800 tb:50 max_io:50 or 204800
1942024-08-05T19:11:30.893Zv":0,"name":"crucible","level":30,"time":"2024-08-05T19:11:30.458283499Z","hostname":"w-01J4HZ22M1CAY0GA8Y82EE8T1F","pid":1215,"":"downstairs","":"downstairs","session_id":"63542410-43e9-4fd5-8062-9d7d09e35541"}
1952024-08-05T19:11:30.893ZFill test
1962024-08-05T19:11:30.893Z{"msg":"No downstairs reconciliation required","v":0,"name":"crucible","level":30,"time":"2024-08-05T19:11:30.458317361Z","hostname":"w-01J4HZ22M1CAY0GA8Y82EE8T1F","pid":1215,"session_id":"63542410-43e9-4fd5-8062-9d7d09e35541"}
1972024-08-05T19:11:30.893Z{"msg":"Transition from WaitQuorum to Active","v":0,"name":"crucible","level":30,"time":"2024-08-05T19:11:30.458340523Z","hostname":"w-01J4HZ22M1CAY0GA8Y82EE8T1F","pid":1215,"client":"0","":"downstairs","session_id":"63542410-43e9-4fd5-8062-9d7d09e35541"}
1982024-08-05T19:11:30.893Z{"msg":"Transition from WaitQuorum to Active","v":0,"name":"crucible","level":30,"time":"2024-08-05T19:11:30.458365354Z","hostname":"w-01J4HZ22M1CAY0GA8Y82EE8T1F","pid":1215,"client":"1","":"downstairs","session_id":"63542410-43e9-4fd5-8062-9d7d09e35541"}
1992024-08-05T19:11:30.893Z{"msg":"Transition from WaitQuorum to Active","v":0,"name":"crucible","level":30,"time":"2024-08-05T19:11:30.458388756Z","hostname":"w-01J4HZ22M1CAY0GA8Y82EE8T1F","pid":1215,"client":"2","":"downstairs","session_id":"63542410-43e9-4fd5-8062-9d7d09e35541"}
2002024-08-05T19:11:30.893Z{"msg":"All required reconciliation work is completed","v":0,"name":"crucible","level":30,"time":"2024-08-05T19:11:30.458420888Z","hostname":"w-01J4HZ22M1CAY0GA8Y82EE8T1F","pid":1215,"session_id":"63542410-43e9-4fd5-8062-9d7d09e35541"}
2012024-08-05T19:11:30.893Z{"msg":"Set Downstairs and Upstairs active after reconciliation","v":0,"name":"crucible","level":30,"time":"2024-08-05T19:11:30.458444Z","hostname":"w-01J4HZ22M1CAY0GA8Y82EE8T1F","pid":1215,"session_id":"63542410-43e9-4fd5-8062-9d7d09e35541"}
2022024-08-05T19:11:30.893Z{"msg":"bbfcec52-81c4-4a50-af4a-da3afb459b5d is now active with session: 63542410-43e9-4fd5-8062-9d7d09e35541","v":0,"name":"crucible","level":30,"time":"2024-08-05T19:11:30.458475462Z","hostname":"w-01J4HZ22M1CAY0GA8Y82EE8T1F","pid":1215,"session_id":"63542410-43e9-4fd5-8062-9d7d09e35541"}
2032024-08-05T19:11:30.893Z{"msg":"Set Active after no reconciliation","v":0,"name":"crucible","level":30,"time":"2024-08-05T19:11:30.458497704Z","hostname":"w-01J4HZ22M1CAY0GA8Y82EE8T1F","pid":1215,"session_id":"63542410-43e9-4fd5-8062-9d7d09e35541"}
2042024-08-05T19:11:30.893Z{"msg":"The guest has finished waiting for activation with:31","v":0,"name":"crucible","level":30,"time":"2024-08-05T19:11:30.458523976Z","hostname":"w-01J4HZ22M1CAY0GA8Y82EE8T1F","pid":1215}
2052024-08-05T19:11:30.896ZRead and Verify all blocks (0..50 range:false)
2062024-08-05T19:11:30.901ZWrote out file "/var/tmp/test_up/verify_file"
2072024-08-05T19:11:30.901ZCLIENT: Tests done. All submitted work has been ACK'd
2082024-08-05T19:11:30.904Z----------------------------------------------------------------
2092024-08-05T19:11:30.904Z Crucible gen:31 GIO:true work queues: Upstairs:0 downstairs:1
2102024-08-05T19:11:30.904ZStates: Active Active Active
2112024-08-05T19:11:30.904ZGW_ID ACK DSID TYPE BKS/EXT DS:0 DS:1 DS:2 REPLAY
2122024-08-05T19:11:30.904Z 3 Acked 1002 Read 50 Done Done Done false
2132024-08-05T19:11:30.904Z STATES DS:0 DS:1 DS:2 TOTAL
2142024-08-05T19:11:30.904Z New 0 0 0 0
2152024-08-05T19:11:30.904Z Sent 0 0 0 0
2162024-08-05T19:11:30.904Z Done 1 1 1 3
2172024-08-05T19:11:30.904Z Skipped 0 0 0 0
2182024-08-05T19:11:30.904Z Error 0 0 0 0
2192024-08-05T19:11:30.904ZLast Flush: 1001 1001 1001
2202024-08-05T19:11:30.904ZDownstairs last five completed: 1001 1000
2212024-08-05T19:11:30.904ZUpstairs last five completed: 3 2 1
2222024-08-05T19:11:30.904ZCLIENT: Up:0 ds:1 act:3
2232024-08-05T19:11:34.902Z----------------------------------------------------------------
2242024-08-05T19:11:34.902Z Crucible gen:31 GIO:true work queues: Upstairs:0 downstairs:0
2252024-08-05T19:11:34.902ZDownstairs last five completed: 1003 1002 1001 1000
2262024-08-05T19:11:34.902ZUpstairs last five completed: 4 3 2 1
2272024-08-05T19:11:34.902ZCLIENT: Up:0 ds:0 act:3
2282024-08-05T19:11:34.902ZCLIENT: All crucible jobs finished, exiting program
2292024-08-05T19:11:34.906Z{"msg":"Guest handle has been dropped","v":0,"name":"crucible","level":40,"time":"2024-08-05T19:11:34.474028773Z","hostname":"w-01J4HZ22M1CAY0GA8Y82EE8T1F","pid":1215}
2302024-08-05T19:11:34.911ZRepair setup passed
2312024-08-05T19:11:34.915ZCopy the 8830 file
2322024-08-05T19:11:34.918Zcp -r /var/tmp/test_up/8830 /var/tmp/test_up/previous
2332024-08-05T19:11:34.920Z/var/tmp/bins/crutest repair -g 32 -q -t 127.0.0.1:8810 -t 127.0.0.1:8820 -t 127.0.0.1:8830 --verify-out /var/tmp/test_up/verify_file --verify-in /var/tmp/test_up/verify_file
2342024-08-05T19:11:34.932Z{"msg":"Upstairs starts","v":0,"name":"crucible","level":30,"time":"2024-08-05T19:11:34.503447073Z","hostname":"w-01J4HZ22M1CAY0GA8Y82EE8T1F","pid":1221}
2352024-08-05T19:11:34.935Z{"msg":"Crucible Version: BuildInfo {\n version: \"0.0.1\",\n git_sha: \"955d5f2fb08fa12300fcdaa7dafdc9edb7db9942\",\n git_commit_timestamp: \"2024-08-01T19:59:22.000000000Z\",\n git_branch: \"fioffs-redux\",\n rustc_semver: \"1.76.0\",\n rustc_channel: \"stable\",\n rustc_host_triple: \"x86_64-unknown-illumos\",\n rustc_commit_sha: \"07dca489ac2d933c78d3c5158e3f43beefeb02ce\",\n cargo_triple: \"x86_64-unknown-illumos\",\n debug: true,\n opt_level: 0,\n}","v":0,"name":"crucible","level":30,"time":"2024-08-05T19:11:34.503844112Z","hostname":"w-01J4HZ22M1CAY0GA8Y82EE8T1F","pid":1221}
2362024-08-05T19:11:34.935Z{"msg":"Upstairs <-> Downstairs Message Version: 11","v":0,"name":"crucible","level":30,"time":"2024-08-05T19:11:34.503884074Z","hostname":"w-01J4HZ22M1CAY0GA8Y82EE8T1F","pid":1221}
2372024-08-05T19:11:34.935Z{"msg":"Crucible 62c16332-f9bf-473e-a9e8-1effe2e1beb8 has session id: 9efa379e-f134-4fb1-8a4e-9f8022adf4bf","v":0,"name":"crucible","level":30,"time":"2024-08-05T19:11:34.504186486Z","hostname":"w-01J4HZ22M1CAY0GA8Y82EE8T1F","pid":1221,"session_id":"9efa379e-f134-4fb1-8a4e-9f8022adf4bf"}
2382024-08-05T19:11:34.935Z{"msg":"Upstairs opts: Upstairs UUID: 62c16332-f9bf-473e-a9e8-1effe2e1beb8, Targets: [127.0.0.1:8810, 127.0.0.1:8820, 127.0.0.1:8830], lossy: false, flush_timeout: None, key populated: false, cert_pem populated: false, key_pem populated: false, root_cert_pem populated: false, Control: None, read_only: false","v":0,"name":"crucible","level":30,"time":"2024-08-05T19:11:34.504237129Z","hostname":"w-01J4HZ22M1CAY0GA8Y82EE8T1F","pid":1221,"session_id":"9efa379e-f134-4fb1-8a4e-9f8022adf4bf"}
2392024-08-05T19:11:34.935Z{"msg":"Crucible stats registered with UUID: 62c16332-f9bf-473e-a9e8-1effe2e1beb8","v":0,"name":"crucible","level":30,"time":"2024-08-05T19:11:34.504272762Z","hostname":"w-01J4HZ22M1CAY0GA8Y82EE8T1F","pid":1221,"session_id":"9efa379e-f134-4fb1-8a4e-9f8022adf4bf"}
2402024-08-05T19:11:34.935ZCrucible runtime is spawned
2412024-08-05T19:11:34.935Z{"msg":"The guest has requested activation with gen:32","v":0,"name":"crucible","level":30,"time":"2024-08-05T19:11:34.504493007Z","hostname":"w-01J4HZ22M1CAY0GA8Y82EE8T1F","pid":1221}
2422024-08-05T19:11:34.935Z{"msg":"62c16332-f9bf-473e-a9e8-1effe2e1beb8 active request set","v":0,"name":"crucible","level":30,"time":"2024-08-05T19:11:34.504646208Z","hostname":"w-01J4HZ22M1CAY0GA8Y82EE8T1F","pid":1221,"session_id":"9efa379e-f134-4fb1-8a4e-9f8022adf4bf"}
2432024-08-05T19:11:34.935Z{"msg":"sending connect oneshot to client","v":0,"name":"crucible","level":30,"time":"2024-08-05T19:11:34.504699282Z","hostname":"w-01J4HZ22M1CAY0GA8Y82EE8T1F","pid":1221,"client":"0","":"downstairs","session_id":"9efa379e-f134-4fb1-8a4e-9f8022adf4bf"}
2442024-08-05T19:11:34.935Z{"msg":"client set_active_request while in New; waiting...","v":0,"name":"crucible","level":30,"time":"2024-08-05T19:11:34.504736585Z","hostname":"w-01J4HZ22M1CAY0GA8Y82EE8T1F","pid":1221,"client":"0","":"downstairs","session_id":"9efa379e-f134-4fb1-8a4e-9f8022adf4bf"}
2452024-08-05T19:11:34.936Z{"msg":"sending connect oneshot to client","v":0,"name":"crucible","level":30,"time":"2024-08-05T19:11:34.504753006Z","hostname":"w-01J4HZ22M1CAY0GA8Y82EE8T1F","pid":1221,"client":"1","":"downstairs","session_id":"9efa379e-f134-4fb1-8a4e-9f8022adf4bf"}
2462024-08-05T19:11:34.936Z{"msg":"client set_active_request while in New; waiting...","v":0,"name":"crucible","level":30,"time":"2024-08-05T19:11:34.504775207Z","hostname":"w-01J4HZ22M1CAY0GA8Y82EE8T1F","pid":1221,"client":"1","":"downstairs","session_id":"9efa379e-f134-4fb1-8a4e-9f8022adf4bf"}
2472024-08-05T19:11:34.936Z{"msg":"sending connect oneshot to client","v":0,"name":"crucible","level":30,"time":"2024-08-05T19:11:34.504789278Z","hostname":"w-01J4HZ22M1CAY0GA8Y82EE8T1F","pid":1221,"client":"2","":"downstairs","session_id":"9efa379e-f134-4fb1-8a4e-9f8022adf4bf"}
2482024-08-05T19:11:34.936Z{"msg":"client set_active_request while in New; waiting...","v":0,"name":"crucible","level":30,"time":"2024-08-05T19:11:34.50481039Z","hostname":"w-01J4HZ22M1CAY0GA8Y82EE8T1F","pid":1221,"client":"2","":"downstairs","session_id":"9efa379e-f134-4fb1-8a4e-9f8022adf4bf"}
2492024-08-05T19:11:34.936Z{"msg":"connecting to 127.0.0.1:8820","v":0,"name":"crucible","level":30,"time":"2024-08-05T19:11:34.504824601Z","hostname":"w-01J4HZ22M1CAY0GA8Y82EE8T1F","pid":1221,"":"io task","client":"1","":"downstairs","session_id":"9efa379e-f134-4fb1-8a4e-9f8022adf4bf"}
2502024-08-05T19:11:34.936Z{"msg":"connecting to 127.0.0.1:8810","v":0,"name":"crucible","level":30,"time":"2024-08-05T19:11:34.504845642Z","hostname":"w-01J4HZ22M1CAY0GA8Y82EE8T1F","pid":1221,"":"io task","client":"0","":"downstairs","session_id":"9efa379e-f134-4fb1-8a4e-9f8022adf4bf"}
2512024-08-05T19:11:34.936Z{"msg":"connecting to 127.0.0.1:8830","v":0,"name":"crucible","level":30,"time":"2024-08-05T19:11:34.504861564Z","hostname":"w-01J4HZ22M1CAY0GA8Y82EE8T1F","pid":1221,"":"io task","client":"2","":"downstairs","session_id":"9efa379e-f134-4fb1-8a4e-9f8022adf4bf"}
2522024-08-05T19:11:34.936Z{"msg":"ds_connection connected from Ok(127.0.0.1:58947)","v":0,"name":"crucible","level":30,"time":"2024-08-05T19:11:34.505088729Z","hostname":"w-01J4HZ22M1CAY0GA8Y82EE8T1F","pid":1221,"":"io task","client":"0","":"downstairs","session_id":"9efa379e-f134-4fb1-8a4e-9f8022adf4bf"}
2532024-08-05T19:11:34.936Z{"msg":"ds_connection connected from Ok(127.0.0.1:48861)","v":0,"name":"crucible","level":30,"time":"2024-08-05T19:11:34.505393621Z","hostname":"w-01J4HZ22M1CAY0GA8Y82EE8T1F","pid":1221,"":"io task","client":"2","":"downstairs","session_id":"9efa379e-f134-4fb1-8a4e-9f8022adf4bf"}
2542024-08-05T19:11:34.936Z{"msg":"ds_connection connected from Ok(127.0.0.1:47799)","v":0,"name":"crucible","level":30,"time":"2024-08-05T19:11:34.505451315Z","hostname":"w-01J4HZ22M1CAY0GA8Y82EE8T1F","pid":1221,"":"io task","client":"1","":"downstairs","session_id":"9efa379e-f134-4fb1-8a4e-9f8022adf4bf"}
2552024-08-05T19:11:34.936Z{"msg":"ds_transition from New to WaitActive","v":0,"name":"crucible","level":30,"time":"2024-08-05T19:11:34.505869505Z","hostname":"w-01J4HZ22M1CAY0GA8Y82EE8T1F","pid":1221,"client":"0","":"downstairs","session_id":"9efa379e-f134-4fb1-8a4e-9f8022adf4bf"}
2562024-08-05T19:11:34.936Z{"msg":"[0] Transition from New to WaitActive","v":0,"name":"crucible","level":30,"time":"2024-08-05T19:11:34.505921188Z","hostname":"w-01J4HZ22M1CAY0GA8Y82EE8T1F","pid":1221,"client":"0","":"downstairs","session_id":"9efa379e-f134-4fb1-8a4e-9f8022adf4bf"}
2572024-08-05T19:11:34.936Z{"msg":"ds_transition from New to WaitActive","v":0,"name":"crucible","level":30,"time":"2024-08-05T19:11:34.506067889Z","hostname":"w-01J4HZ22M1CAY0GA8Y82EE8T1F","pid":1221,"client":"2","":"downstairs","session_id":"9efa379e-f134-4fb1-8a4e-9f8022adf4bf"}
2582024-08-05T19:11:34.936Z{"msg":"[2] Transition from New to WaitActive","v":0,"name":"crucible","level":30,"time":"2024-08-05T19:11:34.506117552Z","hostname":"w-01J4HZ22M1CAY0GA8Y82EE8T1F","pid":1221,"client":"2","":"downstairs","session_id":"9efa379e-f134-4fb1-8a4e-9f8022adf4bf"}
2592024-08-05T19:11:34.936Z{"msg":"ds_transition from New to WaitActive","v":0,"name":"crucible","level":30,"time":"2024-08-05T19:11:34.506138774Z","hostname":"w-01J4HZ22M1CAY0GA8Y82EE8T1F","pid":1221,"client":"1","":"downstairs","session_id":"9efa379e-f134-4fb1-8a4e-9f8022adf4bf"}
2602024-08-05T19:11:34.936Z{"msg":"[1] Transition from New to WaitActive","v":0,"name":"crucible","level":30,"time":"2024-08-05T19:11:34.506165216Z","hostname":"w-01J4HZ22M1CAY0GA8Y82EE8T1F","pid":1221,"client":"1","":"downstairs","session_id":"9efa379e-f134-4fb1-8a4e-9f8022adf4bf"}
2612024-08-05T19:11:34.936Z{"msg":"downstairs client at Some(127.0.0.1:8810) has region UUID 12345678-0000-0000-0000-000000008810","v":0,"name":"crucible","level":30,"time":"2024-08-05T19:11:34.506538292Z","hostname":"w-01J4HZ22M1CAY0GA8Y82EE8T1F","pid":1221,"client":"0","":"downstairs","session_id":"9efa379e-f134-4fb1-8a4e-9f8022adf4bf"}
2622024-08-05T19:11:34.936Z{"msg":"downstairs client at Some(127.0.0.1:8820) has region UUID 12345678-0000-0000-0000-000000008820","v":0,"name":"crucible","level":30,"time":"2024-08-05T19:11:34.506663741Z","hostname":"w-01J4HZ22M1CAY0GA8Y82EE8T1F","pid":1221,"client":"1","":"downstairs","session_id":"9efa379e-f134-4fb1-8a4e-9f8022adf4bf"}
2632024-08-05T19:11:34.939Z{"msg":"downstairs client at Some(127.0.0.1:8830) has region UUID 12345678-0000-0000-0000-000000008830","v":0,"name":"crucible","level":30,"time":"2024-08-05T19:11:34.50678667Z","hostname":"w-01J4HZ22M1CAY0GA8Y82EE8T1F","pid":1221,"client":"2","":"downstairs","session_id":"9efa379e-f134-4fb1-8a4e-9f8022adf4bf"}
2642024-08-05T19:11:34.939Z{"msg":"ds_transition from WaitActive to WaitQuorum","v":0,"name":"crucible","level":30,"time":"2024-08-05T19:11:34.506957942Z","hostname":"w-01J4HZ22M1CAY0GA8Y82EE8T1F","pid":1221,"client":"0","":"downstairs","session_id":"9efa379e-f134-4fb1-8a4e-9f8022adf4bf"}
2652024-08-05T19:11:34.939Z{"msg":"[0] Transition from WaitActive to WaitQuorum","v":0,"name":"crucible","level":30,"time":"2024-08-05T19:11:34.506997215Z","hostname":"w-01J4HZ22M1CAY0GA8Y82EE8T1F","pid":1221,"client":"0","":"downstairs","session_id":"9efa379e-f134-4fb1-8a4e-9f8022adf4bf"}
2662024-08-05T19:11:34.940Z{"msg":"Waiting for more clients to be ready","v":0,"name":"crucible","level":30,"time":"2024-08-05T19:11:34.507022976Z","hostname":"w-01J4HZ22M1CAY0GA8Y82EE8T1F","pid":1221,"session_id":"9efa379e-f134-4fb1-8a4e-9f8022adf4bf"}
2672024-08-05T19:11:34.940Z{"msg":"ds_transition from WaitActive to WaitQuorum","v":0,"name":"crucible","level":30,"time":"2024-08-05T19:11:34.507141435Z","hostname":"w-01J4HZ22M1CAY0GA8Y82EE8T1F","pid":1221,"client":"2","":"downstairs","session_id":"9efa379e-f134-4fb1-8a4e-9f8022adf4bf"}
2682024-08-05T19:11:34.940Z{"msg":"[2] Transition from WaitActive to WaitQuorum","v":0,"name":"crucible","level":30,"time":"2024-08-05T19:11:34.507174857Z","hostname":"w-01J4HZ22M1CAY0GA8Y82EE8T1F","pid":1221,"client":"2","":"downstairs","session_id":"9efa379e-f134-4fb1-8a4e-9f8022adf4bf"}
2692024-08-05T19:11:34.940Z{"msg":"Waiting for more clients to be ready","v":0,"name":"crucible","level":30,"time":"2024-08-05T19:11:34.507199619Z","hostname":"w-01J4HZ22M1CAY0GA8Y82EE8T1F","pid":1221,"session_id":"9efa379e-f134-4fb1-8a4e-9f8022adf4bf"}
2702024-08-05T19:11:34.940Z{"msg":"ds_transition from WaitActive to WaitQuorum","v":0,"name":"crucible","level":30,"time":"2024-08-05T19:11:34.507226991Z","hostname":"w-01J4HZ22M1CAY0GA8Y82EE8T1F","pid":1221,"client":"1","":"downstairs","session_id":"9efa379e-f134-4fb1-8a4e-9f8022adf4bf"}
2712024-08-05T19:11:34.940Z{"msg":"[1] Transition from WaitActive to WaitQuorum","v":0,"name":"crucible","level":30,"time":"2024-08-05T19:11:34.507251393Z","hostname":"w-01J4HZ22M1CAY0GA8Y82EE8T1F","pid":1221,"client":"1","":"downstairs","session_id":"9efa379e-f134-4fb1-8a4e-9f8022adf4bf"}
2722024-08-05T19:11:34.940Z{"msg":"[0]R flush_numbers: [1533, 1533, 1533, 1533, 1533]","v":0,"name":"crucible","level":30,"time":"2024-08-05T19:11:34.507279555Z","hostname":"w-01J4HZ22M1CAY0GA8Y82EE8T1F","pid":1221,"":"downstairs","":"downstairs","session_id":"9efa379e-f134-4fb1-8a4e-9f8022adf4bf"}
2732024-08-05T19:11:34.940Z{"msg":"[0]R generation: [31, 31, 31, 31, 31]","v":0,"name":"crucible","level":30,"time":"2024-08-05T19:11:34.507303916Z","hostname":"w-01J4HZ22M1CAY0GA8Y82EE8T1F","pid":1221,"":"downstairs","":"downstairs","session_id":"9efa379e-f134-4fb1-8a4e-9f8022adf4bf"}
2742024-08-05T19:11:34.940Z{"msg":"[0]R dirty: [false, false, false, false, false]","v":0,"name":"crucible","level":30,"time":"2024-08-05T19:11:34.507331368Z","hostname":"w-01J4HZ22M1CAY0GA8Y82EE8T1F","pid":1221,"":"downstairs","":"downstairs","session_id":"9efa379e-f134-4fb1-8a4e-9f8022adf4bf"}
2752024-08-05T19:11:34.940Z{"msg":"[1]R flush_numbers: [1533, 1533, 1533, 1533, 1533]","vWait for a query_work_queue command to finish before sending IO
2762024-08-05T19:11:34.940Z":0,"name":"crucible","level":30,"time":"2024-08-05T19:11:34.507367621Z","hostname":"w-01J4HZ22M1CAY0GA8Y82EE8T1F","pid":1221,"":"downstairs","":"downstairs","session_id":"9efa379e-f134-4fb1-8a4e-9f8022adf4bf"}
2772024-08-05T19:11:34.940Z{"msg":"[1]R generation: [31, 31, 31, 31, 31]","v":0,"name":"crucible","level":30,"time":"2024-08-05T19:11:34.507392732Z","hostname":"w-01J4HZ22M1CAY0GA8Y82EE8T1F","pid":1221,"":"downstairs","":"downstairs","session_id":"9efa379e-f134-4fb1-8a4e-9f8022adf4bf"}
2782024-08-05T19:11:34.940Z{"msg":"[1]R dirty: [false, false, false, false, false]","v":0,"name":"crucible","level":30,"time":"2024-08-05T19:11:34.507421254Z","hostname":"w-01J4HZ22M1CAY0GA8Y82EE8T1F","pid":1221,"":"downstairs","":"downstairs","session_id":"9efa379e-f134-4fb1-8a4e-9f8022adf4bf"}
2792024-08-05T19:11:34.940Z{"msg":"[2]R flush_numbers: [1533, 1533, 1533, 1533, 1533]","v":0,"name":"crucible","level":30,"time":"2024-08-05T19:11:34.507445546Z","hostname":"w-01J4HZ22M1CAY0GA8Y82EE8T1F","pid":1221,"":"downstairs","":"downstairs","session_id":"9efa379e-f134-4fb1-8a4e-9f8022adf4bf"}
2802024-08-05T19:11:34.940Z{"msg":"[2]R generation: [31, 31, 31, 31, 31]","v":0,"name":"crucible","level":30,"time":"2024-08-05T19:11:34.507477758Z","hostname":"w-01J4HZ22M1CAY0GA8Y82EE8T1F","pid":1221,"":"downstairs","":"downstairs","session_id":"9efa379e-f134-4fb1-8a4e-9f8022adf4bf"}
2812024-08-05T19:11:34.940Z{"msg":"[2]R dirty: [false, false, false, false, false]","v":0,"name":"crucible","level":30,"time":"2024-08-05T19:11:34.50750242Z","hostname":"w-01J4HZ22M1CAY0GA8Y82EE8T1F","pid":1221,"":"downstairs","":"downstairs","session_id":"9efa379e-f134-4fb1-8a4e-9f8022adf4bf"}
2822024-08-05T19:11:34.940Z{"msg":"Max found gen is 32","v":0,"name":"crucible","level":30,"time":"2024-08-05T19:11:34.507529102Z","hostname":"w-01J4HZ22M1CAY0GA8Y82EE8T1F","pid":1221,"":"downstairs","":"downstairs","session_id":"9efa379e-f134-4fb1-8a4e-9f8022adf4bf"}
2832024-08-05T19:11:34.940Z{"msg":"Generation requested: 32 >= found:32","v":0,"name":"crucible","level":30,"time":"2024-08-05T19:11:34.507552954Z","hostname":"w-01J4HZ22M1CAY0GA8Y82EE8T1F","pid":1221,"":"downstairs","":"downstairs","session_id":"9efa379e-f134-4fb1-8a4e-9f8022adf4bf"}
2842024-08-05T19:11:34.940Z{"msg":"Next flush: 1534","v":0,"name":"crucible","level":30,"time":"2024-08-05T19:11:34.507579926Z","hostname":"w-01J4HZ22M1CAY0GA8Y82EE8T1F","pid":1221,"":"downstairs","":"downstairs","session_id":"9efa379e-f134-4fb1-8a4e-9f8022adf4bf"}
2852024-08-05T19:11:34.940Z{"msg":"All extents match","v":0,"name":"crucible","level":30,"time":"2024-08-05T19:11:34.507603547Z","hostname":"w-01J4HZ22M1CAY0GA8Y82EE8T1F","pid":1221,"":"downstairs","":"downstairs","session_id":"9efa379e-f134-4fb1-8a4e-9f8022adf4bf"}
2862024-08-05T19:11:34.940Z{"msg":"No downstairs reconciliation required","v":0,"name":"crucible","level":30,"time":"2024-08-05T19:11:34.507633389Z","hostname":"w-01J4HZ22M1CAY0GA8Y82EE8T1F","pid":1221,"session_id":"9efa379e-f134-4fb1-8a4e-9f8022adf4bf"}
2872024-08-05T19:11:34.940Z{"msg":"Transition from WaitQuorum to Active","v":0,"name":"crucible","level":30,"time":"2024-08-05T19:11:34.507654541Z","hostname":"w-01J4HZ22M1CAY0GA8Y82EE8T1F","pid":1221,"client":"0","":"downstairs","session_id":"9efa379e-f134-4fb1-8a4e-9f8022adf4bf"}
2882024-08-05T19:11:34.940Z{"msg":"Transition from WaitQuorum to Active","v":0,"name":"crucible","level":30,"time":"2024-08-05T19:11:34.507695974Z","hostname":"w-01J4HZ22M1CAY0GA8Y82EE8T1F","pid":1221,"client":"1","":"downstairs","session_id":"9efa379e-f134-4fb1-8a4e-9f8022adf4bf"}
2892024-08-05T19:11:34.940Z{"msg":"Transition from WaitQuorum to Active","v":0,"name":"crucible","level":30,"time":"2024-08-05T19:11:34.507720446Z","hostname":"w-01J4HZ22M1CAY0GA8Y82EE8T1F","pid":1221,"client":"2","":"downstairs","session_id":"9efa379e-f134-4fb1-8a4e-9f8022adf4bf"}
2902024-08-05T19:11:34.940Z{"msg":"All required reconciliation work is completed","v":0,"name":"crucible","level":30,"time":"2024-08-05T19:11:34.507747877Z","hostname":"w-01J4HZ22M1CAY0GA8Y82EE8T1F","pid":1221,"session_id":"9efa379e-f134-4fb1-8a4e-9f8022adf4bf"}
2912024-08-05T19:11:34.940Z{"msg":"Set Downstairs and Upstairs active after reconciliation","v":0,"name":"Region: es:10 ec:5 bs:4096 ts:204800 tb:50 max_io:50 or 204800
2922024-08-05T19:11:34.940Zcrucible","level":30,"time":"2024-08-05T19:11:34.507788851Z","hostname":"w-01J4HZ22M1CAY0GA8Y82EE8T1F","pid":1221,"session_id":"9efa379e-f134-4fb1-8a4e-9f8022adf4bf"}
2932024-08-05T19:11:34.940Z{"msg":"62c16332-f9bf-473e-a9e8-1effe2e1beb8 is now active with session: 9efa379e-f134-4fb1-8a4e-9f8022adf4bf","v":0,"name":"crucible","level":30,"time":"2024-08-05T19:11:34.507813862Z","hostname":"w-01J4HZ22M1CAY0GA8Y82EE8T1F","pid":1221,"session_id":"9efa379e-f134-4fb1-8a4e-9f8022adf4bf"}
2942024-08-05T19:11:34.940Z{"msg":"Set Active after no reconciliation","v":0,"name":"crucible","level":30,"time":"2024-08-05T19:11:34.507840684Z","hostname":"w-01J4HZ22M1CAY0GA8Y82EE8T1F","pid":1221,"session_id":"9efa379e-f134-4fb1-8a4e-9f8022adf4bf"}
2952024-08-05T19:11:34.940Z{"msg":"The guest has finished waiting for activation with:32","v":0,"name":"crucible","level":30,"time":"2024-08-05T19:11:34.507862676Z","hostname":"w-01J4HZ22M1CAY0GA8Y82EE8T1F","pid":1221}
2962024-08-05T19:11:34.940ZLoading write count information from file "/var/tmp/test_up/verify_file"
2972024-08-05T19:11:34.940ZRun Repair workload
2982024-08-05T19:11:34.940Z01/10 Write block 47 len 12288 data: 2 2 2
2992024-08-05T19:11:34.940Z02/10 Read block 1 len 40960
3002024-08-05T19:11:34.940Z03/10 Read block 13 len 28672
3012024-08-05T19:11:34.940Z04/10 Read block 38 len 8192
3022024-08-05T19:11:34.944Z05/10 Flush
3032024-08-05T19:11:34.944Z06/10 Write block 23 len 40960 data: 2 2 2 2 2 2 2 2 2 2
3042024-08-05T19:11:34.944Z07/10 Write block 6 len 24576 data: 2 2 2 2 2 2
3052024-08-05T19:11:34.944Z08/10 Read block 25 len 8192
3062024-08-05T19:11:34.944Z09/10 Write block 33 len 8192 data: 2 2
3072024-08-05T19:11:34.944Z10/10 Write block 15 len 4096 data: 2
3082024-08-05T19:11:34.944Z----------------------------------------------------------------
3092024-08-05T19:11:34.944Z Crucible gen:32 GIO:true work queues: Upstairs:0 downstairs:5
3102024-08-05T19:11:34.944ZStates: Active Active Active
3112024-08-05T19:11:34.944ZGW_ID ACK DSID TYPE BKS/EXT DS:0 DS:1 DS:2 REPLAY
3122024-08-05T19:11:34.944Z 6 Acked 1005 Write 10 Done Done Done false
3132024-08-05T19:11:34.944Z 7 Acked 1006 Write 6 Done Done Done false
3142024-08-05T19:11:34.944Z 8 Acked 1007 Read 2 Done Done Done false
3152024-08-05T19:11:34.944Z 9 Acked 1008 Write 2 Done Sent Sent false
3162024-08-05T19:11:34.944Z 10 Acked 1009 Write 1 Sent Sent Sent false
3172024-08-05T19:11:34.944Z STATES DS:0 DS:1 DS:2 TOTAL
3182024-08-05T19:11:34.945Z New 0 0 0 0
3192024-08-05T19:11:34.945Z Sent 1 2 2 5
3202024-08-05T19:11:34.945Z Done 4 3 3 10
3212024-08-05T19:11:34.945Z Skipped 0 0 0 0
3222024-08-05T19:11:34.945Z Error 0 0 0 0
3232024-08-05T19:11:34.945ZLast Flush: 1004 1004 1004
3242024-08-05T19:11:34.945ZDownstairs last five completed: 1004 1003 1002 1001 1000
3252024-08-05T19:11:34.945ZUpstairs last five completed: 10 9 8 7 6
3262024-08-05T19:11:34.948Z{"msg":"Guest handle has been dropped","v":0,"name":"crucible","level":40,"time":"2024-08-05T19:11:34.516068116Z","hostname":"w-01J4HZ22M1CAY0GA8Y82EE8T1F","pid":1221}
3272024-08-05T19:11:34.948ZWrote out file "/var/tmp/test_up/verify_file"
3282024-08-05T19:11:34.951ZRepair part 1 passed
3292024-08-05T19:11:34.951Z
3302024-08-05T19:11:34.951ZKill the current downstairs
3312024-08-05T19:11:35.059Zrm -rf /var/tmp/test_up/8830
3322024-08-05T19:11:35.060ZNow put back the original so we have a mismatch
3332024-08-05T19:11:35.060Zmv /var/tmp/test_up/previous /var/tmp/test_up/8830
3342024-08-05T19:11:35.064ZRestart downstairs with old directory
3352024-08-05T19:11:35.119Z/var/tmp/bins/crucible-downstairs dump --no-color -d /var/tmp/test_up/8810 -d /var/tmp/test_up/8820 -d /var/tmp/test_up/8830
3362024-08-05T19:11:35.136ZEXT BLOCKS GEN0 GEN1 GEN2 FL0 FL1 FL2 D0 D1 D2 DIFF
3372024-08-05T19:11:35.136Z 0 000-009 31 31 31 1533 1533 1533 T T F <---
3382024-08-05T19:11:35.136Z 1 010-019 31 31 31 1533 1533 1533 T T F <---
3392024-08-05T19:11:35.139Z 2 020-029 31 31 31 1533 1533 1533 T T F <---
3402024-08-05T19:11:35.139Z 3 030-039 31 31 31 1533 1533 1533 T T F <---
3412024-08-05T19:11:35.139Z 4 040-049 32 32 31 1534 1534 1533 F F F <---
3422024-08-05T19:11:35.139ZMax gen: 32, Max flush: 1534
3432024-08-05T19:11:35.139ZError: Difference in extent metadata found!
3442024-08-05T19:11:35.139Zdump test found error as expected
3452024-08-05T19:11:35.139Z
3462024-08-05T19:11:35.140Z
3472024-08-05T19:11:35.140Z/var/tmp/bins/crutest deactivate --range -g 33 -q -t 127.0.0.1:8810 -t 127.0.0.1:8820 -t 127.0.0.1:8830 --verify-out /var/tmp/test_up/verify_file --verify-in /var/tmp/test_up/verify_file
3482024-08-05T19:11:35.153Z{"msg":"Upstairs starts","v":0,"name":"crucible","level":30,"time":"2024-08-05T19:11:34.724343524Z","hostname":"w-01J4HZ22M1CAY0GA8Y82EE8T1F","pid":1228}
3492024-08-05T19:11:35.156Z{"msg":"Crucible Version: BuildInfo {\n version: \"0.0.1\",\n git_sha: \"955d5f2fb08fa12300fcdaa7dafdc9edb7db9942\",\n git_commit_timestamp: \"2024-08-01T19:59:22.000000000Z\",\n git_branch: \"fioffs-redux\",\n rustc_semver: \"1.76.0\",\n rustc_channel: \"stable\",\n rustc_host_triple: \"x86_64-unknown-illumos\",\n rustc_commit_sha: \"07dca489ac2d933c78d3c5158e3f43beefeb02ce\",\n cargo_triple: \"x86_64-unknown-illumos\",\n debug: true,\n opt_level: 0,\n}","v":0,"name":"crucible","level":30,"time":"2024-08-05T19:11:34.725081766Z","hostname":"w-01J4HZ22M1CAY0GA8Y82EE8T1F","pid":1228}
3502024-08-05T19:11:35.156Z{"msg":"Upstairs <-> Downstairs Message Version: 11","v":0,"name":"crucible","level":30,"time":"2024-08-05T19:11:34.725125019Z","hostname":"w-01J4HZ22M1CAY0GA8Y82EE8T1F","pid":1228}
3512024-08-05T19:11:35.156Z{"msg":"Crucible 985ce384-f588-48a7-898e-f83df481492d has session id: 138bff53-b316-48bf-ae4d-884b7471b258","v":0,"name":"crucible","level":30,"time":"2024-08-05T19:11:34.725148121Z","hostname":"w-01J4HZ22M1CAY0GA8Y82EE8T1F","pid":1228,"session_id":"138bff53-b316-48bf-ae4d-884b7471b258"}
3522024-08-05T19:11:35.156Z{"msg":"Upstairs opts: Upstairs UUID: 985ce384-f588-48a7-898e-f83df481492d, Targets: [127.0.0.1:8810, 127.0.0.1:8820, 127.0.0.1:8830], lossy: false, flush_timeout: None, key populated: false, cert_pem populated: false, key_pem populated: false, root_cert_pem populated: false, Control: None, read_only: false","v":0,"name":"crucible","level":30,"time":"2024-08-05T19:11:34.725191744Z","hostname":"w-01J4HZ22M1CAY0GA8Y82EE8T1F","pid":1228,"session_id":"138bff53-b316-48bf-ae4d-884b7471b258"}
3532024-08-05T19:11:35.156Z{"msg":"Crucible stats registered with UUID: 985ce384-f588-48a7-898e-f83df481492d","v":0,"name":"crucible","level":30,"time":"2024-08-05T19:11:34.725239667Z","hostname":"w-01J4HZ22M1CAY0GA8Y82EE8T1F","pid":1228,"session_id":"138bff53-b316-48bf-ae4d-884b7471b258"}
3542024-08-05T19:11:35.156ZCrucible runtime is spawned
3552024-08-05T19:11:35.156Z{"msg":"The guest has requested activation with gen:33","v":0,"name":"crucible","level":30,"time":"2024-08-05T19:11:34.725435181Z","hostname":"w-01J4HZ22M1CAY0GA8Y82EE8T1F","pid":1228}
3562024-08-05T19:11:35.156Z{"msg":"985ce384-f588-48a7-898e-f83df481492d active request set","v":0,"name":"crucible","level":30,"time":"2024-08-05T19:11:34.725465723Z","hostname":"w-01J4HZ22M1CAY0GA8Y82EE8T1F","pid":1228,"session_id":"138bff53-b316-48bf-ae4d-884b7471b258"}
3572024-08-05T19:11:35.156Z{"msg":"sending connect oneshot to client","v":0,"name":"crucible","level":30,"time":"2024-08-05T19:11:34.725479914Z","hostname":"w-01J4HZ22M1CAY0GA8Y82EE8T1F","pid":1228,"client":"0","":"downstairs","session_id":"138bff53-b316-48bf-ae4d-884b7471b258"}
3582024-08-05T19:11:35.156Z{"msg":"client set_active_request while in New; waiting...","v":0,"name":"crucible","level":30,"time":"2024-08-05T19:11:34.725496455Z","hostname":"w-01J4HZ22M1CAY0GA8Y82EE8T1F","pid":1228,"client":"0","":"downstairs","session_id":"138bff53-b316-48bf-ae4d-884b7471b258"}
3592024-08-05T19:11:35.156Z{"msg":"sending connect oneshot to client","v":0,"name":"crucible","level":30,"time":"2024-08-05T19:11:34.725518467Z","hostname":"w-01J4HZ22M1CAY0GA8Y82EE8T1F","pid":1228,"client":"1","":"downstairs","session_id":"138bff53-b316-48bf-ae4d-884b7471b258"}
3602024-08-05T19:11:35.156Z{"msg":"client set_active_request while in New; waiting...","v":0,"name":"crucible","level":30,"time":"2024-08-05T19:11:34.725533098Z","hostname":"w-01J4HZ22M1CAY0GA8Y82EE8T1F","pid":1228,"client":"1","":"downstairs","session_id":"138bff53-b316-48bf-ae4d-884b7471b258"}
3612024-08-05T19:11:35.156Z{"msg":"sending connect oneshot to client","v":0,"name":"crucible","level":30,"time":"2024-08-05T19:11:34.725546949Z","hostname":"w-01J4HZ22M1CAY0GA8Y82EE8T1F","pid":1228,"client":"2","":"downstairs","session_id":"138bff53-b316-48bf-ae4d-884b7471b258"}
3622024-08-05T19:11:35.156Z{"msg":"client set_active_request while in New; waiting...","v":0,"name":"crucible","level":30,"time":"2024-08-05T19:11:34.72556777Z","hostname":"w-01J4HZ22M1CAY0GA8Y82EE8T1F","pid":1228,"client":"2","":"downstairs","session_id":"138bff53-b316-48bf-ae4d-884b7471b258"}
3632024-08-05T19:11:35.156Z{"msg":"connecting to 127.0.0.1:8810","v":0,"name":"crucible","level":30,"time":"2024-08-05T19:11:34.725581851Z","hostname":"w-01J4HZ22M1CAY0GA8Y82EE8T1F","pid":1228,"":"io task","client":"0","":"downstairs","session_id":"138bff53-b316-48bf-ae4d-884b7471b258"}
3642024-08-05T19:11:35.157Z{"msg":"connecting to 127.0.0.1:8820","v":0,"name":"crucible","level":30,"time":"2024-08-05T19:11:34.725595462Z","hostname":"w-01J4HZ22M1CAY0GA8Y82EE8T1F","pid":1228,"":"io task","client":"1","":"downstairs","session_id":"138bff53-b316-48bf-ae4d-884b7471b258"}
3652024-08-05T19:11:35.157Z{"msg":"connecting to 127.0.0.1:8830","v":0,"name":"crucible","level":30,"time":"2024-08-05T19:11:34.725686779Z","hostname":"w-01J4HZ22M1CAY0GA8Y82EE8T1F","pid":1228,"":"io task","client":"2","":"downstairs","session_id":"138bff53-b316-48bf-ae4d-884b7471b258"}
3662024-08-05T19:11:35.157Z{"msg":"ds_connection connected from Ok(127.0.0.1:40988)","v":0,"name":"crucible","level":30,"time":"2024-08-05T19:11:34.725795036Z","hostname":"w-01J4HZ22M1CAY0GA8Y82EE8T1F","pid":1228,"":"io task","client":"0","":"downstairs","session_id":"138bff53-b316-48bf-ae4d-884b7471b258"}
3672024-08-05T19:11:35.157Z{"msg":"ds_connection connected from Ok(127.0.0.1:47080)","v":0,"name":"crucible","level":30,"time":"2024-08-05T19:11:34.72599058Z","hostname":"w-01J4HZ22M1CAY0GA8Y82EE8T1F","pid":1228,"":"io task","client":"1","":"downstairs","session_id":"138bff53-b316-48bf-ae4d-884b7471b258"}
3682024-08-05T19:11:35.157Z{"msg":"ds_connection connect to 127.0.0.1:8830 failure: Os { code: 146, kind: ConnectionRefused, message: \"Connection refused\" }","v":0,"name":"crucible","level":40,"time":"2024-08-05T19:11:34.726031543Z","hostname":"w-01J4HZ22M1CAY0GA8Y82EE8T1F","pid":1228,"":"io task","client":"2","":"downstairs","session_id":"138bff53-b316-48bf-ae4d-884b7471b258"}
3692024-08-05T19:11:35.157Z{"msg":"client task is sending Done(ConnectionFailed(Os { code: 146, kind: ConnectionRefused, message: \"Connection refused\" }))","v":0,"name":"crucible","level":40,"time":"2024-08-05T19:11:34.726050674Z","hostname":"w-01J4HZ22M1CAY0GA8Y82EE8T1F","pid":1228,"":"io task","client":"2","":"downstairs","session_id":"138bff53-b316-48bf-ae4d-884b7471b258"}
3702024-08-05T19:11:35.157Z{"msg":"downstairs task for 2 stopped due to ConnectionFailed(Os { code: 146, kind: ConnectionRefused, message: \"Connection refused\" })","v":0,"name":"crucible","level":40,"time":"2024-08-05T19:11:34.726112979Z","hostname":"w-01J4HZ22M1CAY0GA8Y82EE8T1F","pid":1228,"session_id":"138bff53-b316-48bf-ae4d-884b7471b258"}
3712024-08-05T19:11:35.157Z{"msg":"Gone missing, transition from New to Disconnected","v":0,"name":"crucible","level":30,"time":"2024-08-05T19:11:34.726137851Z","hostname":"w-01J4HZ22M1CAY0GA8Y82EE8T1F","pid":1228,"client":"2","":"downstairs","session_id":"138bff53-b316-48bf-ae4d-884b7471b258"}
3722024-08-05T19:11:35.157Z{"msg":"Disconnected -> New","v":0,"name":"crucible","level":30,"time":"2024-08-05T19:11:34.726151922Z","hostname":"w-01J4HZ22M1CAY0GA8Y82EE8T1F","pid":1228,"client":"2","":"downstairs","session_id":"138bff53-b316-48bf-ae4d-884b7471b258"}
3732024-08-05T19:11:35.157Z{"msg":"client task is exiting","v":0,"name":"crucible","level":30,"time":"2024-08-05T19:11:34.72626474Z","hostname":"w-01J4HZ22M1CAY0GA8Y82EE8T1F","pid":1228,"":"io task","client":"2","":"downstairs","session_id":"138bff53-b316-48bf-ae4d-884b7471b258"}
3742024-08-05T19:11:35.157Z{"msg":"ds_transition from New to WaitActive","v":0,"name":"crucible","level":30,"time":"2024-08-05T19:11:34.726748964Z","hostname":"w-01J4HZ22M1CAY0GA8Y82EE8T1F","pid":1228,"client":"1","":"downstairs","session_id":"138bff53-b316-48bf-ae4d-884b7471b258"}
3752024-08-05T19:11:35.157Z{"msg":"[1] Transition from New to WaitActive","v":0,"name":"crucible","level":30,"time":"2024-08-05T19:11:34.726788957Z","hostname":"w-01J4HZ22M1CAY0GA8Y82EE8T1F","pid":1228,"client":"1","":"downstairs","session_id":"138bff53-b316-48bf-ae4d-884b7471b258"}
3762024-08-05T19:11:35.157Z{"msg":"ds_transition from New to WaitActive","v":0,"name":"crucible","level":30,"time":"2024-08-05T19:11:34.726804668Z","hostname":"w-01J4HZ22M1CAY0GA8Y82EE8T1F","pid":1228,"client":"0","":"downstairs","session_id":"138bff53-b316-48bf-ae4d-884b7471b258"}
3772024-08-05T19:11:35.157Z{"msg":"[0] Transition from New to WaitActive","v":0,"name":"crucible","level":30,"time":"2024-08-05T19:11:34.72683792Z","hostname":"w-01J4HZ22M1CAY0GA8Y82EE8T1F","pid":1228,"client":"0","":"downstairs","session_id":"138bff53-b316-48bf-ae4d-884b7471b258"}
3782024-08-05T19:11:35.157Z{"msg":"downstairs client at Some(127.0.0.1:8820) has region UUID 12345678-0000-0000-0000-000000008820","v":0,"name":"crucible","level":30,"time":"2024-08-05T19:11:34.727364537Z","hostname":"w-01J4HZ22M1CAY0GA8Y82EE8T1F","pid":1228,"client":"1","":"downstairs","session_id":"138bff53-b316-48bf-ae4d-884b7471b258"}
3792024-08-05T19:11:35.157Z{"msg":"downstairs client at Some(127.0.0.1:8810) has region UUID 12345678-0000-0000-0000-000000008810","v":0,"name":"crucible","level":30,"time":"2024-08-05T19:11:34.727511608Z","hostname":"w-01J4HZ22M1CAY0GA8Y82EE8T1F","pid":1228,"client":"0","":"downstairs","session_id":"138bff53-b316-48bf-ae4d-884b7471b258"}
3802024-08-05T19:11:35.157Z{"msg":"ds_transition from WaitActive to WaitQuorum","v":0,"name":"crucible","level":30,"time":"2024-08-05T19:11:34.727746304Z","hostname":"w-01J4HZ22M1CAY0GA8Y82EE8T1F","pid":1228,"client":"1","":"downstairs","session_id":"138bff53-b316-48bf-ae4d-884b7471b258"}
3812024-08-05T19:11:35.160Z{"msg":"[1] Transition from WaitActive to WaitQuorum","v":0,"name":"crucible","level":30,"time":"2024-08-05T19:11:34.727790377Z","hostname":"w-01J4HZ22M1CAY0GA8Y82EE8T1F","pid":1228,"client":"1","":"downstairs","session_id":"138bff53-b316-48bf-ae4d-884b7471b258"}
3822024-08-05T19:11:35.160Z{"msg":"Waiting for more clients to be ready","v":0,"name":"crucible","level":30,"time":"2024-08-05T19:11:34.72782453Z","hostname":"w-01J4HZ22M1CAY0GA8Y82EE8T1F","pid":1228,"session_id":"138bff53-b316-48bf-ae4d-884b7471b258"}
3832024-08-05T19:11:35.160Z{"msg":"ds_transition from WaitActive to WaitQuorum","v":0,"name":"crucible","level":30,"time":"2024-08-05T19:11:34.727846161Z","hostname":"w-01J4HZ22M1CAY0GA8Y82EE8T1F","pid":1228,"client":"0","":"downstairs","session_id":"138bff53-b316-48bf-ae4d-884b7471b258"}
3842024-08-05T19:11:35.160Z{"msg":"[0] Transition from WaitActive to WaitQuorum","v":0,"name":"crucible","level":30,"time":"2024-08-05T19:11:34.727877054Z","hostname":"w-01J4HZ22M1CAY0GA8Y82EE8T1F","pid":1228,"client":"0","":"downstairs","session_id":"138bff53-b316-48bf-ae4d-884b7471b258"}
3852024-08-05T19:11:35.160Z{"msg":"Waiting for more clients to be ready","v":0,"name":"crucible","level":30,"time":"2024-08-05T19:11:34.727902135Z","hostname":"w-01J4HZ22M1CAY0GA8Y82EE8T1F","pid":1228,"session_id":"138bff53-b316-48bf-ae4d-884b7471b258"}
3862024-08-05T19:11:45.156Z{"msg":"connecting to 127.0.0.1:8830","v":0,"name":"crucible","level":30,"time":"2024-08-05T19:11:44.727705709Z","hostname":"w-01J4HZ22M1CAY0GA8Y82EE8T1F","pid":1228,"":"io task","client":"2","":"downstairs","session_id":"138bff53-b316-48bf-ae4d-884b7471b258"}
3872024-08-05T19:11:45.156Z{"msg":"ds_connection connected from Ok(127.0.0.1:57433)","v":0,"name":"crucible","level":30,"time":"2024-08-05T19:11:44.727848599Z","hostname":"w-01J4HZ22M1CAY0GA8Y82EE8T1F","pid":1228,"":"io task","client":"2","":"downstairs","session_id":"138bff53-b316-48bf-ae4d-884b7471b258"}
3882024-08-05T19:11:45.160Z{"msg":"ds_transition from New to WaitActive","v":0,"name":"crucible","level":30,"time":"2024-08-05T19:11:44.729356615Z","hostname":"w-01J4HZ22M1CAY0GA8Y82EE8T1F","pid":1228,"client":"2","":"downstairs","session_id":"138bff53-b316-48bf-ae4d-884b7471b258"}
3892024-08-05T19:11:45.160Z{"msg":"[2] Transition from New to WaitActive","v":0,"name":"crucible","level":30,"time":"2024-08-05T19:11:44.729411849Z","hostname":"w-01J4HZ22M1CAY0GA8Y82EE8T1F","pid":1228,"client":"2","":"downstairs","session_id":"138bff53-b316-48bf-ae4d-884b7471b258"}
3902024-08-05T19:11:45.160Z{"msg":"downstairs client at Some(127.0.0.1:8830) has region UUID 12345678-0000-0000-0000-000000008830","v":0,"name":"crucible","level":30,"time":"2024-08-05T19:11:44.729964598Z","hostname":"w-01J4HZ22M1CAY0GA8Y82EE8T1F","pid":1228,"client":"2","":"downstairs","session_id":"138bff53-b316-48bf-ae4d-884b7471b258"}
3912024-08-05T19:11:45.160Z{"msg":"ds_transition from WaitActive to WaitQuorum","v":0,"name":"crucible","level":30,"time":"2024-08-05T19:11:44.730327194Z","hostname":"w-01J4HZ22M1CAY0GA8Y82EE8T1F","pid":1228,"client":"2","":"downstairs","session_id":"138bff53-b316-48bf-ae4d-884b7471b258"}
3922024-08-05T19:11:45.160Z{"msg":"[2] Transition from WaitActive to WaitQuorum","v":0,"name":"crucible","level":30,"time":"2024-08-05T19:11:44.730365507Z","hostname":"w-01J4HZ22M1CAY0GA8Y82EE8T1F","pid":1228,"client":"2","":"downstairs","session_id":"138bff53-b316-48bf-ae4d-884b7471b258"}
3932024-08-05T19:11:45.161Z{"msg":"[0]R flush_numbers: [1533, 1533, 1533, 1533, 1534]","v":0,"name":"crucible","level":30,"time":"2024-08-05T19:11:44.730382938Z","hostname":"w-01J4HZ22M1CAY0GA8Y82EE8T1F","pid":1228,"":"downstairs","":"downstairs","session_id":"138bff53-b316-48bf-ae4d-884b7471b258"}
3942024-08-05T19:11:45.161Z{"msg":"[0]R generation: [31, 31, 31, 31, 32]","v":0,"name":"crucible","level":30,"time":"2024-08-05T19:11:44.73040746Z","hostname":"w-01J4HZ22M1CAY0GA8Y82EE8T1F","pid":1228,"":"downstairs","":"downstairs","session_id":"138bff53-b316-48bf-ae4d-884b7471b258"}
3952024-08-05T19:11:45.161Z{"msg":"[0]R dirty: [true, true, true, true, false]","v":0,"name":"crucible","level":30,"time":"2024-08-05T19:11:44.730422181Z","hostname":"w-01J4HZ22M1CAY0GA8Y82EE8T1F","pid":1228,"":"downstairs","":"downstairs","session_id":"138bff53-b316-48bf-ae4d-884b7471b258"}
3962024-08-05T19:11:45.161Z{"msg":"[1]R flush_numbers: [1533, 1533, 1533, 1533, 1534]","v":0,"name":"crucible","level":30,"time":"2024-08-05T19:11:44.730443992Z","hostname":"w-01J4HZ22M1CAY0GA8Y82EE8T1F","pid":1228,"":"downstairs","":"downstairs","session_id":"138bff53-b316-48bf-ae4d-884b7471b258"}
3972024-08-05T19:11:45.161Z{"msg":"[1]R generation: [31, 31, 31, 31, 32]","v":0,"name":"crucible","level":30,"time":"2024-08-05T19:11:44.730459384Z","hostname":"w-01J4HZ22M1CAY0GA8Y82EE8T1F","pid":1228,"":"downstairs","":"downstairs","session_id":"138bff53-b316-48bf-ae4d-884b7471b258"}
3982024-08-05T19:11:45.161Z{"msg":"[1]R dirty: [true, true, true, true, false]","v":0,"name":"crucible","level":30,"time":"2024-08-05T19:11:44.730480825Z","hostname":"w-01J4HZ22M1CAY0GA8Y82EE8T1F","pid":1228,"":"downstairs","":"downstairs","session_id":"138bff53-b316-48bf-ae4d-884b7471b258"}
3992024-08-05T19:11:45.161Z{"msg":"[2]R flush_numbers: [1533, 1533, 1533, 1533, 1533]","v":0,"name":"crucible","level":30,"time":"2024-08-05T19:11:44.730495746Z","hostname":"w-01J4HZ22M1CAY0GA8Y82EE8T1F","pid":1228,"":"downstairs","":"downstairs","session_id":"138bff53-b316-48bf-ae4d-884b7471b258"}
4002024-08-05T19:11:45.161Z{"msg":"[2]R generation: [31, 31, 31, 31, 31]","v":0,"name":"crucible","level":30,"time":"2024-08-05T19:11:44.730517517Z","hostname":"w-01J4HZ22M1CAY0GA8Y82EE8T1F","pid":1228,"":"downstairs","":"downstairs","session_id":"138bff53-b316-48bf-ae4d-884b7471b258"}
4012024-08-05T19:11:45.161Z{"msg":"[2]R dirty: [false, false, false, false, false]","v":0,"name":"crucible","level":30,"time":"2024-08-05T19:11:44.730531809Z","hostname":"w-01J4HZ22M1CAY0GA8Y82EE8T1F","pid":1228,"":"downstairs","":"downstairs","session_id":"138bff53-b316-48bf-ae4d-884b7471b258"}
4022024-08-05T19:11:45.161Z{"msg":"Max found gen is 33","v":0,"name":"crucible","level":30,"time":"2024-08-05T19:11:44.73054511Z","hostname":"w-01J4HZ22M1CAY0GA8Y82EE8T1F","pid":1228,"":"downstairs","":"downstairs","session_id":"138bff53-b316-48bf-ae4d-884b7471b258"}
4032024-08-05T19:11:45.161Z{"msg":"Generation requested: 33 >= found:33","v":0,"name":"crucible","level":30,"time":"2024-08-05T19:11:44.730566641Z","hostname":"w-01J4HZ22M1CAY0GA8Y82EE8T1F","pid":1228,"":"downstairs","":"downstairs","session_id":"138bff53-b316-48bf-ae4d-884b7471b258"}
4042024-08-05T19:11:45.161Z{"msg":"Next flush: 1535","v":0,"name":"crucible","level":30,"time":"2024-08-05T19:11:44.730580932Z","hostname":"w-01J4HZ22M1CAY0GA8Y82EE8T1F","pid":1228,"":"downstairs","":"downstairs","session_id":"138bff53-b316-48bf-ae4d-884b7471b258"}
4052024-08-05T19:11:45.161Z{"msg":"Extents 0 dirty","v":0,"name":"crucible","level":30,"time":"2024-08-05T19:11:44.730601694Z","hostname":"w-01J4HZ22M1CAY0GA8Y82EE8T1F","pid":1228,"":"mend","":"downstairs","":"downstairs","session_id":"138bff53-b316-48bf-ae4d-884b7471b258"}
4062024-08-05T19:11:45.161Z{"msg":"First source client ID for extent 0","v":0,"name":"crucible","level":30,"time":"2024-08-05T19:11:44.730616584Z","hostname":"w-01J4HZ22M1CAY0GA8Y82EE8T1F","pid":1228,"mrl":"dirty","":"mend","":"downstairs","":"downstairs","session_id":"138bff53-b316-48bf-ae4d-884b7471b258"}
4072024-08-05T19:11:45.161Z{"msg":"extent:0 gens: 31 31 31","v":0,"name":"crucible","level":30,"time":"2024-08-05T19:11:44.730638556Z","hostname":"w-01J4HZ22M1CAY0GA8Y82EE8T1F","pid":1228,"mrl":"dirty","":"mend","":"downstairs","":"downstairs","session_id":"138bff53-b316-48bf-ae4d-884b7471b258"}
4082024-08-05T19:11:45.161Z{"msg":"extent:0 flush: 1533 1533 1533 scs: [ClientId(0), ClientId(1), ClientId(2)]","v":0,"name":"crucible","level":30,"time":"2024-08-05T19:11:44.730654457Z","hostname":"w-01J4HZ22M1CAY0GA8Y82EE8T1F","pid":1228,"mrl":"dirty","":"mend","":"downstairs","":"downstairs","session_id":"138bff53-b316-48bf-ae4d-884b7471b258"}
4092024-08-05T19:11:45.161Z{"msg":"max_flush now has: [ClientId(0), ClientId(1), ClientId(2)]","v":0,"name":"crucible","level":30,"time":"2024-08-05T19:11:44.730677129Z","hostname":"w-01J4HZ22M1CAY0GA8Y82EE8T1F","pid":1228,"mrl":"dirty","":"mend","":"downstairs","":"downstairs","session_id":"138bff53-b316-48bf-ae4d-884b7471b258"}
4102024-08-05T19:11:45.161Z{"msg":"extent:0 dirty: true true false","v":0,"name":"crucible","level":30,"time":"2024-08-05T19:11:44.73069244Z","hostname":"w-01J4HZ22M1CAY0GA8Y82EE8T1F","pid":1228,"mrl":"dirty","":"mend","":"downstairs","":"downstairs","session_id":"138bff53-b316-48bf-ae4d-884b7471b258"}
4112024-08-05T19:11:45.161Z{"msg":"find dest for source 0 for extent at index 0","v":0,"name":"crucible","level":30,"time":"2024-08-05T19:11:44.730707491Z","hostname":"w-01J4HZ22M1CAY0GA8Y82EE8T1F","pid":1228,"mrl":"dirty","":"mend","":"downstairs","":"downstairs","session_id":"138bff53-b316-48bf-ae4d-884b7471b258"}
4122024-08-05T19:11:45.161Z{"msg":"source 0, add dest 1 source flush","v":0,"name":"crucible","level":30,"time":"2024-08-05T19:11:44.730721902Z","hostname":"w-01J4HZ22M1CAY0GA8Y82EE8T1F","pid":1228,"mrl":"dirty","":"mend","":"downstairs","":"downstairs","session_id":"138bff53-b316-48bf-ae4d-884b7471b258"}
4132024-08-05T19:11:45.161Z{"msg":"source 0, add dest 2 source flush","v":0,"name":"crucible","level":30,"time":"2024-08-05T19:11:44.730738473Z","hostname":"w-01J4HZ22M1CAY0GA8Y82EE8T1F","pid":1228,"mrl":"dirty","":"mend","":"downstairs","":"downstairs","session_id":"138bff53-b316-48bf-ae4d-884b7471b258"}
4142024-08-05T19:11:45.161Z{"msg":"Extents 1 dirty","v":0,"name":"crucible","level":30,"time":"2024-08-05T19:11:44.730754164Z","hostname":"w-01J4HZ22M1CAY0GA8Y82EE8T1F","pid":1228,"":"mend","":"downstairs","":"downstairs","session_id":"138bff53-b316-48bf-ae4d-884b7471b258"}
4152024-08-05T19:11:45.161Z{"msg":"First source client ID for extent 1","v":0,"name":"crucible","level":30,"time":"2024-08-05T19:11:44.730776696Z","hostname":"w-01J4HZ22M1CAY0GA8Y82EE8T1F","pid":1228,"mrl":"dirty","":"mend","":"downstairs","":"downstairs","session_id":"138bff53-b316-48bf-ae4d-884b7471b258"}
4162024-08-05T19:11:45.161Z{"msg":"extent:1 gens: 31 31 31","v":0,"name":"crucible","level":30,"time":"2024-08-05T19:11:44.730791717Z","hostname":"w-01J4HZ22M1CAY0GA8Y82EE8T1F","pid":1228,"mrl":"dirty","":"mend","":"downstairs","":"downstairs","session_id":"138bff53-b316-48bf-ae4d-884b7471b258"}
4172024-08-05T19:11:45.161Z{"msg":"extent:1 flush: 1533 1533 1533 scs: [ClientId(0), ClientId(1), ClientId(2)]","v":0,"name":"crucible","level":30,"time":"2024-08-05T19:11:44.730814589Z","hostname":"w-01J4HZ22M1CAY0GA8Y82EE8T1F","pid":1228,"mrl":"dirty","":"mend","":"downstairs","":"downstairs","session_id":"138bff53-b316-48bf-ae4d-884b7471b258"}
4182024-08-05T19:11:45.161Z{"msg":"max_flush now has: [ClientId(0), ClientId(1), ClientId(2)]","v":0,"name":"crucible","level":30,"time":"2024-08-05T19:11:44.73082988Z","hostname":"w-01J4HZ22M1CAY0GA8Y82EE8T1F","pid":1228,"mrl":"dirty","":"mend","":"downstairs","":"downstairs","session_id":"138bff53-b316-48bf-ae4d-884b7471b258"}
4192024-08-05T19:11:45.161Z{"msg":"extent:1 dirty: true true false","v":0,"name":"crucible","level":30,"time":"2024-08-05T19:11:44.730852091Z","hostname":"w-01J4HZ22M1CAY0GA8Y82EE8T1F","pid":1228,"mrl":"dirty","":"mend","":"downstairs","":"downstairs","session_id":"138bff53-b316-48bf-ae4d-884b7471b258"}
4202024-08-05T19:11:45.161Z{"msg":"find dest for source 0 for extent at index 1","v":0,"name":"crucible","level":30,"time":"2024-08-05T19:11:44.730867512Z","hostname":"w-01J4HZ22M1CAY0GA8Y82EE8T1F","pid":1228,"mrl":"dirty","":"mend","":"downstairs","":"downstairs","session_id":"138bff53-b316-48bf-ae4d-884b7471b258"}
4212024-08-05T19:11:45.161Z{"msg":"source 0, add dest 1 source flush","v":0,"name":"crucible","level":30,"time":"2024-08-05T19:11:44.730889864Z","hostname":"w-01J4HZ22M1CAY0GA8Y82EE8T1F","pid":1228,"mrl":"dirty","":"mend","":"downstairs","":"downstairs","session_id":"138bff53-b316-48bf-ae4d-884b7471b258"}
4222024-08-05T19:11:45.161Z{"msg":"source 0, add dest 2 source flush","v":0,"name":"crucible","level":30,"time":"2024-08-05T19:11:44.730905015Z","hostname":"w-01J4HZ22M1CAY0GA8Y82EE8T1F","pid":1228,"mrl":"dirty","":"mend","":"downstairs","":"downstairs","session_id":"138bff53-b316-48bf-ae4d-884b7471b258"}
4232024-08-05T19:11:45.161Z{"msg":"Extents 2 dirty","v":0,"name":"crucible","level":30,"time":"2024-08-05T19:11:44.730927277Z","hostname":"w-01J4HZ22M1CAY0GA8Y82EE8T1F","pid":1228,"":"mend","":"downstairs","":"downstairs","session_id":"138bff53-b316-48bf-ae4d-884b7471b258"}
4242024-08-05T19:11:45.161Z{"msg":"First source client ID for extent 2","v":0,"name":"crucible","level":30,"time":"2024-08-05T19:11:44.730941787Z","hostname":"w-01J4HZ22M1CAY0GA8Y82EE8T1F","pid":1228,"mrl":"dirty","":"mend","":"downstairs","":"downstairs","session_id":"138bff53-b316-48bf-ae4d-884b7471b258"}
4252024-08-05T19:11:45.161Z{"msg":"extent:2 gens: 31 31 31","v":0,"name":"crucible","level":30,"time":"2024-08-05T19:11:44.730964239Z","hostname":"w-01J4HZ22M1CAY0GA8Y82EE8T1F","pid":1228,"mrl":"dirty","":"mend","":"downstairs","":"downstairs","session_id":"138bff53-b316-48bf-ae4d-884b7471b258"}
4262024-08-05T19:11:45.161Z{"msg":"extent:2 flush: 1533 1533 1533 scs: [ClientId(0), ClientId(1), ClientId(2)]","v":0,"name":"crucible","level":30,"time":"2024-08-05T19:11:44.73097972Z","hostname":"w-01J4HZ22M1CAY0GA8Y82EE8T1F","pid":1228,"mrl":"dirty","":"mend","":"downstairs","":"downstairs","session_id":"138bff53-b316-48bf-ae4d-884b7471b258"}
4272024-08-05T19:11:45.161Z{"msg":"max_flush now has: [ClientId(0), ClientId(1), ClientId(2)]","v":0,"name":"crucible","level":30,"time":"2024-08-05T19:11:44.731002172Z","hostname":"w-01J4HZ22M1CAY0GA8Y82EE8T1F","pid":1228,"mrl":"dirty","":"mend","":"downstairs","":"downstairs","session_id":"138bff53-b316-48bf-ae4d-884b7471b258"}
4282024-08-05T19:11:45.161Z{"msg":"extent:2 dirty: true true false","v":0,"name":"crucible","level":30,"time":"2024-08-05T19:11:44.731016703Z","hostname":"w-01J4HZ22M1CAY0GA8Y82EE8T1F","pid":1228,"mrl":"dirty","":"mend","":"downstairs","":"downstairs","session_id":"138bff53-b316-48bf-ae4d-884b7471b258"}
4292024-08-05T19:11:45.161Z{"msg":"find dest for source 0 for extent at index 2","v":0,"name":"crucible","level":30,"time":"2024-08-05T19:11:44.731039254Z","hostname":"w-01J4HZ22M1CAY0GA8Y82EE8T1F","pid":1228,"mrl":"dirty","":"mend","":"downstairs","":"downstairs","session_id":"138bff53-b316-48bf-ae4d-884b7471b258"}
4302024-08-05T19:11:45.161Z{"msg":"source 0, add dest 1 source flush","v":0,"name":"crucible","level":30,"time":"2024-08-05T19:11:44.731054555Z","hostname":"w-01J4HZ22M1CAY0GA8Y82EE8T1F","pid":1228,"mrl":"dirty","":"mend","":"downstairs","":"downstairs","session_id":"138bff53-b316-48bf-ae4d-884b7471b258"}
4312024-08-05T19:11:45.161Z{"msg":"source 0, add dest 2 source flush","v":0,"name":"crucible","level":30,"time":"2024-08-05T19:11:44.731068607Z","hostname":"w-01J4HZ22M1CAY0GA8Y82EE8T1F","pid":1228,"mrl":"dirty","":"mend","":"downstairs","":"downstairs","session_id":"138bff53-b316-48bf-ae4d-884b7471b258"}
4322024-08-05T19:11:45.162Z{"msg":"Extents 3 dirty","v":0,"name":"crucible","level":30,"time":"2024-08-05T19:11:44.731090788Z","hostname":"w-01J4HZ22M1CAY0GA8Y82EE8T1F","pid":1228,"":"mend","":"downstairs","":"downstairs","session_id":"138bff53-b316-48bf-ae4d-884b7471b258"}
4332024-08-05T19:11:45.162Z{"msg":"First source client ID for extent 3","v":0,"name":"crucible","level":30,"time":"2024-08-05T19:11:44.731105779Z","hostname":"w-01J4HZ22M1CAY0GA8Y82EE8T1F","pid":1228,"mrl":"dirty","":"mend","":"downstairs","":"downstairs","session_id":"138bff53-b316-48bf-ae4d-884b7471b258"}
4342024-08-05T19:11:45.162Z{"msg":"extent:3 gens: 31 31 31","v":0,"name":"crucible","level":30,"time":"2024-08-05T19:11:44.731127921Z","hostname":"w-01J4HZ22M1CAY0GA8Y82EE8T1F","pid":1228,"mrl":"dirty","":"mend","":"downstairs","":"downstairs","session_id":"138bff53-b316-48bf-ae4d-884b7471b258"}
4352024-08-05T19:11:45.162Z{"msg":"extent:3 flush: 1533 1533 1533 scs: [ClientId(0), ClientId(1), ClientId(2)]","v":0,"name":"crucible","level":30,"time":"2024-08-05T19:11:44.731143872Z","hostname":"w-01J4HZ22M1CAY0GA8Y82EE8T1F","pid":1228,"mrl":"dirty","":"mend","":"downstairs","":"downstairs","session_id":"138bff53-b316-48bf-ae4d-884b7471b258"}
4362024-08-05T19:11:45.162Z{"msg":"max_flush now has: [ClientId(0), ClientId(1), ClientId(2)]","v":0,"name":"crucible","level":30,"time":"2024-08-05T19:11:44.731166443Z","hostname":"w-01J4HZ22M1CAY0GA8Y82EE8T1F","pid":1228,"mrl":"dirty","":"mend","":"downstairs","":"downstairs","session_id":"138bff53-b316-48bf-ae4d-884b7471b258"}
4372024-08-05T19:11:45.162Z{"msg":"extent:3 dirty: true true false","v":0,"name":"crucible","level":30,"time":"2024-08-05T19:11:44.731182535Z","hostname":"w-01J4HZ22M1CAY0GA8Y82EE8T1F","pid":1228,"mrl":"dirty","":"mend","":"downstairs","":"downstairs","session_id":"138bff53-b316-48bf-ae4d-884b7471b258"}
4382024-08-05T19:11:45.165Z{"msg":"find dest for source 0 for extent at index 3","v":0,"name":"crucible","level":30,"time":"2024-08-05T19:11:44.731196996Z","hostname":"w-01J4HZ22M1CAY0GA8Y82EE8T1F","pid":1228,"mrl":"dirty","":"mend","":"downstairs","":"downstairs","session_id":"138bff53-b316-48bf-ae4d-884b7471b258"}
4392024-08-05T19:11:45.165Z{"msg":"source 0, add dest 1 source flush","v":0,"name":"crucible","level":30,"time":"2024-08-05T19:11:44.731219077Z","hostname":"w-01J4HZ22M1CAY0GA8Y82EE8T1F","pid":1228,"mrl":"dirty","":"mend","":"downstairs","":"downstairs","session_id":"138bff53-b316-48bf-ae4d-884b7471b258"}
4402024-08-05T19:11:45.165Z{"msg":"source 0, add dest 2 source flush","v":0,"name":"crucible","level":30,"time":"2024-08-05T19:11:44.731234608Z","hostname":"w-01J4HZ22M1CAY0GA8Y82EE8T1F","pid":1228,"mrl":"dirty","":"mend","":"downstairs","":"downstairs","session_id":"138bff53-b316-48bf-ae4d-884b7471b258"}
4412024-08-05T19:11:45.165Z{"msg":"Extent 4 has flush number mismatch","v":0,"name":"crucible","level":30,"time":"2024-08-05T19:11:44.73125677Z","hostname":"w-01J4HZ22M1CAY0GA8Y82EE8T1F","pid":1228,"":"mend","":"downstairs","":"downstairs","session_id":"138bff53-b316-48bf-ae4d-884b7471b258"}
4422024-08-05T19:11:45.165Z{"msg":"First source client ID for extent 4","v":0,"name":"crucible","level":30,"time":"2024-08-05T19:11:44.731271671Z","hostname":"w-01J4HZ22M1CAY0GA8Y82EE8T1F","pid":1228,"mrl":"flush_mismatch","":"mend","":"downstairs","":"downstairs","session_id":"138bff53-b316-48bf-ae4d-884b7471b258"}
4432024-08-05T19:11:45.165Z{"msg":"extent:4 gens: 32 32 31","v":0,"name":"crucible","level":30,"time":"2024-08-05T19:11:44.731294103Z","hostname":"w-01J4HZ22M1CAY0GA8Y82EE8T1F","pid":1228,"mrl":"flush_mismatch","":"mend","":"downstairs","":"downstairs","session_id":"138bff53-b316-48bf-ae4d-884b7471b258"}
4442024-08-05T19:11:45.165Z{"msg":"extent:4 flush: 1534 1534 1533 scs: [ClientId(0), ClientId(1)]","v":0,"name":"crucible","level":30,"time":"2024-08-05T19:11:44.731309433Z","hostname":"w-01J4HZ22M1CAY0GA8Y82EE8T1F","pid":1228,"mrl":"flush_mismatch","":"mend","":"downstairs","":"downstairs","session_id":"138bff53-b316-48bf-ae4d-884b7471b258"}
4452024-08-05T19:11:45.165Z{"msg":"max_flush now has: [ClientId(0), ClientId(1)]","v":0,"name":"crucible","level":30,"time":"2024-08-05T19:11:44.731332025Z","hostname":"w-01J4HZ22M1CAY0GA8Y82EE8T1F","pid":1228,"mrl":"flush_mismatch","":"mend","":"downstairs","":"downstairs","session_id":"138bff53-b316-48bf-ae4d-884b7471b258"}
4462024-08-05T19:11:45.165Z{"msg":"extent:4 dirty: false false false","v":0,"name":"crucible","level":30,"time":"2024-08-05T19:11:44.731347556Z","hostname":"w-01J4HZ22M1CAY0GA8Y82EE8T1F","pid":1228,"mrl":"flush_mismatch","":"mend","":"downstairs","":"downstairs","session_id":"138bff53-b316-48bf-ae4d-884b7471b258"}
4472024-08-05T19:11:45.165Z{"msg":"No maxes found, left with: [ClientId(0), ClientId(1)]","v":0,"name":"crucible","level":30,"time":"2024-08-05T19:11:44.731370348Z","hostname":"w-01J4HZ22M1CAY0GA8Y82EE8T1F","pid":1228,"mrl":"flush_mismatch","":"mend","":"downstairs","":"downstairs","session_id":"138bff53-b316-48bf-ae4d-884b7471b258"}
4482024-08-05T19:11:45.165Z{"msg":"find dest for source 0 for extent at index 4","v":0,"name":"crucible","level":30,"time":"2024-08-05T19:11:44.731386019Z","hostname":"w-01J4HZ22M1CAY0GA8Y82EE8T1F","pid":1228,"mrl":"flush_mismatch","":"mend","":"downstairs","":"downstairs","session_id":"138bff53-b316-48bf-ae4d-884b7471b258"}
4492024-08-05T19:11:45.165Z{"msg":"source 0, add dest 2 gen","v":0,"name":"crucible","level":30,"time":"2024-08-05T19:11:44.731409061Z","hostname":"w-01J4HZ22M1CAY0GA8Y82EE8T1F","pid":1228,"mrl":"flush_mismatch","":"mend","":"downstairs","":"downstairs","session_id":"138bff53-b316-48bf-ae4d-884b7471b258"}
4502024-08-05T19:11:45.165Z{"msg":"Transition from WaitQuorum to Reconcile","v":0,"name":"crucible","level":30,"time":"2024-08-05T19:11:44.731424862Z","hostname":"w-01J4HZ22M1CAY0GA8Y82EE8T1F","pid":1228,"client":"0","":"downstairs","session_id":"138bff53-b316-48bf-ae4d-884b7471b258"}
4512024-08-05T19:11:45.165Z{"msg":"Transition from WaitQuorum to Reconcile","v":0,"name":"crucible","level":30,"time":"2024-08-05T19:11:44.731445753Z","hostname":"w-01J4HZ22M1CAY0GA8Y82EE8T1F","pid":1228,"client":"1","":"downstairs","session_id":"138bff53-b316-48bf-ae4d-884b7471b258"}
4522024-08-05T19:11:45.165Z{"msg":"Transition from WaitQuorum to Reconcile","v":0,"name":"crucible","level":30,"time":"2024-08-05T19:11:44.731459434Z","hostname":"w-01J4HZ22M1CAY0GA8Y82EE8T1F","pid":1228,"client":"2","":"downstairs","session_id":"138bff53-b316-48bf-ae4d-884b7471b258"}
4532024-08-05T19:11:45.165Z{"msg":"starting reconciliation c604c499-4bad-45b7-b906-3c1e3c11128a: found 5 extents that need repair","v":0,"name":"crucible","level":30,"time":"2024-08-05T19:11:44.731481676Z","hostname":"w-01J4HZ22M1CAY0GA8Y82EE8T1F","pid":1228,"":"downstairs","":"downstairs","session_id":"138bff53-b316-48bf-ae4d-884b7471b258"}
4542024-08-05T19:11:45.165Z{"msg":"Full repair list: {ExtentId(0): ExtentFix { source: ClientId(0), dest: [ClientId(1), ClientId(2)] }, ExtentId(2): ExtentFix { source: ClientId(0), dest: [ClientId(1), ClientId(2)] }, ExtentId(3): ExtentFix { source: ClientId(0), dest: [ClientId(1), ClientId(2)] }, ExtentId(1): ExtentFix { source: ClientId(0), dest: [ClientId(1), ClientId(2)] }, ExtentId(4): ExtentFix { source: ClientId(0), dest: [ClientId(2)] }}","v":0,"name":"crucible","level":30,"time":"2024-08-05T19:11:44.731501917Z","hostname":"w-01J4HZ22M1CAY0GA8Y82EE8T1F","pid":1228,"":"downstairs","":"downstairs","session_id":"138bff53-b316-48bf-ae4d-884b7471b258"}
4552024-08-05T19:11:45.165Z{"msg":"Task list: [ReconcileIO { id: ReconciliationId(0), op: ExtentFlush { repair_id: ReconciliationId(0), extent_id: ExtentId(0), client_id: ClientId(0), flush_number: 1535, gen_number: 33 }, state: ClientData([New, New, New]) }, ReconcileIO { id: ReconciliationId(1), op: ExtentClose { repair_id: ReconciliationId(1), extent_id: ExtentId(0) }, state: ClientData([New, New, New]) }, ReconcileIO { id: ReconciliationId(2), op: ExtentRepair { repair_id: ReconciliationId(2), extent_id: ExtentId(0), source_client_id: ClientId(0), source_repair_address: 0.0.0.0:12810, dest_clients: [ClientId(1), ClientId(2)] }, state: ClientData([New, New, New]) }, ReconcileIO { id: ReconciliationId(3), op: ExtentReopen { repair_id: ReconciliationId(3), extent_id: ExtentId(0) }, state: ClientData([New, New, New]) }, ReconcileIO { id: ReconciliationId(4), op: ExtentFlush { repair_id: ReconciliationId(4), extent_id: ExtentId(2), client_id: ClientId(0), flush_number: 1535, gen_number: 33 }, state: ClientData([New, New, New]) }, ReconcileIO { id: ReconciliationId(5), op: ExtentClose { repair_id: ReconciliationId(5), extent_id: ExtentId(2) }, state: ClientData([New, New, New]) }, ReconcileIO { id: ReconciliationId(6), op: ExtentRepair { repair_id: ReconciliationId(6), extent_id: ExtentId(2), source_client_id: ClientId(0), source_repair_address: 0.0.0.0:12810, dest_clients: [ClientId(1), ClientId(2)] }, state: ClientData([New, New, New]) }, ReconcileIO { id: ReconciliationId(7), op: ExtentReopen { repair_id: ReconciliationId(7), extent_id: ExtentId(2) }, state: ClientData([New, New, New]) }, ReconcileIO { id: ReconciliationId(8), op: ExtentFlush { repair_id: ReconciliationId(8), extent_id: ExtentId(3), client_id: ClientId(0), flush_number: 1535, gen_number: 33 }, state: ClientData([New, New, New]) }, ReconcileIO { id: ReconciliationId(9), op: ExtentClose { repair_id: ReconciliationId(9), extent_id: ExtentId(3) }, state: ClientData([New, New, New]) }, ReconcileIO { id: ReconciliationId(10), op: ExtentRepair { repair_id: ReconciliationId(10), extent_id: ExtentId(3), source_client_id: ClientId(0), source_repair_address: 0.0.0.0:12810, dest_clients: [ClientId(1), ClientId(2)] }, state: ClientData([New, New, New]) }, ReconcileIO { id: ReconciliationId(11), op: ExtentReopen { repair_id: ReconciliationId(11), extent_id: ExtentId(3) }, state: ClientData([New, New, New]) }, ReconcileIO { id: ReconciliationId(12), op: ExtentFlush { repair_id: ReconciliationId(12), extent_id: ExtentId(1), client_id: ClientId(0), flush_number: 1535, gen_number: 33 }, state: ClientData([New, New, New]) }, ReconcileIO { id: ReconciliationId(13), op: ExtentClose { repair_id: ReconciliationId(13), extent_id: ExtentId(1) }, state: ClientData([New, New, New]) }, ReconcileIO { id: ReconciliationId(14), op: ExtentRepair { repair_id: ReconciliationId(14), extent_id: ExtentId(1), source_client_id: ClientId(0), source_repair_address: 0.0.0.0:12810, dest_clients: [ClientId(1), ClientId(2)] }, state: ClientData([New, New, New]) }, ReconcileIO { id: ReconciliationId(15), op: ExtentReopen { repair_id: ReconciliationId(15), extent_id: ExtentId(1) }, state: ClientData([New, New, New]) }, ReconcileIO { id: ReconciliationId(16), op: ExtentFlush { repair_id: ReconciliationId(16), extent_id: ExtentId(4), client_id: ClientId(0), flush_number: 1535, 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":"2024-08-05T19:11:44.731601954Z","hostname":"w-01J4HZ22M1CAY0GA8Y82EE8T1F","pid":1228,"":"downstairs","":"downstairs","session_id":"138bff53-b316-48bf-ae4d-884b7471b258"}
4562024-08-05T19:11:45.165Z{"msg":"sending reconcile request ReconciliationId(2)","v":0,"name":"crucible","level":30,"time":"2024-08-05T19:11:44.732275072Z","hostname":"w-01J4HZ22M1CAY0GA8Y82EE8T1F","pid":1228,"client":"1","":"downstairs","session_id":"138bff53-b316-48bf-ae4d-884b7471b258"}
4572024-08-05T19:11:45.165Z{"msg":"sending reconcile request ReconciliationId(2)","v":0,"name":"crucible","level":30,"time":"2024-08-05T19:11:44.732315445Z","hostname":"w-01J4HZ22M1CAY0GA8Y82EE8T1F","pid":1228,"client":"2","":"downstairs","session_id":"138bff53-b316-48bf-ae4d-884b7471b258"}
4582024-08-05T19:11:45.175Z{"msg":"sending reconcile request ReconciliationId(6)","v":0,"name":"crucible","level":30,"time":"2024-08-05T19:11:44.747462016Z","hostname":"w-01J4HZ22M1CAY0GA8Y82EE8T1F","pid":1228,"client":"1","":"downstairs","session_id":"138bff53-b316-48bf-ae4d-884b7471b258"}
4592024-08-05T19:11:45.175Z{"msg":"sending reconcile request ReconciliationId(6)","v":0,"name":"crucible","level":30,"time":"2024-08-05T19:11:44.74751723Z","hostname":"w-01J4HZ22M1CAY0GA8Y82EE8T1F","pid":1228,"client":"2","":"downstairs","session_id":"138bff53-b316-48bf-ae4d-884b7471b258"}
4602024-08-05T19:11:45.185Z{"msg":"sending reconcile request ReconciliationId(10)","v":0,"name":"crucible","level":30,"time":"2024-08-05T19:11:44.757751493Z","hostname":"w-01J4HZ22M1CAY0GA8Y82EE8T1F","pid":1228,"client":"1","":"downstairs","session_id":"138bff53-b316-48bf-ae4d-884b7471b258"}
4612024-08-05T19:11:45.188Z{"msg":"sending reconcile request ReconciliationId(10)","v":0,"name":"crucible","level":30,"time":"2024-08-05T19:11:44.757864201Z","hostname":"w-01J4HZ22M1CAY0GA8Y82EE8T1F","pid":1228,"client":"2","":"downstairs","session_id":"138bff53-b316-48bf-ae4d-884b7471b258"}
4622024-08-05T19:11:45.197Z{"msg":"sending reconcile request ReconciliationId(14)","v":0,"name":"crucible","level":30,"time":"2024-08-05T19:11:44.768795654Z","hostname":"w-01J4HZ22M1CAY0GA8Y82EE8T1F","pid":1228,"client":"1","":"downstairs","session_id":"138bff53-b316-48bf-ae4d-884b7471b258"}
4632024-08-05T19:11:45.197Z{"msg":"sending reconcile request ReconciliationId(14)","v":0,"name":"crucible","level":30,"time":"2024-08-05T19:11:44.768844468Z","hostname":"w-01J4HZ22M1CAY0GA8Y82EE8T1F","pid":1228,"client":"2","":"downstairs","session_id":"138bff53-b316-48bf-ae4d-884b7471b258"}
4642024-08-05T19:11:45.205Z{"msg":"sending reconcile request ReconciliationId(18)","v":0,"name":"crucible","level":30,"time":"2024-08-05T19:11:44.777410963Z","hostname":"w-01J4HZ22M1CAY0GA8Y82EE8T1F","pid":1228,"client":"2","":"downstairs","session_id":"138bff53-b316-48bf-ae4d-884b7471b258"}
4652024-08-05T19:11:45.212Z{"msg":"done with reconciliation","v":0,"name":"crucible","level":30,"time":"2024-08-05T19:11:44.78459044Z","hostname":"w-01J4HZ22M1CAY0GA8Y82EE8T1F","pid":1228,"":"downstairs","":"downstairs","session_id":"138bff53-b316-48bf-ae4d-884b7471b258"}
4662024-08-05T19:11:45.212Z{"msg":"Transition from Reconcile to Active","v":0,"name":"crucible","level":30,"time":"2024-08-05T19:11:44.784629153Z","hostname":"w-01J4HZ22M1CAY0GA8Y82EE8T1F","pid":1228,"client":"0","":"downstairs","session_id":"138bff53-b316-48bf-ae4d-884b7471b258"}
4672024-08-05T19:11:45.212Z{"msg":"Transition from Reconcile to Active","v":0,"name":"crucible","level":30Wait for a query_work_queue command to finish before sending IO
4682024-08-05T19:11:45.212Z,"time":"2024-08-05T19:11:44.784645864Z","hostname":"w-01J4HZ22M1CAY0GA8Y82EE8T1F","pid":1228,"client":"1","":"downstairs","session_id":"138bff53-b316-48bf-ae4d-884b7471b258"}
4692024-08-05T19:11:45.215Z{"msg":"Transition from Reconcile to Active","v":0,"name":"crucible","level":30,"time":"2024-08-05T19:11:44.784671346Z","hostname":"w-01J4HZ22M1CAY0GA8Y82EE8T1F","pid":1228,"client":"2","":"downstairs","session_id":"138bff53-b316-48bf-ae4d-884b7471b258"}
4702024-08-05T19:11:45.215Z{"msg":"All required reconciliation work is completed","v":0,"name":"crucible","level":30,"time":"2024-08-05T19:11:44.784697818Z","hostname":"w-01J4HZ22M1CAY0GA8Y82EE8T1F","pid":1228,"session_id":"138bff53-b316-48bf-ae4d-884b7471b258"}
4712024-08-05T19:11:45.215Z{"msg":"Set Downstairs and Upstairs active after reconciliation","v":0,"name":"crucible","level":30,"time":"2024-08-05T19:11:44.784720389Z","hostname":"w-01J4HZ22M1CAY0GA8Y82EE8T1F","pid":1228,"session_id":"138bff53-b316-48bf-ae4d-884b7471b258"}
4722024-08-05T19:11:45.215Z{"msg":"985ce384-f588-48a7-898e-f83df481492d is now active with session: 138bff53-b316-48bf-ae4d-884b7471b258","v":0,"name":"crucible","level":30,"time":"2024-08-05T19:11:44.784749211Z","hostname":"w-01J4HZ22M1CAY0GA8Y82EE8T1F","pid":1228,"session_id":"138bff53-b316-48bf-ae4d-884b7471b258"}
4732024-08-05T19:11:45.215Z{"msg":"The guest has finished waiting for activation with:33","v":0,"name":"crucible","level":30,"time":"2024-08-05T19:11:44.784798635Z","hostname":"w-01J4HZ22M1CAY0GA8Y82EE8T1F","pid":1228}
4742024-08-05T19:11:45.215ZRegion: es:10 ec:5 bs:4096 ts:204800 tb:50 max_io:50 or 204800
4752024-08-05T19:11:45.215ZLoading write count information from file "/var/tmp/test_up/verify_file"
4762024-08-05T19:11:45.216ZRead and Verify all blocks (0..50 range:true)
4772024-08-05T19:11:45.219ZWrote out file "/var/tmp/test_up/verify_file"
4782024-08-05T19:11:45.219ZVerify test completed
4792024-08-05T19:11:45.222ZWrote out file "/var/tmp/test_up/verify_file"
4802024-08-05T19:11:45.222ZCLIENT: Tests done. All submitted work has been ACK'd
4812024-08-05T19:11:45.222Z----------------------------------------------------------------
4822024-08-05T19:11:45.222Z Crucible gen:33 GIO:true work queues: Upstairs:0 downstairs:1
4832024-08-05T19:11:45.222ZStates: Active Active Active
4842024-08-05T19:11:45.222ZGW_ID ACK DSID TYPE BKS/EXT DS:0 DS:1 DS:2 REPLAY
4852024-08-05T19:11:45.222Z 1 Acked 1000 Read 50 Done Done Done false
4862024-08-05T19:11:45.222Z STATES DS:0 DS:1 DS:2 TOTAL
4872024-08-05T19:11:45.222Z New 0 0 0 0
4882024-08-05T19:11:45.222Z Sent 0 0 0 0
4892024-08-05T19:11:45.222Z Done 1 1 1 3
4902024-08-05T19:11:45.222Z Skipped 0 0 0 0
4912024-08-05T19:11:45.222Z Error 0 0 0 0
4922024-08-05T19:11:45.222ZLast Flush: 0 0 0
4932024-08-05T19:11:45.222ZDownstairs last five completed:
4942024-08-05T19:11:45.222ZUpstairs last five completed: 1
4952024-08-05T19:11:45.222ZCLIENT: Up:0 ds:1 act:3
4962024-08-05T19:11:49.221Z----------------------------------------------------------------
4972024-08-05T19:11:49.221Z Crucible gen:33 GIO:true work queues: Upstairs:0 downstairs:0
4982024-08-05T19:11:49.221ZDownstairs last five completed: 1001 1000
4992024-08-05T19:11:49.221ZUpstairs last five completed: 2 1
5002024-08-05T19:11:49.221ZCLIENT: Up:0 ds:0 act:3
5012024-08-05T19:11:49.221ZCLIENT: All crucible jobs finished, exiting program
5022024-08-05T19:11:49.224Z{"msg":"Guest handle has been dropped","v":0,"name":"crucible","level":40,"time":"2024-08-05T19:11:48.793910561Z","hostname":"w-01J4HZ22M1CAY0GA8Y82EE8T1F","pid":1228}
5032024-08-05T19:11:49.227ZRepair part 2 passed
5042024-08-05T19:11:49.227Z/var/tmp/bins/crucible-downstairs dump --no-color -d /var/tmp/test_up/8810 -d /var/tmp/test_up/8820 -d /var/tmp/test_up/8830
5052024-08-05T19:11:49.243ZEXT BLOCKS GEN0 GEN1 GEN2 FL0 FL1 FL2 D0 D1 D2 DIFF
5062024-08-05T19:11:49.246Z 0 000-009 33 33 33 1535 1535 1535 F F F
5072024-08-05T19:11:49.246Z 1 010-019 33 33 33 1535 1535 1535 F F F
5082024-08-05T19:11:49.246Z 2 020-029 33 33 33 1535 1535 1535 F F F
5092024-08-05T19:11:49.246Z 3 030-039 33 33 33 1535 1535 1535 F F F
5102024-08-05T19:11:49.246Z 4 040-049 32 32 32 1534 1534 1534 F F F
5112024-08-05T19:11:49.246ZMax gen: 33, Max flush: 1535
5122024-08-05T19:11:49.249Zdump test passed
5132024-08-05T19:11:49.249Z/var/tmp/bins/crucible-downstairs dump --no-color -d /var/tmp/test_up/8810 -d /var/tmp/test_up/8820 -d /var/tmp/test_up/8830 -e 1
5142024-08-05T19:11:49.262Z Extent 1
5152024-08-05T19:11:49.265ZGEN 33 33 33
5162024-08-05T19:11:49.265ZFLUSH_ID 1535 1535 1535
5172024-08-05T19:11:49.265ZDIRTY
5182024-08-05T19:11:49.265Z
5192024-08-05T19:11:49.265ZBLOCK D0 D1 D2 C0 C1 C2 DIFF
5202024-08-05T19:11:49.265Z010 A A A A A A
5212024-08-05T19:11:49.268Z011 A A A A A A
5222024-08-05T19:11:49.268Z012 A A A A A A
5232024-08-05T19:11:49.268Z013 A A A A A A
5242024-08-05T19:11:49.271Z014 A A A A A A
5252024-08-05T19:11:49.273Z015 A A A A A A
5262024-08-05T19:11:49.273Z016 A A A A A A
5272024-08-05T19:11:49.277Z017 A A A A A A
5282024-08-05T19:11:49.277Z018 A A A A A A
5292024-08-05T19:11:49.277Z019 A A A A A A
5302024-08-05T19:11:49.280Zdump extent test passed
5312024-08-05T19:11:49.280Z/var/tmp/bins/crucible-downstairs dump --no-color -d /var/tmp/test_up/8810 -d /var/tmp/test_up/8820 -d /var/tmp/test_up/8830 -b 20
5322024-08-05T19:11:49.295ZExtent 2 Block in extent 0 Actual block 20
5332024-08-05T19:11:49.295Z
5342024-08-05T19:11:49.297Z DATA SHA256 VER
5352024-08-05T19:11:49.297Z------ ---------------------------------------------------------------- ---
5362024-08-05T19:11:49.297Z 0 7c06d6ec4d4a970d4585f526f5400d8405c63d6f6b1424682e1fab6d3a776079 A
5372024-08-05T19:11:49.297Z 1 7c06d6ec4d4a970d4585f526f5400d8405c63d6f6b1424682e1fab6d3a776079 A
5382024-08-05T19:11:49.300Z 2 7c06d6ec4d4a970d4585f526f5400d8405c63d6f6b1424682e1fab6d3a776079 A
5392024-08-05T19:11:49.300Z
5402024-08-05T19:11:49.300ZNONCES 0 1 2 DIFF
5412024-08-05T19:11:49.300Z------ ------------------------ ------------------------ ------------------------ -----
5422024-08-05T19:11:49.300Z
5432024-08-05T19:11:49.300Z TAGS 0 1 2 DIFF
5442024-08-05T19:11:49.300Z------ -------------------------------- -------------------------------- -------------------------------- -----
5452024-08-05T19:11:49.300Z
5462024-08-05T19:11:49.300ZHASHES 0 1 2 DIFF
5472024-08-05T19:11:49.300Z------ ---------------- ---------------- ---------------- -----
5482024-08-05T19:11:49.300Z 0 a0d586716ee487f5 a0d586716ee487f5 a0d586716ee487f5
5492024-08-05T19:11:49.300Z
5502024-08-05T19:11:49.303Zdump block test passed
5512024-08-05T19:11:49.303ZUpstairs tests have completed, stopping all downstairs
5522024-08-05T19:11:54.363ZCreating four larger downstairs regions
5532024-08-05T19:11:54.800ZStarting four downstairs
5542024-08-05T19:11:59.807ZNow do the replace-reconcile test
5552024-08-05T19:14:37.520ZCompleted test: replace-reconcile
5562024-08-05T19:14:37.522ZNow do the replace-before-active test
5572024-08-05T19:17:19.294ZCompleted test: replace-before-active
5582024-08-05T19:17:19.294ZTests have completed, stopping all downstairs
5592024-08-05T19:17:19.354Z
5602024-08-05T19:17:19.354ZAll Tests have passed
5612024-08-05T19:17:19.357Z7:50 Test duration
5622024-08-05T19:17:19.357Z
5632024-08-05T19:17:19.357Zreal 7:50.577977639
5642024-08-05T19:17:19.357Zuser 1:12.135384333
5652024-08-05T19:17:19.357Zsys 13.906941710
5662024-08-05T19:17:19.357Ztrap 0.236025472
5672024-08-05T19:17:19.357Ztflt 0.016070854
5682024-08-05T19:17:19.357Zdflt 0.014302961
5692024-08-05T19:17:19.357Zkflt 0.001237727
5702024-08-05T19:17:19.357Zlock 5:42:41.247389308
5712024-08-05T19:17:19.357Zslp 24:47.809994039
5722024-08-05T19:17:19.357Zlat 15.012085619
5732024-08-05T19:17:19.357Zstop 0.132990353
5742024-08-05T19:17:19.357Z+ echo 'test-up-unencrypted ends'
5752024-08-05T19:17:19.357Ztest-up-unencrypted ends
5762024-08-05T19:17:24.359Zprocess exited: duration 478248 ms, exit code 0
5772024-08-05T19:17:24.359Zexec warning: : stdio descriptors remain open after task exit; waiting 60 seconds for them to close
5782024-08-05T19:18:24.393Zexec warning: : stdout descriptor may be held open by a background process; giving up!
5792024-08-05T19:18:24.393Zexec warning: : stderr descriptor may be held open by a background process; giving up!
 
5802024-08-05T19:18:24.406Zfound 14 output files
5812024-08-05T19:18:24.406Zuploading: /tmp/test_up/dsc-out.txt (21914 bytes)
5822024-08-05T19:18:25.419Zuploaded: /tmp/test_up/dsc-out.txt
5832024-08-05T19:18:25.428Zuploading: /tmp/test_up/test_up_out.txt (9547338 bytes)
5842024-08-05T19:18:26.558Zuploaded: /tmp/test_up/test_up_out.txt
5852024-08-05T19:18:26.558Zuploading: /tmp/test_up/dsc/downstairs-8810.txt (2476 bytes)
5862024-08-05T19:18:27.566Zuploaded: /tmp/test_up/dsc/downstairs-8810.txt
5872024-08-05T19:18:27.567Zuploading: /tmp/test_up/dsc/downstairs-8820.txt (140412 bytes)
5882024-08-05T19:18:28.581Zuploaded: /tmp/test_up/dsc/downstairs-8820.txt
5892024-08-05T19:18:28.581Zuploading: /tmp/test_up/dsc/downstairs-8830.txt (246847 bytes)
5902024-08-05T19:18:29.597Zuploaded: /tmp/test_up/dsc/downstairs-8830.txt
5912024-08-05T19:18:29.601Zuploading: /tmp/test_up/dsc/downstairs-8840.txt (135195 bytes)
5922024-08-05T19:18:30.612Zuploaded: /tmp/test_up/dsc/downstairs-8840.txt
5932024-08-05T19:18:30.612Zuploading: /tmp/debug/df.txt (1270 bytes)
5942024-08-05T19:18:31.621Zuploaded: /tmp/debug/df.txt
5952024-08-05T19:18:31.621Zuploading: /tmp/debug/dtrace.txt (408056 bytes)
5962024-08-05T19:18:31.635Zupload warning: file "/tmp/debug/dtrace.txt" changed size mid upload: 408056 -> 492668
5972024-08-05T19:18:32.642Zuploaded: /tmp/debug/dtrace.txt
5982024-08-05T19:18:32.642Zuploading: /tmp/debug/iostat.txt (160349 bytes)
5992024-08-05T19:18:32.650Zupload warning: file "/tmp/debug/iostat.txt" changed size mid upload: 160349 -> 162741
6002024-08-05T19:18:33.657Zuploaded: /tmp/debug/iostat.txt
6012024-08-05T19:18:33.657Zuploading: /tmp/debug/mpstat.txt (390208 bytes)
6022024-08-05T19:18:33.671Zupload warning: file "/tmp/debug/mpstat.txt" changed size mid upload: 390208 -> 396760
6032024-08-05T19:18:34.678Zuploaded: /tmp/debug/mpstat.txt
6042024-08-05T19:18:34.678Zuploading: /tmp/debug/paging.txt (69636 bytes)
6052024-08-05T19:18:34.685Zupload warning: file "/tmp/debug/paging.txt" changed size mid upload: 69636 -> 70934
6062024-08-05T19:18:35.691Zuploaded: /tmp/debug/paging.txt
6072024-08-05T19:18:35.694Zuploading: /tmp/debug/prstat.txt (734965 bytes)
6082024-08-05T19:18:35.713Zupload warning: file "/tmp/debug/prstat.txt" changed size mid upload: 734965 -> 750463
6092024-08-05T19:18:36.719Zuploaded: /tmp/debug/prstat.txt
6102024-08-05T19:18:36.719Zuploading: /tmp/debug/psrinfo.txt (1528 bytes)
6112024-08-05T19:18:37.728Zuploaded: /tmp/debug/psrinfo.txt
6122024-08-05T19:18:37.731Zuploading: /tmp/debug/upstairs-info.txt (81066 bytes)
6132024-08-05T19:18:38.740Zuploaded: /tmp/debug/upstairs-info.txt