01J4HXWY5DJFHB83T6EWEFP4T9: test-up-encrypted

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

Buildomat Job: 01J4HXX7TJ36WTC43YHBPXTXX8

Tags:

Artefacts:

Output:

SEQ GLOBAL TIME DETAILS
12024-08-05T19:07:57.808Zjob dependencies complete; ready to run (waiting for 19 m 59 s)
22024-08-05T19:09:05.210Zjob assigned to worker 01J4HZ23M17JFMB0BME6Y9THXP (queued for 1 m 7 s)
32024-08-05T19:09:13.343Zdownloading input: /input/build/work/bins/crucible-downstairs.gz
42024-08-05T19:09:14.416Zdownloaded input: /input/build/work/bins/crucible-downstairs.gz
52024-08-05T19:09:14.416Zdownloading input: /input/build/work/bins/crucible-hammer.gz
62024-08-05T19:09:15.265Zdownloaded input: /input/build/work/bins/crucible-hammer.gz
72024-08-05T19:09:15.265Zdownloading input: /input/build/work/bins/crutest.gz
82024-08-05T19:09:16.312Zdownloaded input: /input/build/work/bins/crutest.gz
92024-08-05T19:09:16.312Zdownloading input: /input/build/work/bins/dsc.gz
102024-08-05T19:09:16.965Zdownloaded input: /input/build/work/bins/dsc.gz
112024-08-05T19:09:16.970Zdownloading input: /input/build/work/scripts/perf-downstairs-tick.d
122024-08-05T19:09:16.987Zdownloaded input: /input/build/work/scripts/perf-downstairs-tick.d
132024-08-05T19:09:16.988Zdownloading input: /input/build/work/scripts/test_ds.sh
142024-08-05T19:09:17.007Zdownloaded input: /input/build/work/scripts/test_ds.sh
152024-08-05T19:09:17.007Zdownloading input: /input/build/work/scripts/test_live_repair.sh
162024-08-05T19:09:17.024Zdownloaded input: /input/build/work/scripts/test_live_repair.sh
172024-08-05T19:09:17.024Zdownloading input: /input/build/work/scripts/test_repair.sh
182024-08-05T19:09:17.043Zdownloaded input: /input/build/work/scripts/test_repair.sh
192024-08-05T19:09:17.043Zdownloading input: /input/build/work/scripts/test_replay.sh
202024-08-05T19:09:17.062Zdownloaded input: /input/build/work/scripts/test_replay.sh
212024-08-05T19:09:17.062Zdownloading input: /input/build/work/scripts/test_up.sh
222024-08-05T19:09:17.080Zdownloaded input: /input/build/work/scripts/test_up.sh
232024-08-05T19:09:17.080Zdownloading input: /input/build/work/scripts/upstairs_info.d
242024-08-05T19:09:17.119Zdownloaded input: /input/build/work/scripts/upstairs_info.d
252024-08-05T19:09:17.122Zdownloading input: /input/build/tmp/cargo-test-out.log
262024-08-05T19:09:17.992Zdownloaded input: /input/build/tmp/cargo-test-out.log
 
272024-08-05T19:09:17.992Zstarting task 0: "setup"
282024-08-05T19:09:18.057Z++ uname -s
292024-08-05T19:09:18.060Z+ kern=SunOS
302024-08-05T19:09:18.060Z+ case "$kern" in
312024-08-05T19:09:18.060Z+ groupadd -g 12345 build
322024-08-05T19:09:18.063Z+ useradd -u 12345 -g build -d /home/build -s /bin/bash -c build -P 'Primary Administrator' build
332024-08-05T19:09:20.085Z+ zfs create -o mountpoint=/work rpool/work
342024-08-05T19:09:20.410Z++ awk '$2 == "/home" { print $3 }' /etc/mnttab
352024-08-05T19:09:20.414Z+ home_fs=zfs
362024-08-05T19:09:20.414Z+ [[ zfs == autofs ]]
372024-08-05T19:09:20.414Z+ mkdir -p /home/build
382024-08-05T19:09:20.417Z+ chown build:build /home/build /work
392024-08-05T19:09:22.417Z+ chmod 0700 /home/build /work
402024-08-05T19:09:22.421Zprocess exited: duration 4428 ms, exit code 0
 
412024-08-05T19:09:22.426Zstarting task 1: "authentication"
422024-08-05T19:09:22.445Zprocess exited: duration 18 ms, exit code 0
 
432024-08-05T19:09:22.451Zstarting task 2: "build"
442024-08-05T19:09:22.456Z+ banner cores
452024-08-05T19:09:22.480Z
462024-08-05T19:09:22.480Z #### #### ##### ###### ####
472024-08-05T19:09:22.480Z # # # # # # # #
482024-08-05T19:09:22.480Z # # # # # ##### ####
492024-08-05T19:09:22.480Z # # # ##### # #
502024-08-05T19:09:22.480Z # # # # # # # # #
512024-08-05T19:09:22.480Z #### #### # # ###### ####
522024-08-05T19:09:22.480Z
532024-08-05T19:09:22.483Z+ 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:22.500Z+ echo 'input bins dir contains:'
552024-08-05T19:09:22.500Zinput bins dir contains:
562024-08-05T19:09:22.500Z+ ls -ltr /input/build/work/bins
572024-08-05T19:09:22.504Ztotal 697383
582024-08-05T19:09:22.504Z-rw-r--r-- 1 root root 105756823 Aug 5 19:09 crucible-downstairs.gz
592024-08-05T19:09:22.504Z-rw-r--r-- 1 root root 83355941 Aug 5 19:09 crucible-hammer.gz
602024-08-05T19:09:22.504Z-rw-r--r-- 1 root root 103298177 Aug 5 19:09 crutest.gz
612024-08-05T19:09:22.504Z-rw-r--r-- 1 root root 64414616 Aug 5 19:09 dsc.gz
622024-08-05T19:09:22.504Z+ banner unpack
632024-08-05T19:09:22.507Z
642024-08-05T19:09:22.507Z # # # # ##### ## #### # #
652024-08-05T19:09:22.507Z # # ## # # # # # # # # #
662024-08-05T19:09:22.507Z # # # # # # # # # # ####
672024-08-05T19:09:22.507Z # # # # # ##### ###### # # #
682024-08-05T19:09:22.507Z # # # ## # # # # # # #
692024-08-05T19:09:22.507Z #### # # # # # #### # #
702024-08-05T19:09:22.507Z
712024-08-05T19:09:22.507Z+ mkdir -p /var/tmp/bins
722024-08-05T19:09:22.507Z+ for t in "$input/bins/"*.gz
732024-08-05T19:09:22.510Z++ basename /input/build/work/bins/crucible-downstairs.gz
742024-08-05T19:09:22.510Z+ b=crucible-downstairs.gz
752024-08-05T19:09:22.510Z+ b=crucible-downstairs
762024-08-05T19:09:22.510Z+ gunzip
772024-08-05T19:09:24.737Z+ chmod +x /var/tmp/bins/crucible-downstairs
782024-08-05T19:09:24.740Z+ for t in "$input/bins/"*.gz
792024-08-05T19:09:24.740Z++ basename /input/build/work/bins/crucible-hammer.gz
802024-08-05T19:09:24.743Z+ b=crucible-hammer.gz
812024-08-05T19:09:24.743Z+ b=crucible-hammer
822024-08-05T19:09:24.743Z+ gunzip
832024-08-05T19:09:26.486Z+ chmod +x /var/tmp/bins/crucible-hammer
842024-08-05T19:09:26.489Z+ for t in "$input/bins/"*.gz
852024-08-05T19:09:26.489Z++ basename /input/build/work/bins/crutest.gz
862024-08-05T19:09:26.489Z+ b=crutest.gz
872024-08-05T19:09:26.489Z+ b=crutest
882024-08-05T19:09:26.489Z+ gunzip
892024-08-05T19:09:28.657Z+ chmod +x /var/tmp/bins/crutest
902024-08-05T19:09:28.662Z+ for t in "$input/bins/"*.gz
912024-08-05T19:09:28.662Z++ basename /input/build/work/bins/dsc.gz
922024-08-05T19:09:28.662Z+ b=dsc.gz
932024-08-05T19:09:28.662Z+ b=dsc
942024-08-05T19:09:28.662Z+ gunzip
952024-08-05T19:09:30.054Z+ chmod +x /var/tmp/bins/dsc
962024-08-05T19:09:30.057Z+ export BINDIR=/var/tmp/bins
972024-08-05T19:09:30.057Z+ BINDIR=/var/tmp/bins
982024-08-05T19:09:30.057Z+ jobpid=1140
992024-08-05T19:09:30.057Z+ echo 'Setup debug logging'
1002024-08-05T19:09:30.057ZSetup debug logging
1012024-08-05T19:09:30.057Z+ mkdir /tmp/debug
1022024-08-05T19:09:30.057Z+ sleep 7200
1032024-08-05T19:09:30.060Z+ psrinfo -v
1042024-08-05T19:09:30.063Z+ df -h
1052024-08-05T19:09:30.070Z+ prstat -d d -mLc 1
1062024-08-05T19:09:30.073Z+ iostat -T d -xn 1
1072024-08-05T19:09:30.073Z+ mpstat -T d 1
1082024-08-05T19:09:30.073Z+ vmstat -T d -p 1
1092024-08-05T19:09:30.073Z+ pfexec dtrace -Z -s /input/build/work/scripts/perf-downstairs-tick.d
1102024-08-05T19:09:30.073Z+ banner test_up_encrypted
1112024-08-05T19:09:30.077Z+ pfexec dtrace -Z -s /input/build/work/scripts/upstairs_info.d
1122024-08-05T19:09:30.077Z
1132024-08-05T19:09:30.077Z ##### ###### #### ##### # # ##### ###### # #
1142024-08-05T19:09:30.077Z # # # # # # # # # ## #
1152024-08-05T19:09:30.077Z # ##### #### # # # # # ##### # # #
1162024-08-05T19:09:30.077Z # # # # # # ##### # # # #
1172024-08-05T19:09:30.077Z # # # # # # # # # # ##
1182024-08-05T19:09:30.077Z # ###### #### # ####### #### # ####### ###### # #
1192024-08-05T19:09:30.077Z
1202024-08-05T19:09:30.077Z+ ptime -m bash /input/build/work/scripts/test_up.sh -N encrypted
1212024-08-05T19:09:30.104Z/input/build/work
1222024-08-05T19:09:30.113ZTurn off color for downstairs dump
1232024-08-05T19:09:30.229ZUpstairs using key: VcmHj3AhaBUP95QpwvZEyXhFE9mGYrUALFaA8LQpX1c=
1242024-08-05T19:09:30.232Zdsc output goes to /tmp/test_up/dsc-out.txt
1252024-08-05T19:09:30.232ZCreating three downstairs regions
1262024-08-05T19:09:30.458ZStarting three downstairs
1272024-08-05T19:09:35.466ZDisable automatic restart on all downstairs
1282024-08-05T19:09:35.532Z
1292024-08-05T19:09:35.532ZBegin tests, output goes to /tmp/test_up/test_up_out.txt
1302024-08-05T19:09:35.536ZRunning test: span
1312024-08-05T19:09:39.598ZCompleted test: span
1322024-08-05T19:09:44.605ZRunning test: big
1332024-08-05T19:09:48.915ZCompleted test: big
1342024-08-05T19:09:53.923ZRunning test: dep
1352024-08-05T19:10:42.287ZCompleted test: dep
1362024-08-05T19:10:47.293ZRunning test: balloon
1372024-08-05T19:11:26.566ZCompleted test: balloon
1382024-08-05T19:11:31.574ZRunning test: deactivate
1392024-08-05T19:12:26.220ZCompleted test: deactivate
1402024-08-05T19:12:31.227ZRunning hammer
1412024-08-05T19:12:42.827ZRun repair tests
1422024-08-05T19:12:42.830Z/var/tmp/bins/crutest fill -g 31 -q --key VcmHj3AhaBUP95QpwvZEyXhFE9mGYrUALFaA8LQpX1c= -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
1432024-08-05T19:12:42.845Z{"msg":"Upstairs starts","v":0,"name":"crucible","level":30,"time":"2024-08-05T19:12:41.20502673Z","hostname":"w-01J4HZ23M17JFMB0BME6Y9THXP","pid":1219}
1442024-08-05T19:12:42.849Z{"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:12:41.205419752Z","hostname":"w-01J4HZ23M17JFMB0BME6Y9THXP","pid":1219}
1452024-08-05T19:12:42.849Z{"msg":"Upstairs <-> Downstairs Message Version: 11","v":0,"name":"crucible","level":30,"time":"2024-08-05T19:12:41.205471377Z","hostname":"w-01J4HZ23M17JFMB0BME6Y9THXP","pid":1219}
1462024-08-05T19:12:42.849Z{"msg":"Crucible acc43ad6-2969-48d5-9ff0-93e6cf8b03ca has session id: 8b2939a0-20ab-41c3-82c7-52606fab2ce4","v":0,"name":"crucible","level":30,"time":"2024-08-05T19:12:41.205817735Z","hostname":"w-01J4HZ23M17JFMB0BME6Y9THXP","pid":1219,"session_id":"8b2939a0-20ab-41c3-82c7-52606fab2ce4"}
1472024-08-05T19:12:42.849Z{"msg":"Upstairs opts: Upstairs UUID: acc43ad6-2969-48d5-9ff0-93e6cf8b03ca, Targets: [127.0.0.1:8810, 127.0.0.1:8820, 127.0.0.1:8830], lossy: false, flush_timeout: None, key populated: true, cert_pem populated: false, key_pem populated: false, root_cert_pem populated: false, Control: None, read_only: false","v":0,"name":"crucible","level":30,"time":"2024-08-05T19:12:41.20586748Z","hostname":"w-01J4HZ23M17JFMB0BME6Y9THXP","pid":1219,"session_id":"8b2939a0-20ab-41c3-82c7-52606fab2ce4"}
1482024-08-05T19:12:42.849Z{"msg":"Crucible stats registered with UUID: acc43ad6-2969-48d5-9ff0-93e6cf8b03ca","v":0,"name":"crucible","level":30,"time":"2024-08-05T19:12:41.205889738Z","hostname":"w-01J4HZ23M17JFMB0BME6Y9THXP","pid":1219,"session_id":"8b2939a0-20ab-41c3-82c7-52606fab2ce4"}
1492024-08-05T19:12:42.849ZCrucible runtime is spawned
1502024-08-05T19:12:42.849Z{"msg":"The guest has requested activation with gen:31","v":0,"name":"crucible","level":30,"time":"2024-08-05T19:12:41.206251533Z","hostname":"w-01J4HZ23M17JFMB0BME6Y9THXP","pid":1219}
1512024-08-05T19:12:42.849Z{"msg":"acc43ad6-2969-48d5-9ff0-93e6cf8b03ca active request set","v":0,"name":"crucible","level":30,"time":"2024-08-05T19:12:41.20628144Z","hostname":"w-01J4HZ23M17JFMB0BME6Y9THXP","pid":1219,"session_id":"8b2939a0-20ab-41c3-82c7-52606fab2ce4"}
1522024-08-05T19:12:42.849Z{"msg":"sending connect oneshot to client","v":0,"name":"crucible","level":30,"time":"2024-08-05T19:12:41.206295449Z","hostname":"w-01J4HZ23M17JFMB0BME6Y9THXP","pid":1219,"client":"0","":"downstairs","session_id":"8b2939a0-20ab-41c3-82c7-52606fab2ce4"}
1532024-08-05T19:12:42.849Z{"msg":"client set_active_request while in New; waiting...","v":0,"name":"crucible","level":30,"time":"2024-08-05T19:12:41.206322656Z","hostname":"w-01J4HZ23M17JFMB0BME6Y9THXP","pid":1219,"client":"0","":"downstairs","session_id":"8b2939a0-20ab-41c3-82c7-52606fab2ce4"}
1542024-08-05T19:12:42.849Z{"msg":"sending connect oneshot to client","v":0,"name":"crucible","level":30,"time":"2024-08-05T19:12:41.206336915Z","hostname":"w-01J4HZ23M17JFMB0BME6Y9THXP","pid":1219,"client":"1","":"downstairs","session_id":"8b2939a0-20ab-41c3-82c7-52606fab2ce4"}
1552024-08-05T19:12:42.849Z{"msg":"client set_active_request while in New; waiting...","v":0,"name":"crucible","level":30,"time":"2024-08-05T19:12:41.206353544Z","hostname":"w-01J4HZ23M17JFMB0BME6Y9THXP","pid":1219,"client":"1","":"downstairs","session_id":"8b2939a0-20ab-41c3-82c7-52606fab2ce4"}
1562024-08-05T19:12:42.849Z{"msg":"sending connect oneshot to client","v":0,"name":"crucible","level":30,"time":"2024-08-05T19:12:41.206386621Z","hostname":"w-01J4HZ23M17JFMB0BME6Y9THXP","pid":1219,"client":"2","":"downstairs","session_id":"8b2939a0-20ab-41c3-82c7-52606fab2ce4"}
1572024-08-05T19:12:42.849Z{"msg":"client set_active_request while in New; waiting...","v":0,"name":"crucible","level":30,"time":"2024-08-05T19:12:41.206413288Z","hostname":"w-01J4HZ23M17JFMB0BME6Y9THXP","pid":1219,"client":"2","":"downstairs","session_id":"8b2939a0-20ab-41c3-82c7-52606fab2ce4"}
1582024-08-05T19:12:42.849Z{"msg":"connecting to 127.0.0.1:8830","v":0,"name":"crucible","level":30,"time":"2024-08-05T19:12:41.206433926Z","hostname":"w-01J4HZ23M17JFMB0BME6Y9THXP","pid":1219,"":"io task","client":"2","":"downstairs","session_id":"8b2939a0-20ab-41c3-82c7-52606fab2ce4"}
1592024-08-05T19:12:42.849Z{"msg":"connecting to 127.0.0.1:8810","v":0,"name":"crucible","level":30,"time":"2024-08-05T19:12:41.206462413Z","hostname":"w-01J4HZ23M17JFMB0BME6Y9THXP","pid":1219,"":"io task","client":"0","":"downstairs","session_id":"8b2939a0-20ab-41c3-82c7-52606fab2ce4"}
1602024-08-05T19:12:42.849Z{"msg":"connecting to 127.0.0.1:8820","v":0,"name":"crucible","level":30,"time":"2024-08-05T19:12:41.206563704Z","hostname":"w-01J4HZ23M17JFMB0BME6Y9THXP","pid":1219,"":"io task","client":"1","":"downstairs","session_id":"8b2939a0-20ab-41c3-82c7-52606fab2ce4"}
1612024-08-05T19:12:42.849Z{"msg":"ds_connection connected from Ok(127.0.0.1:50514)","v":0,"name":"crucible","level":30,"time":"2024-08-05T19:12:41.206616409Z","hostname":"w-01J4HZ23M17JFMB0BME6Y9THXP","pid":1219,"":"io task","client":"0","":"downstairs","session_id":"8b2939a0-20ab-41c3-82c7-52606fab2ce4"}
1622024-08-05T19:12:42.849Z{"msg":"ds_connection connected from Ok(127.0.0.1:62079)","v":0,"name":"crucible","level":30,"time":"2024-08-05T19:12:41.206676303Z","hostname":"w-01J4HZ23M17JFMB0BME6Y9THXP","pid":1219,"":"io task","client":"2","":"downstairs","session_id":"8b2939a0-20ab-41c3-82c7-52606fab2ce4"}
1632024-08-05T19:12:42.849Z{"msg":"ds_connection connected from Ok(127.0.0.1:40883)","v":0,"name":"crucible","level":30,"time":"2024-08-05T19:12:41.20702806Z","hostname":"w-01J4HZ23M17JFMB0BME6Y9THXP","pid":1219,"":"io task","client":"1","":"downstairs","session_id":"8b2939a0-20ab-41c3-82c7-52606fab2ce4"}
1642024-08-05T19:12:42.849Z{"msg":"ds_transition from New to WaitActive","v":0,"name":"crucible","level":30,"time":"2024-08-05T19:12:41.207676858Z","hostname":"w-01J4HZ23M17JFMB0BME6Y9THXP","pid":1219,"client":"2","":"downstairs","session_id":"8b2939a0-20ab-41c3-82c7-52606fab2ce4"}
1652024-08-05T19:12:42.849Z{"msg":"[2] Transition from New to WaitActive","v":0,"name":"crucible","level":30,"time":"2024-08-05T19:12:41.207717384Z","hostname":"w-01J4HZ23M17JFMB0BME6Y9THXP","pid":1219,"client":"2","":"downstairs","session_id":"8b2939a0-20ab-41c3-82c7-52606fab2ce4"}
1662024-08-05T19:12:42.849Z{"msg":"ds_transition from New to WaitActive","v":0,"name":"crucible","level":30,"time":"2024-08-05T19:12:41.207744972Z","hostname":"w-01J4HZ23M17JFMB0BME6Y9THXP","pid":1219,"client":"1","":"downstairs","session_id":"8b2939a0-20ab-41c3-82c7-52606fab2ce4"}
1672024-08-05T19:12:42.849Z{"msg":"[1] Transition from New to WaitActive","v":0,"name":"crucible","level":30,"time":"2024-08-05T19:12:41.207822934Z","hostname":"w-01J4HZ23M17JFMB0BME6Y9THXP","pid":1219,"client":"1","":"downstairs","session_id":"8b2939a0-20ab-41c3-82c7-52606fab2ce4"}
1682024-08-05T19:12:42.849Z{"msg":"ds_transition from New to WaitActive","v":0,"name":"crucible","level":30,"time":"2024-08-05T19:12:41.20786766Z","hostname":"w-01J4HZ23M17JFMB0BME6Y9THXP","pid":1219,"client":"0","":"downstairs","session_id":"8b2939a0-20ab-41c3-82c7-52606fab2ce4"}
1692024-08-05T19:12:42.849Z{"msg":"[0] Transition from New to WaitActive","v":0,"name":"crucible","level":30,"time":"2024-08-05T19:12:41.207885738Z","hostname":"w-01J4HZ23M17JFMB0BME6Y9THXP","pid":1219,"client":"0","":"downstairs","session_id":"8b2939a0-20ab-41c3-82c7-52606fab2ce4"}
1702024-08-05T19:12:42.849Z{"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:12:41.208401229Z","hostname":"w-01J4HZ23M17JFMB0BME6Y9THXP","pid":1219,"client":"1","":"downstairs","session_id":"8b2939a0-20ab-41c3-82c7-52606fab2ce4"}
1712024-08-05T19:12:42.849Z{"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:12:41.208451644Z","hostname":"w-01J4HZ23M17JFMB0BME6Y9THXP","pid":1219,"client":"2","":"downstairs","session_id":"8b2939a0-20ab-41c3-82c7-52606fab2ce4"}
1722024-08-05T19:12:42.854Z{"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:12:41.208483901Z","hostname":"w-01J4HZ23M17JFMB0BME6Y9THXP","pid":1219,"client":"0","":"downstairs","session_id":"8b2939a0-20ab-41c3-82c7-52606fab2ce4"}
1732024-08-05T19:12:42.854Z{"msg":"ds_transition from WaitActive to WaitQuorum","v":0,"name":"crucible","level":30,"time":"2024-08-05T19:12:41.208872084Z","hostname":"w-01J4HZ23M17JFMB0BME6Y9THXP","pid":1219,"client":"1","":"downstairs","session_id":"8b2939a0-20ab-41c3-82c7-52606fab2ce4"}
1742024-08-05T19:12:42.854Z{"msg":"[1] Transition from WaitActive to WaitQuorum","v":0,"name":"crucible","level":30,"time":"2024-08-05T19:12:41.208905581Z","hostname":"w-01J4HZ23M17JFMB0BME6Y9THXP","pid":1219,"client":"1","":"downstairs","session_id":"8b2939a0-20ab-41c3-82c7-52606fab2ce4"}
1752024-08-05T19:12:42.854Z{"msg":"Waiting for more clients to be ready","v":0,"name":"crucible","level":30,"time":"2024-08-05T19:12:41.20892056Z","hostname":"w-01J4HZ23M17JFMB0BME6Y9THXP","pid":1219,"session_id":"8b2939a0-20ab-41c3-82c7-52606fab2ce4"}
1762024-08-05T19:12:42.854Z{"msg":"ds_transition from WaitActive to WaitQuorum","v":0,"name":"crucible","level":30,"time":"2024-08-05T19:12:41.20901772Z","hostname":"w-01J4HZ23M17JFMB0BME6Y9THXP","pid":1219,"client":"2","":"downstairs","session_id":"8b2939a0-20ab-41c3-82c7-52606fab2ce4"}
1772024-08-05T19:12:42.854Z{"msg":"[2] Transition from WaitActive to WaitQuorum","v":0,"name":"crucible","level":30,"time":"2024-08-05T19:12:41.209063256Z","Wait for a query_work_queue command to finish before sending IO
1782024-08-05T19:12:42.854Zhostname":"w-01J4HZ23M17JFMB0BME6Y9THXP","pid":1219,"client":"2","":"downstairs","session_id":"8b2939a0-20ab-41c3-82c7-52606fab2ce4"}
1792024-08-05T19:12:42.854Z{"msg":"Waiting for more clients to be ready","v":0,"name":"crucible","level":30,"time":"2024-08-05T19:12:41.209103502Z","hostname":"w-01J4HZ23M17JFMB0BME6Y9THXP","pid":1219,"session_id":"8b2939a0-20ab-41c3-82c7-52606fab2ce4"}
1802024-08-05T19:12:42.854Z{"msg":"ds_transition from WaitActive to WaitQuorum","v":0,"name":"crucible","level":30,"time":"2024-08-05T19:12:41.209137319Z","hostname":"w-01J4HZ23M17JFMB0BME6Y9THXP","pid":1219,"client":"0","":"downstairs","session_id":"8b2939a0-20ab-41c3-82c7-52606fab2ce4"}
1812024-08-05T19:12:42.854Z{"msg":"[0] Transition from WaitActive to WaitQuorum","v":0,"name":"crucible","level":30,"time":"2024-08-05T19:12:41.209173266Z","hostname":"w-01J4HZ23M17JFMB0BME6Y9THXP","pid":1219,"client":"0","":"downstairs","session_id":"8b2939a0-20ab-41c3-82c7-52606fab2ce4"}
1822024-08-05T19:12:42.854Z{"msg":"[0]R flush_numbers: [1673, 1673, 1673, 1673, 1673]","v":0,"name":"crucible","level":30,"time":"2024-08-05T19:12:41.209208672Z","hostname":"w-01J4HZ23M17JFMB0BME6Y9THXP","pid":1219,"":"downstairs","":"downstairs","session_id":"8b2939a0-20ab-41c3-82c7-52606fab2ce4"}
1832024-08-05T19:12:42.854Z{"msg":"[0]R generation: [25, 25, 25, 25, 25]","v":0,"name":"crucible","level":30,"time":"2024-08-05T19:12:41.209246019Z","hostname":"w-01J4HZ23M17JFMB0BME6Y9THXP","pid":1219,"":"downstairs","":"downstairs","session_id":"8b2939a0-20ab-41c3-82c7-52606fab2ce4"}
1842024-08-05T19:12:42.854Z{"msg":"[0]R dirty: [false, false, false, false, false]","v":0,"name":"crucible","level":30,"time":"2024-08-05T19:12:41.209284855Z","hostname":"w-01J4HZ23M17JFMB0BME6Y9THXP","pid":1219,"":"downstairs","":"downstairs","session_id":"8b2939a0-20ab-41c3-82c7-52606fab2ce4"}
1852024-08-05T19:12:42.854Z{"msg":"[1]R flush_numbers: [1673, 1673, 1673, 1673, 1673]","v":0,"name":"crucible","level":30,"time":"2024-08-05T19:12:41.209322482Z","hostname":"w-01J4HZ23M17JFMB0BME6Y9THXP","pid":1219,"":"downstairs","":"downstairs","session_id":"8b2939a0-20ab-41c3-82c7-52606fab2ce4"}
1862024-08-05T19:12:42.854Z{"msg":"[1]R generation: [25, 25, 25, 25, 25]","v":0,"name":"crucible","level":30,"time":"2024-08-05T19:12:41.209349039Z","hostname":"w-01J4HZ23M17JFMB0BME6Y9THXP","pid":1219,"":"downstairs","":"downstairs","session_id":"8b2939a0-20ab-41c3-82c7-52606fab2ce4"}
1872024-08-05T19:12:42.854Z{"msg":"[1]R dirty: [false, false, false, false, false]",Region: es:10 ec:5 bs:4096 ts:204800 tb:50 max_io:50 or 204800
1882024-08-05T19:12:42.854Z"v":0,"name":"crucible","level":30,"time":"2024-08-05T19:12:41.209478927Z","hostname":"w-01J4HZ23M17JFMB0BME6Y9THXP","pid":1219,"":"downstairs","":"downstairs","session_id":"8b2939a0-20ab-41c3-82c7-52606fab2ce4"}
1892024-08-05T19:12:42.854Z{"msg":"Fill test
1902024-08-05T19:12:42.854Z[2]R flush_numbers: [1673, 1673, 1673, 1673, 1673]","v":0,"name":"crucible","level":30,"time":"2024-08-05T19:12:41.209508934Z","hostname":"w-01J4HZ23M17JFMB0BME6Y9THXP","pid":1219,"":"downstairs","":"downstairs","session_id":"8b2939a0-20ab-41c3-82c7-52606fab2ce4"}
1912024-08-05T19:12:42.854Z{"msg":"[2]R generation: [25, 25, 25, 25, 25]","v":0,"name":"crucible","level":30,"time":"2024-08-05T19:12:41.209524092Z","hostname":"w-01J4HZ23M17JFMB0BME6Y9THXP","pid":1219,"":"downstairs","":"downstairs","session_id":"8b2939a0-20ab-41c3-82c7-52606fab2ce4"}
1922024-08-05T19:12:42.854Z{"msg":"[2]R dirty: [false, false, false, false, false]","v":0,"name":"crucible","level":30,"time":"2024-08-05T19:12:41.20954419Z","hostname":"w-01J4HZ23M17JFMB0BME6Y9THXP","pid":1219,"":"downstairs","":"downstairs","session_id":"8b2939a0-20ab-41c3-82c7-52606fab2ce4"}
1932024-08-05T19:12:42.854Z{"msg":"Max found gen is 26","v":0,"name":"crucible","level":30,"time":"2024-08-05T19:12:41.209557529Z","hostname":"w-01J4HZ23M17JFMB0BME6Y9THXP","pid":1219,"":"downstairs","":"downstairs","session_id":"8b2939a0-20ab-41c3-82c7-52606fab2ce4"}
1942024-08-05T19:12:42.854Z{"msg":"Generation requested: 31 >= found:26","v":0,"name":"crucible","level":30,"time":"2024-08-05T19:12:41.209577617Z","hostname":"w-01J4HZ23M17JFMB0BME6Y9THXP","pid":1219,"":"downstairs","":"downstairs","session_id":"8b2939a0-20ab-41c3-82c7-52606fab2ce4"}
1952024-08-05T19:12:42.854Z{"msg":"Next flush: 1674","v":0,"name":"crucible","level":30,"time":"2024-08-05T19:12:41.209590556Z","hostname":"w-01J4HZ23M17JFMB0BME6Y9THXP","pid":1219,"":"downstairs","":"downstairs","session_id":"8b2939a0-20ab-41c3-82c7-52606fab2ce4"}
1962024-08-05T19:12:42.854Z{"msg":"All extents match","v":0,"name":"crucible","level":30,"time":"2024-08-05T19:12:41.209609954Z","hostname":"w-01J4HZ23M17JFMB0BME6Y9THXP","pid":1219,"":"downstairs","":"downstairs","session_id":"8b2939a0-20ab-41c3-82c7-52606fab2ce4"}
1972024-08-05T19:12:42.854Z{"msg":"No downstairs reconciliation required","v":0,"name":"crucible","level":30,"time":"2024-08-05T19:12:41.209623273Z","hostname":"w-01J4HZ23M17JFMB0BME6Y9THXP","pid":1219,"session_id":"8b2939a0-20ab-41c3-82c7-52606fab2ce4"}
1982024-08-05T19:12:42.854Z{"msg":"Transition from WaitQuorum to Active","v":0,"name":"crucible","level":30,"time":"2024-08-05T19:12:41.209641511Z","hostname":"w-01J4HZ23M17JFMB0BME6Y9THXP","pid":1219,"client":"0","":"downstairs","session_id":"8b2939a0-20ab-41c3-82c7-52606fab2ce4"}
1992024-08-05T19:12:42.854Z{"msg":"Transition from WaitQuorum to Active","v":0,"name":"crucible","level":30,"time":"2024-08-05T19:12:41.20965503Z","hostname":"w-01J4HZ23M17JFMB0BME6Y9THXP","pid":1219,"client":"1","":"downstairs","session_id":"8b2939a0-20ab-41c3-82c7-52606fab2ce4"}
2002024-08-05T19:12:42.854Z{"msg":"Transition from WaitQuorum to Active","v":0,"name":"crucible","level":30,"time":"2024-08-05T19:12:41.209674698Z","hostname":"w-01J4HZ23M17JFMB0BME6Y9THXP","pid":1219,"client":"2","":"downstairs","session_id":"8b2939a0-20ab-41c3-82c7-52606fab2ce4"}
2012024-08-05T19:12:42.854Z{"msg":"All required reconciliation work is completed","v":0,"name":"crucible","level":30,"time":"2024-08-05T19:12:41.209687877Z","hostname":"w-01J4HZ23M17JFMB0BME6Y9THXP","pid":1219,"session_id":"8b2939a0-20ab-41c3-82c7-52606fab2ce4"}
2022024-08-05T19:12:42.855Z{"msg":"Set Downstairs and Upstairs active after reconciliation","v":0,"name":"crucible","level":30,"time":"2024-08-05T19:12:41.209706565Z","hostname":"w-01J4HZ23M17JFMB0BME6Y9THXP","pid":1219,"session_id":"8b2939a0-20ab-41c3-82c7-52606fab2ce4"}
2032024-08-05T19:12:42.855Z{"msg":"acc43ad6-2969-48d5-9ff0-93e6cf8b03ca is now active with session: 8b2939a0-20ab-41c3-82c7-52606fab2ce4","v":0,"name":"crucible","level":30,"time":"2024-08-05T19:12:41.209719614Z","hostname":"w-01J4HZ23M17JFMB0BME6Y9THXP","pid":1219,"session_id":"8b2939a0-20ab-41c3-82c7-52606fab2ce4"}
2042024-08-05T19:12:42.855Z{"msg":"Set Active after no reconciliation","v":0,"name":"crucible","level":30,"time":"2024-08-05T19:12:41.209737972Z","hostname":"w-01J4HZ23M17JFMB0BME6Y9THXP","pid":1219,"session_id":"8b2939a0-20ab-41c3-82c7-52606fab2ce4"}
2052024-08-05T19:12:42.855Z{"msg":"The guest has finished waiting for activation with:31","v":0,"name":"crucible","level":30,"time":"2024-08-05T19:12:41.209750031Z","hostname":"w-01J4HZ23M17JFMB0BME6Y9THXP","pid":1219}
2062024-08-05T19:12:42.887ZRead and Verify all blocks (0..50 range:false)
2072024-08-05T19:12:42.922ZWrote out file "/var/tmp/test_up/verify_file"
2082024-08-05T19:12:42.922ZCLIENT: Tests done. All submitted work has been ACK'd
2092024-08-05T19:12:42.922Z----------------------------------------------------------------
2102024-08-05T19:12:42.922Z Crucible gen:31 GIO:true work queues: Upstairs:0 downstairs:1
2112024-08-05T19:12:42.925ZStates: Active Active Active
2122024-08-05T19:12:42.925ZGW_ID ACK DSID TYPE BKS/EXT DS:0 DS:1 DS:2 REPLAY
2132024-08-05T19:12:42.925Z 3 Acked 1002 Read 50 Done Done Done false
2142024-08-05T19:12:42.925Z STATES DS:0 DS:1 DS:2 TOTAL
2152024-08-05T19:12:42.925Z New 0 0 0 0
2162024-08-05T19:12:42.925Z Sent 0 0 0 0
2172024-08-05T19:12:42.925Z Done 1 1 1 3
2182024-08-05T19:12:42.925Z Skipped 0 0 0 0
2192024-08-05T19:12:42.925Z Error 0 0 0 0
2202024-08-05T19:12:42.925ZLast Flush: 1001 1001 1001
2212024-08-05T19:12:42.925ZDownstairs last five completed: 1001 1000
2222024-08-05T19:12:42.925ZUpstairs last five completed: 3 2 1
2232024-08-05T19:12:42.925ZCLIENT: Up:0 ds:1 act:3
2242024-08-05T19:12:46.924Z----------------------------------------------------------------
2252024-08-05T19:12:46.924Z Crucible gen:31 GIO:true work queues: Upstairs:0 downstairs:0
2262024-08-05T19:12:46.924ZDownstairs last five completed: 1003 1002 1001 1000
2272024-08-05T19:12:46.924ZUpstairs last five completed: 4 3 2 1
2282024-08-05T19:12:46.924ZCLIENT: Up:0 ds:0 act:3
2292024-08-05T19:12:46.924ZCLIENT: All crucible jobs finished, exiting program
2302024-08-05T19:12:46.927Z{"msg":"Guest handle has been dropped","v":0,"name":"crucible","level":40,"time":"2024-08-05T19:12:45.284188017Z","hostname":"w-01J4HZ23M17JFMB0BME6Y9THXP","pid":1219}
2312024-08-05T19:12:46.934ZRepair setup passed
2322024-08-05T19:12:46.937ZCopy the 8830 file
2332024-08-05T19:12:46.940Zcp -r /var/tmp/test_up/8830 /var/tmp/test_up/previous
2342024-08-05T19:12:46.944Z/var/tmp/bins/crutest repair -g 32 -q --key VcmHj3AhaBUP95QpwvZEyXhFE9mGYrUALFaA8LQpX1c= -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
2352024-08-05T19:12:46.956Z{"msg":"Upstairs starts","v":0,"name":"crucible","level":30,"time":"2024-08-05T19:12:45.31541796Z","hostname":"w-01J4HZ23M17JFMB0BME6Y9THXP","pid":1225}
2362024-08-05T19:12:46.956Z{"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:12:45.315756868Z","hostname":"w-01J4HZ23M17JFMB0BME6Y9THXP","pid":1225}
2372024-08-05T19:12:46.959Z{"msg":"Upstairs <-> Downstairs Message Version: 11","v":0,"name":"crucible","level":30,"time":"2024-08-05T19:12:45.315782115Z","hostname":"w-01J4HZ23M17JFMB0BME6Y9THXP","pid":1225}
2382024-08-05T19:12:46.959Z{"msg":"Crucible d3b19879-a1eb-43b1-9e79-01ee5b4b89c0 has session id: 2c5c9cad-f7da-4b02-bc1a-8d480b286f4d","v":0,"name":"crucible","level":30,"time":"2024-08-05T19:12:45.316148271Z","hostname":"w-01J4HZ23M17JFMB0BME6Y9THXP","pid":1225,"session_id":"2c5c9cad-f7da-4b02-bc1a-8d480b286f4d"}
2392024-08-05T19:12:46.959Z{"msg":"Upstairs opts: Upstairs UUID: d3b19879-a1eb-43b1-9e79-01ee5b4b89c0, Targets: [127.0.0.1:8810, 127.0.0.1:8820, 127.0.0.1:8830], lossy: false, flush_timeout: None, key populated: true, cert_pem populated: false, key_pem populated: false, root_cert_pem populated: false, Control: None, read_only: false","v":0,"name":"crucible","level":30,"time":"2024-08-05T19:12:45.316229093Z","hostname":"w-01J4HZ23M17JFMB0BME6Y9THXP","pid":1225,"session_id":"2c5c9cad-f7da-4b02-bc1a-8d480b286f4d"}
2402024-08-05T19:12:46.959Z{"msg":"Crucible stats registered with UUID: d3b19879-a1eb-43b1-9e79-01ee5b4b89c0","v":0,"name":"crucible","level":30,"time":"2024-08-05T19:12:45.316288717Z","hostname":"w-01J4HZ23M17JFMB0BME6Y9THXP","pid":1225,"session_id":"2c5c9cad-f7da-4b02-bc1a-8d480b286f4d"}
2412024-08-05T19:12:46.959ZCrucible runtime is spawned
2422024-08-05T19:12:46.959Z{"msg":"The guest has requested activation with gen:32","v":0,"name":"crucible","level":30,"time":"2024-08-05T19:12:45.316612726Z","hostname":"w-01J4HZ23M17JFMB0BME6Y9THXP","pid":1225}
2432024-08-05T19:12:46.959Z{"msg":"d3b19879-a1eb-43b1-9e79-01ee5b4b89c0 active request set","v":0,"name":"crucible","level":30,"time":"2024-08-05T19:12:45.316649223Z","hostname":"w-01J4HZ23M17JFMB0BME6Y9THXP","pid":1225,"session_id":"2c5c9cad-f7da-4b02-bc1a-8d480b286f4d"}
2442024-08-05T19:12:46.959Z{"msg":"sending connect oneshot to client","v":0,"name":"crucible","level":30,"time":"2024-08-05T19:12:45.31668452Z","hostname":"w-01J4HZ23M17JFMB0BME6Y9THXP","pid":1225,"client":"0","":"downstairs","session_id":"2c5c9cad-f7da-4b02-bc1a-8d480b286f4d"}
2452024-08-05T19:12:46.959Z{"msg":"client set_active_request while in New; waiting...","v":0,"name":"crucible","level":30,"time":"2024-08-05T19:12:45.316713727Z","hostname":"w-01J4HZ23M17JFMB0BME6Y9THXP","pid":1225,"client":"0","":"downstairs","session_id":"2c5c9cad-f7da-4b02-bc1a-8d480b286f4d"}
2462024-08-05T19:12:46.959Z{"msg":"sending connect oneshot to client","v":0,"name":"crucible","level":30,"time":"2024-08-05T19:12:45.316737155Z","hostname":"w-01J4HZ23M17JFMB0BME6Y9THXP","pid":1225,"client":"1","":"downstairs","session_id":"2c5c9cad-f7da-4b02-bc1a-8d480b286f4d"}
2472024-08-05T19:12:46.959Z{"msg":"client set_active_request while in New; waiting...","v":0,"name":"crucible","level":30,"time":"2024-08-05T19:12:45.316774881Z","hostname":"w-01J4HZ23M17JFMB0BME6Y9THXP","pid":1225,"client":"1","":"downstairs","session_id":"2c5c9cad-f7da-4b02-bc1a-8d480b286f4d"}
2482024-08-05T19:12:46.959Z{"msg":"sending connect oneshot to client","v":0,"name":"crucible","level":30,"time":"2024-08-05T19:12:45.316811368Z","hostname":"w-01J4HZ23M17JFMB0BME6Y9THXP","pid":1225,"client":"2","":"downstairs","session_id":"2c5c9cad-f7da-4b02-bc1a-8d480b286f4d"}
2492024-08-05T19:12:46.959Z{"msg":"client set_active_request while in New; waiting...","v":0,"name":"crucible","level":30,"time":"2024-08-05T19:12:45.316844875Z","hostname":"w-01J4HZ23M17JFMB0BME6Y9THXP","pid":1225,"client":"2","":"downstairs","session_id":"2c5c9cad-f7da-4b02-bc1a-8d480b286f4d"}
2502024-08-05T19:12:46.959Z{"msg":"connecting to 127.0.0.1:8810","v":0,"name":"crucible","level":30,"time":"2024-08-05T19:12:45.316879091Z","hostname":"w-01J4HZ23M17JFMB0BME6Y9THXP","pid":1225,"":"io task","client":"0","":"downstairs","session_id":"2c5c9cad-f7da-4b02-bc1a-8d480b286f4d"}
2512024-08-05T19:12:46.959Z{"msg":"connecting to 127.0.0.1:8820","v":0,"name":"crucible","level":30,"time":"2024-08-05T19:12:45.316905119Z","hostname":"w-01J4HZ23M17JFMB0BME6Y9THXP","pid":1225,"":"io task","client":"1","":"downstairs","session_id":"2c5c9cad-f7da-4b02-bc1a-8d480b286f4d"}
2522024-08-05T19:12:46.959Z{"msg":"connecting to 127.0.0.1:8830","v":0,"name":"crucible","level":30,"time":"2024-08-05T19:12:45.316944965Z","hostname":"w-01J4HZ23M17JFMB0BME6Y9THXP","pid":1225,"":"io task","client":"2","":"downstairs","session_id":"2c5c9cad-f7da-4b02-bc1a-8d480b286f4d"}
2532024-08-05T19:12:46.959Z{"msg":"ds_connection connected from Ok(127.0.0.1:43177)","v":0,"name":"crucible","level":30,"time":"2024-08-05T19:12:45.317115059Z","hostname":"w-01J4HZ23M17JFMB0BME6Y9THXP","pid":1225,"":"io task","client":"2","":"downstairs","session_id":"2c5c9cad-f7da-4b02-bc1a-8d480b286f4d"}
2542024-08-05T19:12:46.959Z{"msg":"ds_connection connected from Ok(127.0.0.1:44656)","v":0,"name":"crucible","level":30,"time":"2024-08-05T19:12:45.317274274Z","hostname":"w-01J4HZ23M17JFMB0BME6Y9THXP","pid":1225,"":"io task","client":"1","":"downstairs","session_id":"2c5c9cad-f7da-4b02-bc1a-8d480b286f4d"}
2552024-08-05T19:12:46.959Z{"msg":"ds_connection connected from Ok(127.0.0.1:51883)","v":0,"name":"crucible","level":30,"time":"2024-08-05T19:12:45.31731787Z","hostname":"w-01J4HZ23M17JFMB0BME6Y9THXP","pid":1225,"":"io task","client":"0","":"downstairs","session_id":"2c5c9cad-f7da-4b02-bc1a-8d480b286f4d"}
2562024-08-05T19:12:46.959Z{"msg":"ds_transition from New to WaitActive","v":0,"name":"crucible","level":30,"time":"2024-08-05T19:12:45.318053869Z","hostname":"w-01J4HZ23M17JFMB0BME6Y9THXP","pid":1225,"client":"2","":"downstairs","session_id":"2c5c9cad-f7da-4b02-bc1a-8d480b286f4d"}
2572024-08-05T19:12:46.959Z{"msg":"[2] Transition from New to WaitActive","v":0,"name":"crucible","level":30,"time":"2024-08-05T19:12:45.318093866Z","hostname":"w-01J4HZ23M17JFMB0BME6Y9THXP","pid":1225,"client":"2","":"downstairs","session_id":"2c5c9cad-f7da-4b02-bc1a-8d480b286f4d"}
2582024-08-05T19:12:46.959Z{"msg":"ds_transition from New to WaitActive","v":0,"name":"crucible","level":30,"time":"2024-08-05T19:12:45.318111074Z","hostname":"w-01J4HZ23M17JFMB0BME6Y9THXP","pid":1225,"client":"0","":"downstairs","session_id":"2c5c9cad-f7da-4b02-bc1a-8d480b286f4d"}
2592024-08-05T19:12:46.959Z{"msg":"[0] Transition from New to WaitActive","v":0,"name":"crucible","level":30,"time":"2024-08-05T19:12:45.31815477Z","hostname":"w-01J4HZ23M17JFMB0BME6Y9THXP","pid":1225,"client":"0","":"downstairs","session_id":"2c5c9cad-f7da-4b02-bc1a-8d480b286f4d"}
2602024-08-05T19:12:46.959Z{"msg":"ds_transition from New to WaitActive","v":0,"name":"crucible","level":30,"time":"2024-08-05T19:12:45.318182617Z","hostname":"w-01J4HZ23M17JFMB0BME6Y9THXP","pid":1225,"client":"1","":"downstairs","session_id":"2c5c9cad-f7da-4b02-bc1a-8d480b286f4d"}
2612024-08-05T19:12:46.959Z{"msg":"[1] Transition from New to WaitActive","v":0,"name":"crucible","level":30,"time":"2024-08-05T19:12:45.318236622Z","hostname":"w-01J4HZ23M17JFMB0BME6Y9THXP","pid":1225,"client":"1","":"downstairs","session_id":"2c5c9cad-f7da-4b02-bc1a-8d480b286f4d"}
2622024-08-05T19:12:46.959Z{"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:12:45.318755793Z","hostname":"w-01J4HZ23M17JFMB0BME6Y9THXP","pid":1225,"client":"2","":"downstairs","session_id":"2c5c9cad-f7da-4b02-bc1a-8d480b286f4d"}
2632024-08-05T19:12:46.959Z{"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:12:45.318809758Z","hostname":"w-01J4HZ23M17JFMB0BME6Y9THXP","pid":1225,"client":"0","":"downstairs","session_id":"2c5c9cad-f7da-4b02-bc1a-8d480b286f4d"}
2642024-08-05T19:12:46.963Z{"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:12:45.318921877Z","hostname":"w-01J4HZ23M17JFMB0BME6Y9THXP","pid":1225,"client":"1","":"downstairs","session_id":"2c5c9cad-f7da-4b02-bc1a-8d480b286f4d"}
2652024-08-05T19:12:46.963Z{"msg":"ds_transition from WaitActive to WaitQuorum","v":0,"name":"crucible","level":30,"time":"2024-08-05T19:12:45.319190122Z","hostname":"w-01J4HZ23M17JFMB0BME6Y9THXP","pid":1225,"client":"2","":"downstairs","session_id":"2c5c9cad-f7da-4b02-bc1a-8d480b286f4d"}
2662024-08-05T19:12:46.963Z{"msg":"[2] Transition from WaitActive to WaitQuorum","v":0,"name":"crucible","level":30,"time":"2024-08-05T19:12:45.319255155Z","hostname":"w-01J4HZ23M17JFMB0BME6Y9THXP","pid":1225,"client":"2","":"downstairs","session_id":"2c5c9cad-f7da-4b02-bc1a-8d480b286f4d"}
2672024-08-05T19:12:46.963Z{"msg":"Waiting for more clients to be ready","v":0,"name":"crucible","level":30,"time":"2024-08-05T19:12:45.319303501Z","hostname":"w-01J4HZ23M17JFMB0BME6Y9THXP","pid":1225,"session_id":"2c5c9cad-f7da-4b02-bc1a-8d480b286f4d"}
2682024-08-05T19:12:46.963Z{"msg":"ds_transition from WaitActive to WaitQuorum","v":0,"name":"crucible","level":30,"time":"2024-08-05T19:12:45.319345617Z","hostname":"w-01J4HZ23M17JFMB0BME6Y9THXP","pid":1225,"client":"0","":"downstairs","session_id":"2c5c9cad-f7da-4b02-bc1a-8d480b286f4d"}
2692024-08-05T19:12:46.963Z{"msg":"[0] Transition from WaitActive to WaitQuorum","v":0,"name":"crucible","level":30,"time":"2024-08-05T19:12:45.319383123Z","hostname":"w-01J4HZ23M17JFMB0BME6Y9THXP","pid":1225,"client":"0","":"downstairs","session_id":"2c5c9cad-f7da-4b02-bc1a-8d480b286f4d"}
2702024-08-05T19:12:46.963Z{"msg":"Waiting for more clients to be ready","v":0,"name":"crucible","level":30,"time":"2024-08-05T19:12:45.319407961Z","hostname":"w-01J4HZ23M17JFMB0BME6Y9THXP","pid":1225,"session_id":"2c5c9cad-f7da-4b02-bc1a-8d480b286f4d"}
2712024-08-05T19:12:46.963Z{"msg":"ds_transition from WaitActive to WaitQuorum","v":0,"name":"crucible","level":30,"time":"2024-08-05T19:12:45.319439088Z","hostname":"w-01J4HZ23M17JFMB0BME6Y9THXP","pid":1225,"client":"1","":"downstairs","session_id":"2c5c9cad-f7da-4b02-bc1a-8d480b286f4d"}
2722024-08-05T19:12:46.963Z{"msg":"[1] Transition from WaitActive to WaitQuorum","v":0,"name":"crucible","level":30,"time":"2024-08-05T19:12:45.319473595Z","hostname":"w-01J4HZ23M17JFMB0BME6Y9THXP","pid":1225,"client":"1","":"downstairs","session_id":"2c5c9cad-f7da-4b02-bc1a-8d480b286f4d"}
2732024-08-05T19:12:46.963Z{"msg":"[0]R flush_numbers: [1674, 1674, 1674, 1674, 1674]","v":0,"name":"crucible","level":30,"time":"2024-08-05T19:12:45.319508451Z","hostname":"Wait for a query_work_queue command to finish before sending IO
2742024-08-05T19:12:46.963Zw-01J4HZ23M17JFMB0BME6Y9THXP","pid":1225,"":"downstairs","":"downstairs","session_id":"2c5c9cad-f7da-4b02-bc1a-8d480b286f4d"}
2752024-08-05T19:12:46.963Z{"msg":"[0]R generation: [31, 31, 31, 31, 31]","v":0,"name":"crucible","level":30,"time":"2024-08-05T19:12:45.319536089Z","hostname":"w-01J4HZ23M17JFMB0BME6Y9THXP","pid":1225,"":"downstairs","":"downstairs","session_id":"2c5c9cad-f7da-4b02-bc1a-8d480b286f4d"}
2762024-08-05T19:12:46.963Z{"msg":"[0]R dirty: [false, false, false, false, false]","v":0,"name":"crucible","level":30,"time":"2024-08-05T19:12:45.319574515Z","hostname":"w-01J4HZ23M17JFMB0BME6Y9THXP","pid":1225,"":"downstairs","":"downstairs","session_id":"2c5c9cad-f7da-4b02-bc1a-8d480b286f4d"}
2772024-08-05T19:12:46.963Z{"msg":"[1]R flush_numbers: [1674, 1674, 1674, 1674, 1674]","v":0,"name":"crucible","level":30,"time":"2024-08-05T19:12:45.319613281Z","hostname":"w-01J4HZ23M17JFMB0BME6Y9THXP","pid":1225,"":"downstairs","":"downstairs","session_id":"2c5c9cad-f7da-4b02-bc1a-8d480b286f4d"}
2782024-08-05T19:12:46.963Z{"msg":"[1]R generation: [31, 31, 31, 31, 31]","v":0,"name":"crucible","level":30,"time":"2024-08-05T19:12:45.319651728Z","hostname":"w-01J4HZ23M17JFMB0BME6Y9THXP","pid":1225,"":"downstairs","":"downstairs","session_id":"2c5c9cad-f7da-4b02-bc1a-8d480b286f4d"}
2792024-08-05T19:12:46.963Z{"msg":"[1]R dirty: [false, false, false, false, false]","v":0,"name":"crucible","level":30,"time":"2024-08-05T19:12:45.319690034Z","hostname":"w-01J4HZ23M17JFMB0BME6Y9THXP","pid":1225,"":"downstairs","":"downstairs","session_id":"2c5c9cad-f7da-4b02-bc1a-8d480b286f4d"}
2802024-08-05T19:12:46.963Z{"msg":"[2]R flush_numbers: [1674, 1674, 1674, 1674, 1674]","v":0,"name":"crucible","level":30,"time":"2024-08-05T19:12:45.31972996Z","hostname":"w-01J4HZ23M17JFMB0BME6Y9THXP","pid":1225,"":"downstairs","":"downstairs","session_id":"2c5c9cad-f7da-4b02-bc1a-8d480b286f4d"}
2812024-08-05T19:12:46.964Z{"msg":"[2]R generation: [31, 31, 31, 31, 31]","v":0,"name":"crucible","level":30,"time":"2024-08-05T19:12:45.319796224Z","hostname":"w-01J4HZ23M17JFMB0BME6Y9THXP","pid":1225,"":"downstairs","":"downstairs","session_id":"2c5c9cad-f7da-4b02-bc1a-8d480b286f4d"}
2822024-08-05T19:12:46.964Z{Region: es:10 ec:5 bs:4096 ts:204800 tb:50 max_io:50 or 204800
2832024-08-05T19:12:46.964Z"msg":"[2]R dirty: [false, false, false, false, false]","v":0,"name":"crucible","level":30,"time":"2024-08-05T19:12:45.319826881Z","hostname":"w-01J4HZ23M17JFMB0BME6Y9THXP","pid":1225,"":"downstairs","":"downstairs","session_id":"2c5c9cad-f7da-4b02-bc1a-8d480b286f4d"}
2842024-08-05T19:12:46.964Z{"msg":"Max found gen is 32","v":0,"name":"crucible","level":30,"time":"2024-08-05T19:12:45.319854509Z","hostname":"w-01J4HZ23M17JFMB0BME6Y9THXP","pid":1225,"":"downstairs","":"downstairs","session_id":"2c5c9cad-f7da-4b02-bc1a-8d480b286f4d"}
2852024-08-05T19:12:46.964Z{"msg":"Generation requested: 32 >= found:32","v":0,"name":"crucible","level":30,"time":"2024-08-05T19:12:45.319869107Z","hostname":"w-01J4HZ23M17JFMB0BME6Y9THXP","pid":1225,"":"downstairs","":"downstairs","session_id":"2c5c9cad-f7da-4b02-bc1a-8d480b286f4d"}
2862024-08-05T19:12:46.964Z{"msg":"Next flush: 1675","v":0,"name":"crucible","level":30,"time":"2024-08-05T19:12:45.319888555Z","hostname":"w-01J4HZ23M17JFMB0BME6Y9THXP","pid":1225,"":"downstairs","":"downstairs","session_id":"2c5c9cad-f7da-4b02-bc1a-8d480b286f4d"}
2872024-08-05T19:12:46.964Z{"msg":"All extents match","v":0,"name":"crucible","level":30,"time":"2024-08-05T19:12:45.319915763Z","hostname":"w-01J4HZ23M17JFMB0BME6Y9THXP","pid":1225,"":"downstairs","":"downstairs","session_id":"2c5c9cad-f7da-4b02-bc1a-8d480b286f4d"}
2882024-08-05T19:12:46.964Z{"msg":"No downstairs reconciliation required","v":0,"name":"crucible","level":30,"time":"2024-08-05T19:12:45.319929851Z","hostname":"w-01J4HZ23M17JFMB0BME6Y9THXP","pid":1225,"session_id":"2c5c9cad-f7da-4b02-bc1a-8d480b286f4d"}
2892024-08-05T19:12:46.964Z{"msg":"Transition from WaitQuorum to Active","v":0,"name":"crucible","level":30,"time":"2024-08-05T19:12:45.31994671Z","hostname":"w-01J4HZ23M17JFMB0BME6Y9THXP","pid":1225,"client":"0","":"downstairs","session_id":"2c5c9cad-f7da-4b02-bc1a-8d480b286f4d"}
2902024-08-05T19:12:46.964Z{"msg":"Transition from WaitQuorum to Active","v":0,"name":"crucible","level":30,"time":"2024-08-05T19:12:45.319975727Z","hostname":"w-01J4HZ23M17JFMB0BME6Y9THXP","pid":1225,"client":"1","":"downstairs","session_id":"2c5c9cad-f7da-4b02-bc1a-8d480b286f4d"}
2912024-08-05T19:12:46.964Z{"msg":"Transition from WaitQuorum to Active","v":0,"name":"crucible","level":30,"time":"2024-08-05T19:12:45.319990925Z","hostname":"w-01J4HZ23M17JFMB0BME6Y9THXP","pid":1225,"client":"2","":"downstairs","session_id":"2c5c9cad-f7da-4b02-bc1a-8d480b286f4d"}
2922024-08-05T19:12:46.964Z{"msg":"All required reconciliation work is completed","v":0,"name":"crucible","level":30,"time":"2024-08-05T19:12:45.320022982Z","hostname":"w-01J4HZ23M17JFMB0BME6Y9THXP","pid":1225,"session_id":"2c5c9cad-f7da-4b02-bc1a-8d480b286f4d"}
2932024-08-05T19:12:46.964Z{"msg":"Set Downstairs and Upstairs active after reconciliation","v":0,"name":"crucible","level":30,"time":"2024-08-05T19:12:45.320037681Z","hostname":"w-01J4HZ23M17JFMB0BME6Y9THXP","pid":1225,"session_id":"2c5c9cad-f7da-4b02-bc1a-8d480b286f4d"}
2942024-08-05T19:12:46.964Z{"msg":"d3b19879-a1eb-43b1-9e79-01ee5b4b89c0 is now active with session: 2c5c9cad-f7da-4b02-bc1a-8d480b286f4d","v":0,"name":"crucible","level":30,"time":"2024-08-05T19:12:45.320068038Z","hostname":"w-01J4HZ23M17JFMB0BME6Y9THXP","pid":1225,"session_id":"2c5c9cad-f7da-4b02-bc1a-8d480b286f4d"}
2952024-08-05T19:12:46.964Z{"msg":"Set Active after no reconciliation","v":0,"name":"crucible","level":30,"time":"2024-08-05T19:12:45.320087076Z","hostname":"w-01J4HZ23M17JFMB0BME6Y9THXP","pid":1225,"session_id":"2c5c9cad-f7da-4b02-bc1a-8d480b286f4d"}
2962024-08-05T19:12:46.964Z{"msg":"The guest has finished waiting for activation with:32","v":0,"name":"crucible","level":30,"time":"2024-08-05T19:12:45.320114034Z","hostname":"w-01J4HZ23M17JFMB0BME6Y9THXP","pid":1225}
2972024-08-05T19:12:46.964ZLoading write count information from file "/var/tmp/test_up/verify_file"
2982024-08-05T19:12:46.964ZRun Repair workload
2992024-08-05T19:12:46.964Z01/10 Write block 38 len 20480 data: 2 2 2 2 2
3002024-08-05T19:12:46.967Z02/10 Read block 0 len 4096
3012024-08-05T19:12:46.967Z03/10 Write block 21 len 36864 data: 2 2 2 2 2 2 2 2 2
3022024-08-05T19:12:46.972Z04/10 Read block 11 len 40960
3032024-08-05T19:12:46.980Z05/10 Write block 32 len 24576 data: 2 2 2 2 2 2
3042024-08-05T19:12:46.984Z06/10 Write block 1 len 28672 data: 2 2 2 2 2 2 2
3052024-08-05T19:12:46.988Z07/10 Read block 24 len 12288
3062024-08-05T19:12:46.992Z08/10 Read block 34 len 8192
3072024-08-05T19:12:46.996Z09/10 Read block 25 len 32768
3082024-08-05T19:12:47.002Z10/10 Read block 43 len 24576
3092024-08-05T19:12:47.009Z----------------------------------------------------------------
3102024-08-05T19:12:47.009Z Crucible gen:32 GIO:true work queues: Upstairs:0 downstairs:10
3112024-08-05T19:12:47.009ZStates: Active Active Active
3122024-08-05T19:12:47.009ZGW_ID ACK DSID TYPE BKS/EXT DS:0 DS:1 DS:2 REPLAY
3132024-08-05T19:12:47.009Z 1 Acked 1000 Write 5 Done Done Done false
3142024-08-05T19:12:47.009Z 2 Acked 1001 Read 1 Done Done Done false
3152024-08-05T19:12:47.009Z 3 Acked 1002 Write 9 Done Done Done false
3162024-08-05T19:12:47.009Z 4 Acked 1003 Read 10 Done Done Done false
3172024-08-05T19:12:47.009Z 5 Acked 1004 Write 6 Done Done Done false
3182024-08-05T19:12:47.009Z 6 Acked 1005 Write 7 Done Done Done false
3192024-08-05T19:12:47.009Z 7 Acked 1006 Read 3 Done Done Done false
3202024-08-05T19:12:47.009Z 8 Acked 1007 Read 2 Done Done Done false
3212024-08-05T19:12:47.009Z 9 Acked 1008 Read 8 Done Done Done false
3222024-08-05T19:12:47.009Z 10 Acked 1009 Read 6 Done Done Done false
3232024-08-05T19:12:47.009Z STATES DS:0 DS:1 DS:2 TOTAL
3242024-08-05T19:12:47.010Z New 0 0 0 0
3252024-08-05T19:12:47.010Z Sent 0 0 0 0
3262024-08-05T19:12:47.010Z Done 10 10 10 30
3272024-08-05T19:12:47.010Z Skipped 0 0 0 0
3282024-08-05T19:12:47.010Z Error 0 0 0 0
3292024-08-05T19:12:47.010ZLast Flush: 0 0 0
3302024-08-05T19:12:47.010ZDownstairs last five completed:
3312024-08-05T19:12:47.013ZUpstairs last five completed: 10 9 8 7 6
3322024-08-05T19:12:47.013Z{"msg":"Guest handle has been dropped","v":0,"name":"crucible","level":40,"time":"2024-08-05T19:12:45.369499782Z","hostname":"w-01J4HZ23M17JFMB0BME6Y9THXP","pid":1225}
3332024-08-05T19:12:47.013ZWrote out file "/var/tmp/test_up/verify_file"
3342024-08-05T19:12:47.016ZRepair part 1 passed
3352024-08-05T19:12:47.016Z
3362024-08-05T19:12:47.016ZKill the current downstairs
3372024-08-05T19:12:47.131Zrm -rf /var/tmp/test_up/8830
3382024-08-05T19:12:47.131ZNow put back the original so we have a mismatch
3392024-08-05T19:12:47.131Zmv /var/tmp/test_up/previous /var/tmp/test_up/8830
3402024-08-05T19:12:47.135ZRestart downstairs with old directory
3412024-08-05T19:12:47.193Z/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
3422024-08-05T19:12:47.212ZEXT BLOCKS GEN0 GEN1 GEN2 FL0 FL1 FL2 D0 D1 D2 DIFF
3432024-08-05T19:12:47.212Z 0 000-009 31 31 31 1674 1674 1674 T T F <---
3442024-08-05T19:12:47.212Z 1 010-019 31 31 31 1674 1674 1674 F F F
3452024-08-05T19:12:47.212Z 2 020-029 31 31 31 1674 1674 1674 T T F <---
3462024-08-05T19:12:47.212Z 3 030-039 31 31 31 1674 1674 1674 T T F <---
3472024-08-05T19:12:47.212Z 4 040-049 31 31 31 1674 1674 1674 T T F <---
3482024-08-05T19:12:47.212ZMax gen: 31, Max flush: 1674
3492024-08-05T19:12:47.215ZError: Difference in extent metadata found!
3502024-08-05T19:12:47.218Zdump test found error as expected
3512024-08-05T19:12:47.218Z
3522024-08-05T19:12:47.218Z
3532024-08-05T19:12:47.218Z/var/tmp/bins/crutest deactivate --range -g 33 -q --key VcmHj3AhaBUP95QpwvZEyXhFE9mGYrUALFaA8LQpX1c= -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
3542024-08-05T19:12:47.233Z{"msg":"Upstairs starts","v":0,"name":"crucible","level":30,"time":"2024-08-05T19:12:45.592292486Z","hostname":"w-01J4HZ23M17JFMB0BME6Y9THXP","pid":1232}
3552024-08-05T19:12:47.233Z{"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:12:45.592706847Z","hostname":"w-01J4HZ23M17JFMB0BME6Y9THXP","pid":1232}
3562024-08-05T19:12:47.233Z{"msg":"Upstairs <-> Downstairs Message Version: 11","v":0,"name":"crucible","level":30,"time":"2024-08-05T19:12:45.592745383Z","hostname":"w-01J4HZ23M17JFMB0BME6Y9THXP","pid":1232}
3572024-08-05T19:12:47.236Z{"msg":"Crucible 70aa0c1b-1aaa-4f74-b534-56df5fef483c has session id: d0693a67-a328-40d2-a0ce-4293eab3b217","v":0,"name":"crucible","level":30,"time":"2024-08-05T19:12:45.592901178Z","hostname":"w-01J4HZ23M17JFMB0BME6Y9THXP","pid":1232,"session_id":"d0693a67-a328-40d2-a0ce-4293eab3b217"}
3582024-08-05T19:12:47.236Z{"msg":"Upstairs opts: Upstairs UUID: 70aa0c1b-1aaa-4f74-b534-56df5fef483c, Targets: [127.0.0.1:8810, 127.0.0.1:8820, 127.0.0.1:8830], lossy: false, flush_timeout: None, key populated: true, cert_pem populated: false, key_pem populated: false, root_cert_pem populated: false, Control: None, read_only: false","v":0,"name":"crucible","level":30,"time":"2024-08-05T19:12:45.592981741Z","hostname":"w-01J4HZ23M17JFMB0BME6Y9THXP","pid":1232,"session_id":"d0693a67-a328-40d2-a0ce-4293eab3b217"}
3592024-08-05T19:12:47.236Z{"msg":"Crucible stats registered with UUID: 70aa0c1b-1aaa-4f74-b534-56df5fef483c","v":0,"name":"crucible","level":30,"time":"2024-08-05T19:12:45.593011268Z","hostname":"w-01J4HZ23M17JFMB0BME6Y9THXP","pid":1232,"session_id":"d0693a67-a328-40d2-a0ce-4293eab3b217"}
3602024-08-05T19:12:47.236ZCrucible runtime is spawned
3612024-08-05T19:12:47.236Z{"msg":"The guest has requested activation with gen:33","v":0,"name":"crucible","level":30,"time":"2024-08-05T19:12:45.593428528Z","hostname":"w-01J4HZ23M17JFMB0BME6Y9THXP","pid":1232}
3622024-08-05T19:12:47.236Z{"msg":"70aa0c1b-1aaa-4f74-b534-56df5fef483c active request set","v":0,"name":"crucible","level":30,"time":"2024-08-05T19:12:45.59351998Z","hostname":"w-01J4HZ23M17JFMB0BME6Y9THXP","pid":1232,"session_id":"d0693a67-a328-40d2-a0ce-4293eab3b217"}
3632024-08-05T19:12:47.236Z{"msg":"sending connect oneshot to client","v":0,"name":"crucible","level":30,"time":"2024-08-05T19:12:45.593547667Z","hostname":"w-01J4HZ23M17JFMB0BME6Y9THXP","pid":1232,"client":"0","":"downstairs","session_id":"d0693a67-a328-40d2-a0ce-4293eab3b217"}
3642024-08-05T19:12:47.236Z{"msg":"client set_active_request while in New; waiting...","v":0,"name":"crucible","level":30,"time":"2024-08-05T19:12:45.593567305Z","hostname":"w-01J4HZ23M17JFMB0BME6Y9THXP","pid":1232,"client":"0","":"downstairs","session_id":"d0693a67-a328-40d2-a0ce-4293eab3b217"}
3652024-08-05T19:12:47.236Z{"msg":"sending connect oneshot to client","v":0,"name":"crucible","level":30,"time":"2024-08-05T19:12:45.593601182Z","hostname":"w-01J4HZ23M17JFMB0BME6Y9THXP","pid":1232,"client":"1","":"downstairs","session_id":"d0693a67-a328-40d2-a0ce-4293eab3b217"}
3662024-08-05T19:12:47.236Z{"msg":"client set_active_request while in New; waiting...","v":0,"name":"crucible","level":30,"time":"2024-08-05T19:12:45.593625649Z","hostname":"w-01J4HZ23M17JFMB0BME6Y9THXP","pid":1232,"client":"1","":"downstairs","session_id":"d0693a67-a328-40d2-a0ce-4293eab3b217"}
3672024-08-05T19:12:47.236Z{"msg":"sending connect oneshot to client","v":0,"name":"crucible","level":30,"time":"2024-08-05T19:12:45.593647618Z","hostname":"w-01J4HZ23M17JFMB0BME6Y9THXP","pid":1232,"client":"2","":"downstairs","session_id":"d0693a67-a328-40d2-a0ce-4293eab3b217"}
3682024-08-05T19:12:47.236Z{"msg":"client set_active_request while in New; waiting...","v":0,"name":"crucible","level":30,"time":"2024-08-05T19:12:45.593679544Z","hostname":"w-01J4HZ23M17JFMB0BME6Y9THXP","pid":1232,"client":"2","":"downstairs","session_id":"d0693a67-a328-40d2-a0ce-4293eab3b217"}
3692024-08-05T19:12:47.236Z{"msg":"connecting to 127.0.0.1:8820","v":0,"name":"crucible","level":30,"time":"2024-08-05T19:12:45.593694113Z","hostname":"w-01J4HZ23M17JFMB0BME6Y9THXP","pid":1232,"":"io task","client":"1","":"downstairs","session_id":"d0693a67-a328-40d2-a0ce-4293eab3b217"}
3702024-08-05T19:12:47.236Z{"msg":"connecting to 127.0.0.1:8830","v":0,"name":"crucible","level":30,"time":"2024-08-05T19:12:45.593714881Z","hostname":"w-01J4HZ23M17JFMB0BME6Y9THXP","pid":1232,"":"io task","client":"2","":"downstairs","session_id":"d0693a67-a328-40d2-a0ce-4293eab3b217"}
3712024-08-05T19:12:47.236Z{"msg":"connecting to 127.0.0.1:8810","v":0,"name":"crucible","level":30,"time":"2024-08-05T19:12:45.593743968Z","hostname":"w-01J4HZ23M17JFMB0BME6Y9THXP","pid":1232,"":"io task","client":"0","":"downstairs","session_id":"d0693a67-a328-40d2-a0ce-4293eab3b217"}
3722024-08-05T19:12:47.236Z{"msg":"ds_connection connected from Ok(127.0.0.1:50525)","v":0,"name":"crucible","level":30,"time":"2024-08-05T19:12:45.593922641Z","hostname":"w-01J4HZ23M17JFMB0BME6Y9THXP","pid":1232,"":"io task","client":"1","":"downstairs","session_id":"d0693a67-a328-40d2-a0ce-4293eab3b217"}
3732024-08-05T19:12:47.236Z{"msg":"ds_connection connected from Ok(127.0.0.1:42617)","v":0,"name":"crucible","level":30,"time":"2024-08-05T19:12:45.593954788Z","hostname":"w-01J4HZ23M17JFMB0BME6Y9THXP","pid":1232,"":"io task","client":"0","":"downstairs","session_id":"d0693a67-a328-40d2-a0ce-4293eab3b217"}
3742024-08-05T19:12:47.236Z{"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:12:45.593992315Z","hostname":"w-01J4HZ23M17JFMB0BME6Y9THXP","pid":1232,"":"io task","client":"2","":"downstairs","session_id":"d0693a67-a328-40d2-a0ce-4293eab3b217"}
3752024-08-05T19:12:47.236Z{"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:12:45.594027771Z","hostname":"w-01J4HZ23M17JFMB0BME6Y9THXP","pid":1232,"":"io task","client":"2","":"downstairs","session_id":"d0693a67-a328-40d2-a0ce-4293eab3b217"}
3762024-08-05T19:12:47.236Z{"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:12:45.594063878Z","hostname":"w-01J4HZ23M17JFMB0BME6Y9THXP","pid":1232,"session_id":"d0693a67-a328-40d2-a0ce-4293eab3b217"}
3772024-08-05T19:12:47.236Z{"msg":"Gone missing, transition from New to Disconnected","v":0,"name":"crucible","level":30,"time":"2024-08-05T19:12:45.594094625Z","hostname":"w-01J4HZ23M17JFMB0BME6Y9THXP","pid":1232,"client":"2","":"downstairs","session_id":"d0693a67-a328-40d2-a0ce-4293eab3b217"}
3782024-08-05T19:12:47.237Z{"msg":"Disconnected -> New","v":0,"name":"crucible","level":30,"time":"2024-08-05T19:12:45.594119863Z","hostname":"w-01J4HZ23M17JFMB0BME6Y9THXP","pid":1232,"client":"2","":"downstairs","session_id":"d0693a67-a328-40d2-a0ce-4293eab3b217"}
3792024-08-05T19:12:47.237Z{"msg":"client task is exiting","v":0,"name":"crucible","level":30,"time":"2024-08-05T19:12:45.594333612Z","hostname":"w-01J4HZ23M17JFMB0BME6Y9THXP","pid":1232,"":"io task","client":"2","":"downstairs","session_id":"d0693a67-a328-40d2-a0ce-4293eab3b217"}
3802024-08-05T19:12:47.237Z{"msg":"ds_transition from New to WaitActive","v":0,"name":"crucible","level":30,"time":"2024-08-05T19:12:45.59477936Z","hostname":"w-01J4HZ23M17JFMB0BME6Y9THXP","pid":1232,"client":"1","":"downstairs","session_id":"d0693a67-a328-40d2-a0ce-4293eab3b217"}
3812024-08-05T19:12:47.237Z{"msg":"[1] Transition from New to WaitActive","v":0,"name":"crucible","level":30,"time":"2024-08-05T19:12:45.594814837Z","hostname":"w-01J4HZ23M17JFMB0BME6Y9THXP","pid":1232,"client":"1","":"downstairs","session_id":"d0693a67-a328-40d2-a0ce-4293eab3b217"}
3822024-08-05T19:12:47.237Z{"msg":"ds_transition from New to WaitActive","v":0,"name":"crucible","level":30,"time":"2024-08-05T19:12:45.594830765Z","hostname":"w-01J4HZ23M17JFMB0BME6Y9THXP","pid":1232,"client":"0","":"downstairs","session_id":"d0693a67-a328-40d2-a0ce-4293eab3b217"}
3832024-08-05T19:12:47.237Z{"msg":"[0] Transition from New to WaitActive","v":0,"name":"crucible","level":30,"time":"2024-08-05T19:12:45.594850443Z","hostname":"w-01J4HZ23M17JFMB0BME6Y9THXP","pid":1232,"client":"0","":"downstairs","session_id":"d0693a67-a328-40d2-a0ce-4293eab3b217"}
3842024-08-05T19:12:47.237Z{"msg":"downstairs client at Some(127.0.0.1:8810) has region UUID 12345678-0000-0000-0000-000000008810","v":0,"name":"crucible","level":30,"time":"2024-08-05T19:12:45.595450266Z","hostname":"w-01J4HZ23M17JFMB0BME6Y9THXP","pid":1232,"client":"0","":"downstairs","session_id":"d0693a67-a328-40d2-a0ce-4293eab3b217"}
3852024-08-05T19:12:47.237Z{"msg":"downstairs client at Some(127.0.0.1:8820) has region UUID 12345678-0000-0000-0000-000000008820","v":0,"name":"crucible","level":30,"time":"2024-08-05T19:12:45.595498682Z","hostname":"w-01J4HZ23M17JFMB0BME6Y9THXP","pid":1232,"client":"1","":"downstairs","session_id":"d0693a67-a328-40d2-a0ce-4293eab3b217"}
3862024-08-05T19:12:47.237Z{"msg":"ds_transition from WaitActive to WaitQuorum","v":0,"name":"crucible","level":30,"time":"2024-08-05T19:12:45.595855298Z","hostname":"w-01J4HZ23M17JFMB0BME6Y9THXP","pid":1232,"client":"1","":"downstairs","session_id":"d0693a67-a328-40d2-a0ce-4293eab3b217"}
3872024-08-05T19:12:47.237Z{"msg":"[1] Transition from WaitActive to WaitQuorum","v":0,"name":"crucible","level":30,"time":"2024-08-05T19:12:45.595896214Z","hostname":"w-01J4HZ23M17JFMB0BME6Y9THXP","pid":1232,"client":"1","":"downstairs","session_id":"d0693a67-a328-40d2-a0ce-4293eab3b217"}
3882024-08-05T19:12:47.237Z{"msg":"Waiting for more clients to be ready","v":0,"name":"crucible","level":30,"time":"2024-08-05T19:12:45.595921171Z","hostname":"w-01J4HZ23M17JFMB0BME6Y9THXP","pid":1232,"session_id":"d0693a67-a328-40d2-a0ce-4293eab3b217"}
3892024-08-05T19:12:47.237Z{"msg":"ds_transition from WaitActive to WaitQuorum","v":0,"name":"crucible","level":30,"time":"2024-08-05T19:12:45.595953568Z","hostname":"w-01J4HZ23M17JFMB0BME6Y9THXP","pid":1232,"client":"0","":"downstairs","session_id":"d0693a67-a328-40d2-a0ce-4293eab3b217"}
3902024-08-05T19:12:47.237Z{"msg":"[0] Transition from WaitActive to WaitQuorum","v":0,"name":"crucible","level":30,"time":"2024-08-05T19:12:45.595973117Z","hostname":"w-01J4HZ23M17JFMB0BME6Y9THXP","pid":1232,"client":"0","":"downstairs","session_id":"d0693a67-a328-40d2-a0ce-4293eab3b217"}
3912024-08-05T19:12:47.240Z{"msg":"Waiting for more clients to be ready","v":0,"name":"crucible","level":30,"time":"2024-08-05T19:12:45.596005294Z","hostname":"w-01J4HZ23M17JFMB0BME6Y9THXP","pid":1232,"session_id":"d0693a67-a328-40d2-a0ce-4293eab3b217"}
3922024-08-05T19:12:57.237Z{"msg":"connecting to 127.0.0.1:8830","v":0,"name":"crucible","level":30,"time":"2024-08-05T19:12:55.595973027Z","hostname":"w-01J4HZ23M17JFMB0BME6Y9THXP","pid":1232,"":"io task","client":"2","":"downstairs","session_id":"d0693a67-a328-40d2-a0ce-4293eab3b217"}
3932024-08-05T19:12:57.237Z{"msg":"ds_connection connected from Ok(127.0.0.1:38148)","v":0,"name":"crucible","level":30,"time":"2024-08-05T19:12:55.596070007Z","hostname":"w-01J4HZ23M17JFMB0BME6Y9THXP","pid":1232,"":"io task","client":"2","":"downstairs","session_id":"d0693a67-a328-40d2-a0ce-4293eab3b217"}
3942024-08-05T19:12:57.242Z{"msg":"ds_transition from New to WaitActive","v":0,"name":"crucible","level":30,"time":"2024-08-05T19:12:55.59699308Z","hostname":"w-01J4HZ23M17JFMB0BME6Y9THXP","pid":1232,"client":"2","":"downstairs","session_id":"d0693a67-a328-40d2-a0ce-4293eab3b217"}
3952024-08-05T19:12:57.242Z{"msg":"[2] Transition from New to WaitActive","v":0,"name":"crucible","level":30,"time":"2024-08-05T19:12:55.597023287Z","hostname":"w-01J4HZ23M17JFMB0BME6Y9THXP","pid":1232,"client":"2","":"downstairs","session_id":"d0693a67-a328-40d2-a0ce-4293eab3b217"}
3962024-08-05T19:12:57.243Z{"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:12:55.597580674Z","hostname":"w-01J4HZ23M17JFMB0BME6Y9THXP","pid":1232,"client":"2","":"downstairs","session_id":"d0693a67-a328-40d2-a0ce-4293eab3b217"}
3972024-08-05T19:12:57.243Z{"msg":"ds_transition from WaitActive to WaitQuorum","v":0,"name":"crucible","level":30,"time":"2024-08-05T19:12:55.597979636Z","hostname":"w-01J4HZ23M17JFMB0BME6Y9THXP","pid":1232,"client":"2","":"downstairs","session_id":"d0693a67-a328-40d2-a0ce-4293eab3b217"}
3982024-08-05T19:12:57.243Z{"msg":"[2] Transition from WaitActive to WaitQuorum","v":0,"name":"crucible","level":30,"time":"2024-08-05T19:12:55.598018362Z","hostname":"w-01J4HZ23M17JFMB0BME6Y9THXP","pid":1232,"client":"2","":"downstairs","session_id":"d0693a67-a328-40d2-a0ce-4293eab3b217"}
3992024-08-05T19:12:57.243Z{"msg":"[0]R flush_numbers: [1674, 1674, 1674, 1674, 1674]","v":0,"name":"crucible","level":30,"time":"2024-08-05T19:12:55.598035311Z","hostname":"w-01J4HZ23M17JFMB0BME6Y9THXP","pid":1232,"":"downstairs","":"downstairs","session_id":"d0693a67-a328-40d2-a0ce-4293eab3b217"}
4002024-08-05T19:12:57.243Z{"msg":"[0]R generation: [31, 31, 31, 31, 31]","v":0,"name":"crucible","level":30,"time":"2024-08-05T19:12:55.59804995Z","hostname":"w-01J4HZ23M17JFMB0BME6Y9THXP","pid":1232,"":"downstairs","":"downstairs","session_id":"d0693a67-a328-40d2-a0ce-4293eab3b217"}
4012024-08-05T19:12:57.243Z{"msg":"[0]R dirty: [true, false, true, true, true]","v":0,"name":"crucible","level":30,"time":"2024-08-05T19:12:55.598063738Z","hostname":"w-01J4HZ23M17JFMB0BME6Y9THXP","pid":1232,"":"downstairs","":"downstairs","session_id":"d0693a67-a328-40d2-a0ce-4293eab3b217"}
4022024-08-05T19:12:57.243Z{"msg":"[1]R flush_numbers: [1674, 1674, 1674, 1674, 1674]","v":0,"name":"crucible","level":30,"time":"2024-08-05T19:12:55.598077747Z","hostname":"w-01J4HZ23M17JFMB0BME6Y9THXP","pid":1232,"":"downstairs","":"downstairs","session_id":"d0693a67-a328-40d2-a0ce-4293eab3b217"}
4032024-08-05T19:12:57.243Z{"msg":"[1]R generation: [31, 31, 31, 31, 31]","v":0,"name":"crucible","level":30,"time":"2024-08-05T19:12:55.598099235Z","hostname":"w-01J4HZ23M17JFMB0BME6Y9THXP","pid":1232,"":"downstairs","":"downstairs","session_id":"d0693a67-a328-40d2-a0ce-4293eab3b217"}
4042024-08-05T19:12:57.243Z{"msg":"[1]R dirty: [true, false, true, true, true]","v":0,"name":"crucible","level":30,"time":"2024-08-05T19:12:55.598113113Z","hostname":"w-01J4HZ23M17JFMB0BME6Y9THXP","pid":1232,"":"downstairs","":"downstairs","session_id":"d0693a67-a328-40d2-a0ce-4293eab3b217"}
4052024-08-05T19:12:57.243Z{"msg":"[2]R flush_numbers: [1674, 1674, 1674, 1674, 1674]","v":0,"name":"crucible","level":30,"time":"2024-08-05T19:12:55.598133871Z","hostname":"w-01J4HZ23M17JFMB0BME6Y9THXP","pid":1232,"":"downstairs","":"downstairs","session_id":"d0693a67-a328-40d2-a0ce-4293eab3b217"}
4062024-08-05T19:12:57.243Z{"msg":"[2]R generation: [31, 31, 31, 31, 31]","v":0,"name":"crucible","level":30,"time":"2024-08-05T19:12:55.59814762Z","hostname":"w-01J4HZ23M17JFMB0BME6Y9THXP","pid":1232,"":"downstairs","":"downstairs","session_id":"d0693a67-a328-40d2-a0ce-4293eab3b217"}
4072024-08-05T19:12:57.243Z{"msg":"[2]R dirty: [false, false, false, false, false]","v":0,"name":"crucible","level":30,"time":"2024-08-05T19:12:55.598167948Z","hostname":"w-01J4HZ23M17JFMB0BME6Y9THXP","pid":1232,"":"downstairs","":"downstairs","session_id":"d0693a67-a328-40d2-a0ce-4293eab3b217"}
4082024-08-05T19:12:57.243Z{"msg":"Max found gen is 32","v":0,"name":"crucible","level":30,"time":"2024-08-05T19:12:55.598181217Z","hostname":"w-01J4HZ23M17JFMB0BME6Y9THXP","pid":1232,"":"downstairs","":"downstairs","session_id":"d0693a67-a328-40d2-a0ce-4293eab3b217"}
4092024-08-05T19:12:57.243Z{"msg":"Generation requested: 33 >= found:32","v":0,"name":"crucible","level":30,"time":"2024-08-05T19:12:55.598201125Z","hostname":"w-01J4HZ23M17JFMB0BME6Y9THXP","pid":1232,"":"downstairs","":"downstairs","session_id":"d0693a67-a328-40d2-a0ce-4293eab3b217"}
4102024-08-05T19:12:57.243Z{"msg":"Next flush: 1675","v":0,"name":"crucible","level":30,"time":"2024-08-05T19:12:55.598214304Z","hostname":"w-01J4HZ23M17JFMB0BME6Y9THXP","pid":1232,"":"downstairs","":"downstairs","session_id":"d0693a67-a328-40d2-a0ce-4293eab3b217"}
4112024-08-05T19:12:57.243Z{"msg":"Extents 0 dirty","v":0,"name":"crucible","level":30,"time":"2024-08-05T19:12:55.598234132Z","hostname":"w-01J4HZ23M17JFMB0BME6Y9THXP","pid":1232,"":"mend","":"downstairs","":"downstairs","session_id":"d0693a67-a328-40d2-a0ce-4293eab3b217"}
4122024-08-05T19:12:57.243Z{"msg":"First source client ID for extent 0","v":0,"name":"crucible","level":30,"time":"2024-08-05T19:12:55.598247831Z","hostname":"w-01J4HZ23M17JFMB0BME6Y9THXP","pid":1232,"mrl":"dirty","":"mend","":"downstairs","":"downstairs","session_id":"d0693a67-a328-40d2-a0ce-4293eab3b217"}
4132024-08-05T19:12:57.243Z{"msg":"extent:0 gens: 31 31 31","v":0,"name":"crucible","level":30,"time":"2024-08-05T19:12:55.598269338Z","hostname":"w-01J4HZ23M17JFMB0BME6Y9THXP","pid":1232,"mrl":"dirty","":"mend","":"downstairs","":"downstairs","session_id":"d0693a67-a328-40d2-a0ce-4293eab3b217"}
4142024-08-05T19:12:57.243Z{"msg":"extent:0 flush: 1674 1674 1674 scs: [ClientId(0), ClientId(1), ClientId(2)]","v":0,"name":"crucible","level":30,"time":"2024-08-05T19:12:55.598284497Z","hostname":"w-01J4HZ23M17JFMB0BME6Y9THXP","pid":1232,"mrl":"dirty","":"mend","":"downstairs","":"downstairs","session_id":"d0693a67-a328-40d2-a0ce-4293eab3b217"}
4152024-08-05T19:12:57.243Z{"msg":"max_flush now has: [ClientId(0), ClientId(1), ClientId(2)]","v":0,"name":"crucible","level":30,"time":"2024-08-05T19:12:55.598306795Z","hostname":"w-01J4HZ23M17JFMB0BME6Y9THXP","pid":1232,"mrl":"dirty","":"mend","":"downstairs","":"downstairs","session_id":"d0693a67-a328-40d2-a0ce-4293eab3b217"}
4162024-08-05T19:12:57.243Z{"msg":"extent:0 dirty: true true false","v":0,"name":"crucible","level":30,"time":"2024-08-05T19:12:55.598321624Z","hostname":"w-01J4HZ23M17JFMB0BME6Y9THXP","pid":1232,"mrl":"dirty","":"mend","":"downstairs","":"downstairs","session_id":"d0693a67-a328-40d2-a0ce-4293eab3b217"}
4172024-08-05T19:12:57.243Z{"msg":"find dest for source 0 for extent at index 0","v":0,"name":"crucible","level":30,"time":"2024-08-05T19:12:55.598342922Z","hostname":"w-01J4HZ23M17JFMB0BME6Y9THXP","pid":1232,"mrl":"dirty","":"mend","":"downstairs","":"downstairs","session_id":"d0693a67-a328-40d2-a0ce-4293eab3b217"}
4182024-08-05T19:12:57.243Z{"msg":"source 0, add dest 1 source flush","v":0,"name":"crucible","level":30,"time":"2024-08-05T19:12:55.59835727Z","hostname":"w-01J4HZ23M17JFMB0BME6Y9THXP","pid":1232,"mrl":"dirty","":"mend","":"downstairs","":"downstairs","session_id":"d0693a67-a328-40d2-a0ce-4293eab3b217"}
4192024-08-05T19:12:57.243Z{"msg":"source 0, add dest 2 source flush","v":0,"name":"crucible","level":30,"time":"2024-08-05T19:12:55.598378098Z","hostname":"w-01J4HZ23M17JFMB0BME6Y9THXP","pid":1232,"mrl":"dirty","":"mend","":"downstairs","":"downstairs","session_id":"d0693a67-a328-40d2-a0ce-4293eab3b217"}
4202024-08-05T19:12:57.243Z{"msg":"Extents 2 dirty","v":0,"name":"crucible","level":30,"time":"2024-08-05T19:12:55.598392847Z","hostname":"w-01J4HZ23M17JFMB0BME6Y9THXP","pid":1232,"":"mend","":"downstairs","":"downstairs","session_id":"d0693a67-a328-40d2-a0ce-4293eab3b217"}
4212024-08-05T19:12:57.243Z{"msg":"First source client ID for extent 2","v":0,"name":"crucible","level":30,"time":"2024-08-05T19:12:55.598406885Z","hostname":"w-01J4HZ23M17JFMB0BME6Y9THXP","pid":1232,"mrl":"dirty","":"mend","":"downstairs","":"downstairs","session_id":"d0693a67-a328-40d2-a0ce-4293eab3b217"}
4222024-08-05T19:12:57.243Z{"msg":"extent:2 gens: 31 31 31","v":0,"name":"crucible","level":30,"time":"2024-08-05T19:12:55.598420714Z","hostname":"w-01J4HZ23M17JFMB0BME6Y9THXP","pid":1232,"mrl":"dirty","":"mend","":"downstairs","":"downstairs","session_id":"d0693a67-a328-40d2-a0ce-4293eab3b217"}
4232024-08-05T19:12:57.243Z{"msg":"extent:2 flush: 1674 1674 1674 scs: [ClientId(0), ClientId(1), ClientId(2)]","v":0,"name":"crucible","level":30,"time":"2024-08-05T19:12:55.598442312Z","hostname":"w-01J4HZ23M17JFMB0BME6Y9THXP","pid":1232,"mrl":"dirty","":"mend","":"downstairs","":"downstairs","session_id":"d0693a67-a328-40d2-a0ce-4293eab3b217"}
4242024-08-05T19:12:57.243Z{"msg":"max_flush now has: [ClientId(0), ClientId(1), ClientId(2)]","v":0,"name":"crucible","level":30,"time":"2024-08-05T19:12:55.598456851Z","hostname":"w-01J4HZ23M17JFMB0BME6Y9THXP","pid":1232,"mrl":"dirty","":"mend","":"downstairs","":"downstairs","session_id":"d0693a67-a328-40d2-a0ce-4293eab3b217"}
4252024-08-05T19:12:57.243Z{"msg":"extent:2 dirty: true true false","v":0,"name":"crucible","level":30,"time":"2024-08-05T19:12:55.598471019Z","hostname":"w-01J4HZ23M17JFMB0BME6Y9THXP","pid":1232,"mrl":"dirty","":"mend","":"downstairs","":"downstairs","session_id":"d0693a67-a328-40d2-a0ce-4293eab3b217"}
4262024-08-05T19:12:57.243Z{"msg":"find dest for source 0 for extent at index 2","v":0,"name":"crucible","level":30,"time":"2024-08-05T19:12:55.598491928Z","hostname":"w-01J4HZ23M17JFMB0BME6Y9THXP","pid":1232,"mrl":"dirty","":"mend","":"downstairs","":"downstairs","session_id":"d0693a67-a328-40d2-a0ce-4293eab3b217"}
4272024-08-05T19:12:57.243Z{"msg":"source 0, add dest 1 source flush","v":0,"name":"crucible","level":30,"time":"2024-08-05T19:12:55.598506226Z","hostname":"w-01J4HZ23M17JFMB0BME6Y9THXP","pid":1232,"mrl":"dirty","":"mend","":"downstairs","":"downstairs","session_id":"d0693a67-a328-40d2-a0ce-4293eab3b217"}
4282024-08-05T19:12:57.243Z{"msg":"source 0, add dest 2 source flush","v":0,"name":"crucible","level":30,"time":"2024-08-05T19:12:55.598520325Z","hostname":"w-01J4HZ23M17JFMB0BME6Y9THXP","pid":1232,"mrl":"dirty","":"mend","":"downstairs","":"downstairs","session_id":"d0693a67-a328-40d2-a0ce-4293eab3b217"}
4292024-08-05T19:12:57.243Z{"msg":"Extents 3 dirty","v":0,"name":"crucible","level":30,"time":"2024-08-05T19:12:55.598540783Z","hostname":"w-01J4HZ23M17JFMB0BME6Y9THXP","pid":1232,"":"mend","":"downstairs","":"downstairs","session_id":"d0693a67-a328-40d2-a0ce-4293eab3b217"}
4302024-08-05T19:12:57.243Z{"msg":"First source client ID for extent 3","v":0,"name":"crucible","level":30,"time":"2024-08-05T19:12:55.598554311Z","hostname":"w-01J4HZ23M17JFMB0BME6Y9THXP","pid":1232,"mrl":"dirty","":"mend","":"downstairs","":"downstairs","session_id":"d0693a67-a328-40d2-a0ce-4293eab3b217"}
4312024-08-05T19:12:57.243Z{"msg":"extent:3 gens: 31 31 31","v":0,"name":"crucible","level":30,"time":"2024-08-05T19:12:55.59857636Z","hostname":"w-01J4HZ23M17JFMB0BME6Y9THXP","pid":1232,"mrl":"dirty","":"mend","":"downstairs","":"downstairs","session_id":"d0693a67-a328-40d2-a0ce-4293eab3b217"}
4322024-08-05T19:12:57.243Z{"msg":"extent:3 flush: 1674 1674 1674 scs: [ClientId(0), ClientId(1), ClientId(2)]","v":0,"name":"crucible","level":30,"time":"2024-08-05T19:12:55.598591128Z","hostname":"w-01J4HZ23M17JFMB0BME6Y9THXP","pid":1232,"mrl":"dirty","":"mend","":"downstairs","":"downstairs","session_id":"d0693a67-a328-40d2-a0ce-4293eab3b217"}
4332024-08-05T19:12:57.243Z{"msg":"max_flush now has: [ClientId(0), ClientId(1), ClientId(2)]","v":0,"name":"crucible","level":30,"time":"2024-08-05T19:12:55.598605247Z","hostname":"w-01J4HZ23M17JFMB0BME6Y9THXP","pid":1232,"mrl":"dirty","":"mend","":"downstairs","":"downstairs","session_id":"d0693a67-a328-40d2-a0ce-4293eab3b217"}
4342024-08-05T19:12:57.244Z{"msg":"extent:3 dirty: true true false","v":0,"name":"crucible","level":30,"time":"2024-08-05T19:12:55.598626405Z","hostname":"w-01J4HZ23M17JFMB0BME6Y9THXP","pid":1232,"mrl":"dirty","":"mend","":"downstairs","":"downstairs","session_id":"d0693a67-a328-40d2-a0ce-4293eab3b217"}
4352024-08-05T19:12:57.244Z{"msg":"find dest for source 0 for extent at index 3","v":0,"name":"crucible","level":30,"time":"2024-08-05T19:12:55.598650022Z","hostname":"w-01J4HZ23M17JFMB0BME6Y9THXP","pid":1232,"mrl":"dirty","":"mend","":"downstairs","":"downstairs","session_id":"d0693a67-a328-40d2-a0ce-4293eab3b217"}
4362024-08-05T19:12:57.244Z{"msg":"source 0, add dest 1 source flush","v":0,"name":"crucible","level":30,"time":"2024-08-05T19:12:55.598683599Z","hostname":"w-01J4HZ23M17JFMB0BME6Y9THXP","pid":1232,"mrl":"dirty","":"mend","":"downstairs","":"downstairs","session_id":"d0693a67-a328-40d2-a0ce-4293eab3b217"}
4372024-08-05T19:12:57.244Z{"msg":"source 0, add dest 2 source flush","v":0,"name":"crucible","level":30,"time":"2024-08-05T19:12:55.598714396Z","hostname":"w-01J4HZ23M17JFMB0BME6Y9THXP","pid":1232,"mrl":"dirty","":"mend","":"downstairs","":"downstairs","session_id":"d0693a67-a328-40d2-a0ce-4293eab3b217"}
4382024-08-05T19:12:57.244Z{"msg":"Extents 4 dirty","v":0,"name":"crucible","level":30,"time":"2024-08-05T19:12:55.598729425Z","hostname":"w-01J4HZ23M17JFMB0BME6Y9THXP","pid":1232,"":"mend","":"downstairs","":"downstairs","session_id":"d0693a67-a328-40d2-a0ce-4293eab3b217"}
4392024-08-05T19:12:57.244Z{"msg":"First source client ID for extent 4","v":0,"name":"crucible","level":30,"time":"2024-08-05T19:12:55.598743124Z","hostname":"w-01J4HZ23M17JFMB0BME6Y9THXP","pid":1232,"mrl":"dirty","":"mend","":"downstairs","":"downstairs","session_id":"d0693a67-a328-40d2-a0ce-4293eab3b217"}
4402024-08-05T19:12:57.244Z{"msg":"extent:4 gens: 31 31 31","v":0,"name":"crucible","level":30,"time":"2024-08-05T19:12:55.598757052Z","hostname":"w-01J4HZ23M17JFMB0BME6Y9THXP","pid":1232,"mrl":"dirty","":"mend","":"downstairs","":"downstairs","session_id":"d0693a67-a328-40d2-a0ce-4293eab3b217"}
4412024-08-05T19:12:57.244Z{"msg":"extent:4 flush: 1674 1674 1674 scs: [ClientId(0), ClientId(1), ClientId(2)]","v":0,"name":"crucible","level":30,"time":"2024-08-05T19:12:55.59877844Z","hostname":"w-01J4HZ23M17JFMB0BME6Y9THXP","pid":1232,"mrl":"dirty","":"mend","":"downstairs","":"downstairs","session_id":"d0693a67-a328-40d2-a0ce-4293eab3b217"}
4422024-08-05T19:12:57.244Z{"msg":"max_flush now has: [ClientId(0), ClientId(1), ClientId(2)]","v":0,"name":"crucible","level":30,"time":"2024-08-05T19:12:55.598793359Z","hostname":"w-01J4HZ23M17JFMB0BME6Y9THXP","pid":1232,"mrl":"dirty","":"mend","":"downstairs","":"downstairs","session_id":"d0693a67-a328-40d2-a0ce-4293eab3b217"}
4432024-08-05T19:12:57.244Z{"msg":"extent:4 dirty: true true false","v":0,"name":"crucible","level":30,"time":"2024-08-05T19:12:55.598814127Z","hostname":"w-01J4HZ23M17JFMB0BME6Y9THXP","pid":1232,"mrl":"dirty","":"mend","":"downstairs","":"downstairs","session_id":"d0693a67-a328-40d2-a0ce-4293eab3b217"}
4442024-08-05T19:12:57.244Z{"msg":"find dest for source 0 for extent at index 4","v":0,"name":"crucible","level":30,"time":"2024-08-05T19:12:55.598828996Z","hostname":"w-01J4HZ23M17JFMB0BME6Y9THXP","pid":1232,"mrl":"dirty","":"mend","":"downstairs","":"downstairs","session_id":"d0693a67-a328-40d2-a0ce-4293eab3b217"}
4452024-08-05T19:12:57.244Z{"msg":"source 0, add dest 1 source flush","v":0,"name":"crucible","level":30,"time":"2024-08-05T19:12:55.598849543Z","hostname":"w-01J4HZ23M17JFMB0BME6Y9THXP","pid":1232,"mrl":"dirty","":"mend","":"downstairs","":"downstairs","session_id":"d0693a67-a328-40d2-a0ce-4293eab3b217"}
4462024-08-05T19:12:57.244Z{"msg":"source 0, add dest 2 source flush","v":0,"name":"crucible","level":30,"time":"2024-08-05T19:12:55.598864182Z","hostname":"w-01J4HZ23M17JFMB0BME6Y9THXP","pid":1232,"mrl":"dirty","":"mend","":"downstairs","":"downstairs","session_id":"d0693a67-a328-40d2-a0ce-4293eab3b217"}
4472024-08-05T19:12:57.244Z{"msg":"Transition from WaitQuorum to Reconcile","v":0,"name":"crucible","level":30,"time":"2024-08-05T19:12:55.59888534Z","hostname":"w-01J4HZ23M17JFMB0BME6Y9THXP","pid":1232,"client":"0","":"downstairs","session_id":"d0693a67-a328-40d2-a0ce-4293eab3b217"}
4482024-08-05T19:12:57.244Z{"msg":"Transition from WaitQuorum to Reconcile","v":0,"name":"crucible","level":30,"time":"2024-08-05T19:12:55.598898959Z","hostname":"w-01J4HZ23M17JFMB0BME6Y9THXP","pid":1232,"client":"1","":"downstairs","session_id":"d0693a67-a328-40d2-a0ce-4293eab3b217"}
4492024-08-05T19:12:57.244Z{"msg":"Transition from WaitQuorum to Reconcile","v":0,"name":"crucible","level":30,"time":"2024-08-05T19:12:55.598918607Z","hostname":"w-01J4HZ23M17JFMB0BME6Y9THXP","pid":1232,"client":"2","":"downstairs","session_id":"d0693a67-a328-40d2-a0ce-4293eab3b217"}
4502024-08-05T19:12:57.244Z{"msg":"starting reconciliation 999e88d0-a947-41c2-812d-1487c7417e80: found 4 extents that need repair","v":0,"name":"crucible","level":30,"time":"2024-08-05T19:12:55.598932875Z","hostname":"w-01J4HZ23M17JFMB0BME6Y9THXP","pid":1232,"":"downstairs","":"downstairs","session_id":"d0693a67-a328-40d2-a0ce-4293eab3b217"}
4512024-08-05T19:12:57.244Z{"msg":"Full repair list: {ExtentId(4): ExtentFix { source: ClientId(0), dest: [ClientId(1), ClientId(2)] }, ExtentId(2): ExtentFix { source: ClientId(0), dest: [ClientId(1), ClientId(2)] }, ExtentId(0): ExtentFix { source: ClientId(0), dest: [ClientId(1), ClientId(2)] }, ExtentId(3): ExtentFix { source: ClientId(0), dest: [ClientId(1), ClientId(2)] }}","v":0,"name":"crucible","level":30,"time":"2024-08-05T19:12:55.598957213Z","hostname":"w-01J4HZ23M17JFMB0BME6Y9THXP","pid":1232,"":"downstairs","":"downstairs","session_id":"d0693a67-a328-40d2-a0ce-4293eab3b217"}
4522024-08-05T19:12:57.244Z{"msg":"Task list: [ReconcileIO { id: ReconciliationId(0), op: ExtentFlush { repair_id: ReconciliationId(0), extent_id: ExtentId(4), client_id: ClientId(0), flush_number: 1675, gen_number: 32 }, state: ClientData([New, New, New]) }, ReconcileIO { id: ReconciliationId(1), op: ExtentClose { repair_id: ReconciliationId(1), extent_id: ExtentId(4) }, state: ClientData([New, New, New]) }, ReconcileIO { id: ReconciliationId(2), op: ExtentRepair { repair_id: ReconciliationId(2), extent_id: ExtentId(4), source_client_id: ClientId(0), source_repair_address: 0.0.0.0:12810, dest_clients: [ClientId(1), ClientId(2)] }, state: ClientData([New, New, New]) }, ReconcileIO { id: ReconciliationId(3), op: ExtentReopen { repair_id: ReconciliationId(3), extent_id: ExtentId(4) }, 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: 1675, gen_number: 32 }, state: ClientData([New, New, New]) }, ReconcileIO { id: ReconciliationId(5), op: ExtentClose { repair_id: ReconciliationId(5), extent_id: ExtentId(2) }, state: ClientData([New, New, New]) }, ReconcileIO { id: ReconciliationId(6), op: ExtentRepair { repair_id: ReconciliationId(6), extent_id: ExtentId(2), source_client_id: ClientId(0), source_repair_address: 0.0.0.0:12810, dest_clients: [ClientId(1), ClientId(2)] }, state: ClientData([New, New, New]) }, ReconcileIO { id: ReconciliationId(7), op: ExtentReopen { repair_id: ReconciliationId(7), extent_id: ExtentId(2) }, state: ClientData([New, New, New]) }, ReconcileIO { id: ReconciliationId(8), op: ExtentFlush { repair_id: ReconciliationId(8), extent_id: ExtentId(0), client_id: ClientId(0), flush_number: 1675, gen_number: 32 }, state: ClientData([New, New, New]) }, ReconcileIO { id: ReconciliationId(9), op: ExtentClose { repair_id: ReconciliationId(9), extent_id: ExtentId(0) }, state: ClientData([New, New, New]) }, ReconcileIO { id: ReconciliationId(10), op: ExtentRepair { repair_id: ReconciliationId(10), 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(11), op: ExtentReopen { repair_id: ReconciliationId(11), extent_id: ExtentId(0) }, state: ClientData([New, New, New]) }, ReconcileIO { id: ReconciliationId(12), op: ExtentFlush { repair_id: ReconciliationId(12), extent_id: ExtentId(3), client_id: ClientId(0), flush_number: 1675, gen_number: 32 }, state: ClientData([New, New, New]) }, ReconcileIO { id: ReconciliationId(13), op: ExtentClose { repair_id: ReconciliationId(13), extent_id: ExtentId(3) }, state: ClientData([New, New, New]) }, ReconcileIO { id: ReconciliationId(14), op: ExtentRepair { repair_id: ReconciliationId(14), extent_id: ExtentId(3), source_client_id: ClientId(0), source_repair_address: 0.0.0.0:12810, dest_clients: [ClientId(1), ClientId(2)] }, state: ClientData([New, New, New]) }, ReconcileIO { id: ReconciliationId(15), op: ExtentReopen { repair_id: ReconciliationId(15), extent_id: ExtentId(3) }, state: ClientData([New, New, New]) }]","v":0,"name":"crucible","level":30,"time":"2024-08-05T19:12:55.599049364Z","hostname":"w-01J4HZ23M17JFMB0BME6Y9THXP","pid":1232,"":"downstairs","":"downstairs","session_id":"d0693a67-a328-40d2-a0ce-4293eab3b217"}
4532024-08-05T19:12:57.247Z{"msg":"sending reconcile request ReconciliationId(2)","v":0,"name":"crucible","level":30,"time":"2024-08-05T19:12:55.600020862Z","hostname":"w-01J4HZ23M17JFMB0BME6Y9THXP","pid":1232,"client":"1","":"downstairs","session_id":"d0693a67-a328-40d2-a0ce-4293eab3b217"}
4542024-08-05T19:12:57.248Z{"msg":"sending reconcile request ReconciliationId(2)","v":0,"name":"crucible","level":30,"time":"2024-08-05T19:12:55.600059028Z","hostname":"w-01J4HZ23M17JFMB0BME6Y9THXP","pid":1232,"client":"2","":"downstairs","session_id":"d0693a67-a328-40d2-a0ce-4293eab3b217"}
4552024-08-05T19:12:57.258Z{"msg":"sending reconcile request ReconciliationId(6)","v":0,"name":"crucible","level":30,"time":"2024-08-05T19:12:55.616549622Z","hostname":"w-01J4HZ23M17JFMB0BME6Y9THXP","pid":1232,"client":"1","":"downstairs","session_id":"d0693a67-a328-40d2-a0ce-4293eab3b217"}
4562024-08-05T19:12:57.258Z{"msg":"sending reconcile request ReconciliationId(6)","v":0,"name":"crucible","level":30,"time":"2024-08-05T19:12:55.616606107Z","hostname":"w-01J4HZ23M17JFMB0BME6Y9THXP","pid":1232,"client":"2","":"downstairs","session_id":"d0693a67-a328-40d2-a0ce-4293eab3b217"}
4572024-08-05T19:12:57.270Z{"msg":"sending reconcile request ReconciliationId(10)","v":0,"name":"crucible","level":30,"time":"2024-08-05T19:12:55.628808747Z","hostname":"w-01J4HZ23M17JFMB0BME6Y9THXP","pid":1232,"client":"1","":"downstairs","session_id":"d0693a67-a328-40d2-a0ce-4293eab3b217"}
4582024-08-05T19:12:57.270Z{"msg":"sending reconcile request ReconciliationId(10)","v":0,"name":"crucible","level":30,"time":"2024-08-05T19:12:55.628870082Z","hostname":"w-01J4HZ23M17JFMB0BME6Y9THXP","pid":1232,"client":"2","":"downstairs","session_id":"d0693a67-a328-40d2-a0ce-4293eab3b217"}
4592024-08-05T19:12:57.280Z{"msg":"sending reconcile request ReconciliationId(14)","v":0,"name":"crucible","level":30,"time":"2024-08-05T19:12:55.639051554Z","hostname":"w-01J4HZ23M17JFMB0BME6Y9THXP","pid":1232,"client":"1","":"downstairs","session_id":"d0693a67-a328-40d2-a0ce-4293eab3b217"}
4602024-08-05T19:12:57.280Z{"msg":"sending reconcile request ReconciliationId(14)","v":0,"name":"crucible","level":30,"time":"2024-08-05T19:12:55.639109229Z","hostname":"w-01J4HZ23M17JFMB0BME6Y9THXP","pid":1232,"client":"2","":"downstairs","session_id":"d0693a67-a328-40d2-a0ce-4293eab3b217"}
4612024-08-05T19:12:57.290Z{"msg":"done with reconciliation","v":0,"name":"crucible","level":30,"time":"2024-08-05T19:12:55.648696178Z","hostname":"w-01J4HZ23M17JFMB0BME6Y9THXP","pid":1232,"":"downstairs","":"downstairs","session_id":"d0693a67-a328-40d2-a0ce-4293eab3b217"}
4622024-08-05T19:12:57.290ZWait for a query_work_queue command to finish before sending IO
4632024-08-05T19:12:57.290Z{"msg":"Transition from Reconcile to Active","v":0,"name":"crucible","level":30,"time":"2024-08-05T19:12:55.648765431Z","hostname":"w-01J4HZ23M17JFMB0BME6Y9THXP","pid":1232,"client":"0","":"downstairs","session_id":"d0693a67-a328-40d2-a0ce-4293eab3b217"}
4642024-08-05T19:12:57.290Z{"msg":"Transition from Reconcile to Active","v":0,"name":"crucible","level":30,"time":"2024-08-05T19:12:55.64878317Z","hostname":"w-01J4HZ23M17JFMB0BME6Y9THXP","pid":1232,"client":"1","":"downstairs","session_id":"d0693a67-a328-40d2-a0ce-4293eab3b217"}
4652024-08-05T19:12:57.290Z{"msg":"Transition from Reconcile to Active","v":0,"name":"crucible","level":30,"time":"2024-08-05T19:12:55.648798138Z","hostname":"w-01J4HZ23M17JFMB0BME6Y9THXP","pid":1232,"client":"2","":"downstairs","session_id":"d0693a67-a328-40d2-a0ce-4293eab3b217"}
4662024-08-05T19:12:57.290Z{"msg":"All required reconciliation work is completed","v":0,"name":"crucible","level":30,"time":"2024-08-05T19:12:55.648812017Z","hostname":"w-01J4HZ23M17JFMB0BME6Y9THXP","pid":1232,"session_id":"d0693a67-a328-40d2-a0ce-4293eab3b217"}
4672024-08-05T19:12:57.290Z{"msg":"Set Downstairs and Upstairs active after reconciliation","v":0,"name":"crucible","level":30,"time":"2024-08-05T19:12:55.648836574Z","hostname":"w-01J4HZ23M17JFMB0BME6Y9THXP","pid":1232,"session_id":"d0693a67-a328-40d2-a0ce-4293eab3b217"}
4682024-08-05T19:12:57.293Z{"msg":"70aa0c1b-1aaa-4f74-b534-56df5fef483c is now active with session: d0693a67-a328-40d2-a0ce-4293eab3b217","v":0,"name":"crucible","level":30,"time":"2024-08-05T19:12:55.648857512Z","hostname":"w-01J4HZ23M17JFMB0BME6Y9THXP","pid":1232,"session_id":"d0693a67-a328-40d2-a0ce-4293eab3b217"}
4692024-08-05T19:12:57.293Z{"msg":"The guest has finished waiting for activation with:33","v":0,"name":"crucible","level":30,"time":"2024-08-05T19:12:55.64888978Z","hostname":"w-01J4HZ23M17JFMB0BME6Y9THXP","pid":1232}
4702024-08-05T19:12:57.293ZRegion: es:10 ec:5 bs:4096 ts:204800 tb:50 max_io:50 or 204800
4712024-08-05T19:12:57.293ZLoading write count information from file "/var/tmp/test_up/verify_file"
4722024-08-05T19:12:57.293ZRead and Verify all blocks (0..50 range:true)
4732024-08-05T19:12:57.326ZWrote out file "/var/tmp/test_up/verify_file"
4742024-08-05T19:12:57.326ZVerify test completed
4752024-08-05T19:12:57.330ZWrote out file "/var/tmp/test_up/verify_file"
4762024-08-05T19:12:57.330ZCLIENT: Tests done. All submitted work has been ACK'd
4772024-08-05T19:12:57.330Z----------------------------------------------------------------
4782024-08-05T19:12:57.330Z Crucible gen:33 GIO:true work queues: Upstairs:0 downstairs:1
4792024-08-05T19:12:57.330ZStates: Active Active Active
4802024-08-05T19:12:57.330ZGW_ID ACK DSID TYPE BKS/EXT DS:0 DS:1 DS:2 REPLAY
4812024-08-05T19:12:57.330Z 1 Acked 1000 Read 50 Done Done Done false
4822024-08-05T19:12:57.330Z STATES DS:0 DS:1 DS:2 TOTAL
4832024-08-05T19:12:57.330Z New 0 0 0 0
4842024-08-05T19:12:57.330Z Sent 0 0 0 0
4852024-08-05T19:12:57.330Z Done 1 1 1 3
4862024-08-05T19:12:57.330Z Skipped 0 0 0 0
4872024-08-05T19:12:57.330Z Error 0 0 0 0
4882024-08-05T19:12:57.330ZLast Flush: 0 0 0
4892024-08-05T19:12:57.330ZDownstairs last five completed:
4902024-08-05T19:12:57.330ZUpstairs last five completed: 1
4912024-08-05T19:12:57.330ZCLIENT: Up:0 ds:1 act:3
4922024-08-05T19:13:01.328Z----------------------------------------------------------------
4932024-08-05T19:13:01.328Z Crucible gen:33 GIO:true work queues: Upstairs:0 downstairs:0
4942024-08-05T19:13:01.328ZDownstairs last five completed: 1001 1000
4952024-08-05T19:13:01.328ZUpstairs last five completed: 2 1
4962024-08-05T19:13:01.328ZCLIENT: Up:0 ds:0 act:3
4972024-08-05T19:13:01.328ZCLIENT: All crucible jobs finished, exiting program
4982024-08-05T19:13:01.331Z{"msg":"Guest handle has been dropped","v":0,"name":"crucible","level":40,"time":"2024-08-05T19:12:59.686685627Z","hostname":"w-01J4HZ23M17JFMB0BME6Y9THXP","pid":1232}
4992024-08-05T19:13:01.334ZRepair part 2 passed
5002024-08-05T19:13:01.334Z/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
5012024-08-05T19:13:01.352ZEXT BLOCKS GEN0 GEN1 GEN2 FL0 FL1 FL2 D0 D1 D2 DIFF
5022024-08-05T19:13:01.352Z 0 000-009 32 32 32 1675 1675 1675 F F F
5032024-08-05T19:13:01.352Z 1 010-019 31 31 31 1674 1674 1674 F F F
5042024-08-05T19:13:01.352Z 2 020-029 32 32 32 1675 1675 1675 F F F
5052024-08-05T19:13:01.352Z 3 030-039 32 32 32 1675 1675 1675 F F F
5062024-08-05T19:13:01.352Z 4 040-049 32 32 32 1675 1675 1675 F F F
5072024-08-05T19:13:01.352ZMax gen: 32, Max flush: 1675
5082024-08-05T19:13:01.355Zdump test passed
5092024-08-05T19:13:01.355Z/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
5102024-08-05T19:13:01.373Z Extent 1
5112024-08-05T19:13:01.375ZGEN 31 31 31
5122024-08-05T19:13:01.376ZFLUSH_ID 1674 1674 1674
5132024-08-05T19:13:01.376ZDIRTY
5142024-08-05T19:13:01.376Z
5152024-08-05T19:13:01.376ZBLOCK D0 D1 D2 C0 C1 C2 DIFF
5162024-08-05T19:13:01.376Z010 A A A A A A
5172024-08-05T19:13:01.378Z011 A A A A A A
5182024-08-05T19:13:01.379Z012 A A A A A A
5192024-08-05T19:13:01.379Z013 A A A A A A
5202024-08-05T19:13:01.381Z014 A A A A A A
5212024-08-05T19:13:01.381Z015 A A A A A A
5222024-08-05T19:13:01.384Z016 A A A A A A
5232024-08-05T19:13:01.384Z017 A A A A A A
5242024-08-05T19:13:01.387Z018 A A A A A A
5252024-08-05T19:13:01.387Z019 A A A A A A
5262024-08-05T19:13:01.392Zdump extent test passed
5272024-08-05T19:13:01.395Z/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
5282024-08-05T19:13:01.409ZExtent 2 Block in extent 0 Actual block 20
5292024-08-05T19:13:01.409Z
5302024-08-05T19:13:01.412Z DATA SHA256 VER
5312024-08-05T19:13:01.412Z------ ---------------------------------------------------------------- ---
5322024-08-05T19:13:01.412Z 0 0f9b666a8a70b586ff49c4429472feabc46c945b1f8728c34c4f2a37d1751467 A
5332024-08-05T19:13:01.415Z 1 0f9b666a8a70b586ff49c4429472feabc46c945b1f8728c34c4f2a37d1751467 A
5342024-08-05T19:13:01.415Z 2 0f9b666a8a70b586ff49c4429472feabc46c945b1f8728c34c4f2a37d1751467 A
5352024-08-05T19:13:01.415Z
5362024-08-05T19:13:01.415ZNONCES 0 1 2 DIFF
5372024-08-05T19:13:01.415Z------ ------------------------ ------------------------ ------------------------ -----
5382024-08-05T19:13:01.415Z 0 f049bdb85d8c8d9bb7bda802 f049bdb85d8c8d9bb7bda802 f049bdb85d8c8d9bb7bda802
5392024-08-05T19:13:01.415Z
5402024-08-05T19:13:01.415Z TAGS 0 1 2 DIFF
5412024-08-05T19:13:01.415Z------ -------------------------------- -------------------------------- -------------------------------- -----
5422024-08-05T19:13:01.415Z 0 615aa12eae31d89b9993a8cb2ac7b7fc 615aa12eae31d89b9993a8cb2ac7b7fc 615aa12eae31d89b9993a8cb2ac7b7fc
5432024-08-05T19:13:01.415Z
5442024-08-05T19:13:01.415ZHASHES 0 1 2 DIFF
5452024-08-05T19:13:01.415Z------ ---------------- ---------------- ---------------- -----
5462024-08-05T19:13:01.415Z
5472024-08-05T19:13:01.418Zdump block test passed
5482024-08-05T19:13:01.418ZUpstairs tests have completed, stopping all downstairs
5492024-08-05T19:13:06.482ZCreating four larger downstairs regions
5502024-08-05T19:13:06.917ZStarting four downstairs
5512024-08-05T19:13:11.925ZNow do the replace-reconcile test
5522024-08-05T19:15:46.813ZCompleted test: replace-reconcile
5532024-08-05T19:15:46.816ZNow do the replace-before-active test
5542024-08-05T19:18:26.741ZCompleted test: replace-before-active
5552024-08-05T19:18:26.743ZTests have completed, stopping all downstairs
5562024-08-05T19:18:26.801Z
5572024-08-05T19:18:26.801ZAll Tests have passed
5582024-08-05T19:18:26.807Z8:57 Test duration
5592024-08-05T19:18:26.807Z
5602024-08-05T19:18:26.807Zreal 8:56.639267828
5612024-08-05T19:18:26.807Zuser 3:16.520289772
5622024-08-05T19:18:26.807Zsys 16.486126958
5632024-08-05T19:18:26.808Ztrap 0.259643943
5642024-08-05T19:18:26.808Ztflt 0.039991974
5652024-08-05T19:18:26.808Zdflt 0.038132955
5662024-08-05T19:18:26.808Zkflt 0.001512542
5672024-08-05T19:18:26.808Zlock 7:56:28.783249337
5682024-08-05T19:18:26.808Zslp 32:03.965833356
5692024-08-05T19:18:26.808Zlat 17.241109151
5702024-08-05T19:18:26.808Zstop 0.127218126
5712024-08-05T19:18:26.808Z+ echo 'test-up-encrypted ends'
5722024-08-05T19:18:26.808Ztest-up-encrypted ends
5732024-08-05T19:18:31.805Zprocess exited: duration 544282 ms, exit code 0
5742024-08-05T19:18:31.805Zexec warning: : stdio descriptors remain open after task exit; waiting 60 seconds for them to close
5752024-08-05T19:19:31.826Zexec warning: : stdout descriptor may be held open by a background process; giving up!
5762024-08-05T19:19:31.826Zexec warning: : stderr descriptor may be held open by a background process; giving up!
 
5772024-08-05T19:19:31.837Zfound 14 output files
5782024-08-05T19:19:31.844Zuploading: /tmp/test_up/dsc-out.txt (21502 bytes)
5792024-08-05T19:19:32.852Zuploaded: /tmp/test_up/dsc-out.txt
5802024-08-05T19:19:32.852Zuploading: /tmp/test_up/test_up_out.txt (9595365 bytes)
5812024-08-05T19:19:34.063Zuploaded: /tmp/test_up/test_up_out.txt
5822024-08-05T19:19:34.064Zuploading: /tmp/test_up/dsc/downstairs-8810.txt (2475 bytes)
5832024-08-05T19:19:35.081Zuploaded: /tmp/test_up/dsc/downstairs-8810.txt
5842024-08-05T19:19:35.081Zuploading: /tmp/test_up/dsc/downstairs-8820.txt (140429 bytes)
5852024-08-05T19:19:36.102Zuploaded: /tmp/test_up/dsc/downstairs-8820.txt
5862024-08-05T19:19:36.102Zuploading: /tmp/test_up/dsc/downstairs-8830.txt (246792 bytes)
5872024-08-05T19:19:37.137Zuploaded: /tmp/test_up/dsc/downstairs-8830.txt
5882024-08-05T19:19:37.137Zuploading: /tmp/test_up/dsc/downstairs-8840.txt (135210 bytes)
5892024-08-05T19:19:38.178Zuploaded: /tmp/test_up/dsc/downstairs-8840.txt
5902024-08-05T19:19:38.178Zuploading: /tmp/debug/df.txt (1270 bytes)
5912024-08-05T19:19:39.189Zuploaded: /tmp/debug/df.txt
5922024-08-05T19:19:39.189Zuploading: /tmp/debug/dtrace.txt (514862 bytes)
5932024-08-05T19:19:40.224Zuploaded: /tmp/debug/dtrace.txt
5942024-08-05T19:19:40.227Zuploading: /tmp/debug/iostat.txt (180050 bytes)
5952024-08-05T19:19:40.241Zupload warning: file "/tmp/debug/iostat.txt" changed size mid upload: 180050 -> 182741
5962024-08-05T19:19:41.248Zuploaded: /tmp/debug/iostat.txt
5972024-08-05T19:19:41.248Zuploading: /tmp/debug/mpstat.txt (438257 bytes)
5982024-08-05T19:19:41.276Zupload warning: file "/tmp/debug/mpstat.txt" changed size mid upload: 438257 -> 445537
5992024-08-05T19:19:42.283Zuploaded: /tmp/debug/mpstat.txt
6002024-08-05T19:19:42.283Zuploading: /tmp/debug/paging.txt (78266 bytes)
6012024-08-05T19:19:42.294Zupload warning: file "/tmp/debug/paging.txt" changed size mid upload: 78266 -> 79678
6022024-08-05T19:19:43.301Zuploaded: /tmp/debug/paging.txt
6032024-08-05T19:19:43.301Zuploading: /tmp/debug/prstat.txt (842206 bytes)
6042024-08-05T19:19:43.340Zupload warning: file "/tmp/debug/prstat.txt" changed size mid upload: 842206 -> 857720
6052024-08-05T19:19:44.348Zuploaded: /tmp/debug/prstat.txt
6062024-08-05T19:19:44.348Zuploading: /tmp/debug/psrinfo.txt (1528 bytes)
6072024-08-05T19:19:45.357Zuploaded: /tmp/debug/psrinfo.txt
6082024-08-05T19:19:45.357Zuploading: /tmp/debug/upstairs-info.txt (99297 bytes)
6092024-08-05T19:19:46.374Zuploaded: /tmp/debug/upstairs-info.txt