01J44ZV82Y81TP5DPAJZMEBSFQ: test-up-unencrypted

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

Buildomat Job: 01J44ZVHT7HSHY0D67NCT6ZP08

Tags:

Artefacts:

Output:

SEQ GLOBAL TIME DETAILS
12024-07-31T18:25:29.558Zjob dependencies complete; ready to run (waiting for 13 m 37 s)
22024-07-31T18:26:34.719Zjob assigned to worker 01J450MRXTE9TPPNZEBAC250HX (queued for 1 m 5 s)
32024-07-31T18:26:42.667Zdownloading input: /input/build/work/bins/crucible-downstairs.gz
42024-07-31T18:26:43.928Zdownloaded input: /input/build/work/bins/crucible-downstairs.gz
52024-07-31T18:26:43.928Zdownloading input: /input/build/work/bins/crucible-hammer.gz
62024-07-31T18:26:44.825Zdownloaded input: /input/build/work/bins/crucible-hammer.gz
72024-07-31T18:26:44.825Zdownloading input: /input/build/work/bins/crutest.gz
82024-07-31T18:26:45.905Zdownloaded input: /input/build/work/bins/crutest.gz
92024-07-31T18:26:45.905Zdownloading input: /input/build/work/bins/dsc.gz
102024-07-31T18:26:46.556Zdownloaded input: /input/build/work/bins/dsc.gz
112024-07-31T18:26:46.559Zdownloading input: /input/build/work/scripts/perf-downstairs-tick.d
122024-07-31T18:26:46.575Zdownloaded input: /input/build/work/scripts/perf-downstairs-tick.d
132024-07-31T18:26:46.575Zdownloading input: /input/build/work/scripts/test_ds.sh
142024-07-31T18:26:46.594Zdownloaded input: /input/build/work/scripts/test_ds.sh
152024-07-31T18:26:46.594Zdownloading input: /input/build/work/scripts/test_live_repair.sh
162024-07-31T18:26:46.613Zdownloaded input: /input/build/work/scripts/test_live_repair.sh
172024-07-31T18:26:46.613Zdownloading input: /input/build/work/scripts/test_repair.sh
182024-07-31T18:26:46.629Zdownloaded input: /input/build/work/scripts/test_repair.sh
192024-07-31T18:26:46.629Zdownloading input: /input/build/work/scripts/test_replay.sh
202024-07-31T18:26:46.647Zdownloaded input: /input/build/work/scripts/test_replay.sh
212024-07-31T18:26:46.647Zdownloading input: /input/build/work/scripts/test_up.sh
222024-07-31T18:26:46.667Zdownloaded input: /input/build/work/scripts/test_up.sh
232024-07-31T18:26:46.667Zdownloading input: /input/build/work/scripts/upstairs_info.d
242024-07-31T18:26:46.688Zdownloaded input: /input/build/work/scripts/upstairs_info.d
252024-07-31T18:26:46.691Zdownloading input: /input/build/tmp/cargo-test-out.log
262024-07-31T18:26:47.562Zdownloaded input: /input/build/tmp/cargo-test-out.log
 
272024-07-31T18:26:47.562Zstarting task 0: "setup"
282024-07-31T18:26:47.623Z++ uname -s
292024-07-31T18:26:47.626Z+ kern=SunOS
302024-07-31T18:26:47.626Z+ case "$kern" in
312024-07-31T18:26:47.626Z+ groupadd -g 12345 build
322024-07-31T18:26:47.629Z+ useradd -u 12345 -g build -d /home/build -s /bin/bash -c build -P 'Primary Administrator' build
332024-07-31T18:26:49.645Z+ zfs create -o mountpoint=/work rpool/work
342024-07-31T18:26:49.867Z++ awk '$2 == "/home" { print $3 }' /etc/mnttab
352024-07-31T18:26:49.869Z+ home_fs=zfs
362024-07-31T18:26:49.869Z+ [[ zfs == autofs ]]
372024-07-31T18:26:49.869Z+ mkdir -p /home/build
382024-07-31T18:26:49.872Z+ chown build:build /home/build /work
392024-07-31T18:26:51.873Z+ chmod 0700 /home/build /work
402024-07-31T18:26:51.876Zprocess exited: duration 4312 ms, exit code 0
 
412024-07-31T18:26:51.882Zstarting task 1: "authentication"
422024-07-31T18:26:51.899Zprocess exited: duration 17 ms, exit code 0
 
432024-07-31T18:26:51.907Zstarting task 2: "build"
442024-07-31T18:26:51.910Z+ banner cores
452024-07-31T18:26:51.929Z
462024-07-31T18:26:51.929Z #### #### ##### ###### ####
472024-07-31T18:26:51.929Z # # # # # # # #
482024-07-31T18:26:51.929Z # # # # # ##### ####
492024-07-31T18:26:51.929Z # # # ##### # #
502024-07-31T18:26:51.929Z # # # # # # # # #
512024-07-31T18:26:51.929Z #### #### # # ###### ####
522024-07-31T18:26:51.929Z
532024-07-31T18:26:51.932Z+ pfexec coreadm -i /tmp/core.%f.%p -g /tmp/core.%f.%p -e global -e log -e proc-setid -e global-setid
542024-07-31T18:26:51.939Z+ echo 'input bins dir contains:'
552024-07-31T18:26:51.939Zinput bins dir contains:
562024-07-31T18:26:51.941Z+ ls -ltr /input/build/work/bins
572024-07-31T18:26:51.941Ztotal 697310
582024-07-31T18:26:51.942Z-rw-r--r-- 1 root root 105718804 Jul 31 18:26 crucible-downstairs.gz
592024-07-31T18:26:51.942Z-rw-r--r-- 1 root root 83362443 Jul 31 18:26 crucible-hammer.gz
602024-07-31T18:26:51.942Z-rw-r--r-- 1 root root 103297708 Jul 31 18:26 crutest.gz
612024-07-31T18:26:51.942Z-rw-r--r-- 1 root root 64414616 Jul 31 18:26 dsc.gz
622024-07-31T18:26:51.942Z+ banner unpack
632024-07-31T18:26:51.944Z
642024-07-31T18:26:51.944Z # # # # ##### ## #### # #
652024-07-31T18:26:51.944Z # # ## # # # # # # # # #
662024-07-31T18:26:51.944Z # # # # # # # # # # ####
672024-07-31T18:26:51.945Z # # # # # ##### ###### # # #
682024-07-31T18:26:51.945Z # # # ## # # # # # # #
692024-07-31T18:26:51.945Z #### # # # # # #### # #
702024-07-31T18:26:51.945Z
712024-07-31T18:26:51.945Z+ mkdir -p /var/tmp/bins
722024-07-31T18:26:51.945Z+ for t in "$input/bins/"*.gz
732024-07-31T18:26:51.947Z++ basename /input/build/work/bins/crucible-downstairs.gz
742024-07-31T18:26:51.947Z+ b=crucible-downstairs.gz
752024-07-31T18:26:51.947Z+ b=crucible-downstairs
762024-07-31T18:26:51.947Z+ gunzip
772024-07-31T18:26:54.159Z+ chmod +x /var/tmp/bins/crucible-downstairs
782024-07-31T18:26:54.161Z+ for t in "$input/bins/"*.gz
792024-07-31T18:26:54.161Z++ basename /input/build/work/bins/crucible-hammer.gz
802024-07-31T18:26:54.164Z+ b=crucible-hammer.gz
812024-07-31T18:26:54.164Z+ b=crucible-hammer
822024-07-31T18:26:54.164Z+ gunzip
832024-07-31T18:26:55.903Z+ chmod +x /var/tmp/bins/crucible-hammer
842024-07-31T18:26:55.906Z+ for t in "$input/bins/"*.gz
852024-07-31T18:26:55.906Z++ basename /input/build/work/bins/crutest.gz
862024-07-31T18:26:55.909Z+ b=crutest.gz
872024-07-31T18:26:55.909Z+ b=crutest
882024-07-31T18:26:55.909Z+ gunzip
892024-07-31T18:26:58.059Z+ chmod +x /var/tmp/bins/crutest
902024-07-31T18:26:58.062Z+ for t in "$input/bins/"*.gz
912024-07-31T18:26:58.062Z++ basename /input/build/work/bins/dsc.gz
922024-07-31T18:26:58.065Z+ b=dsc.gz
932024-07-31T18:26:58.065Z+ b=dsc
942024-07-31T18:26:58.065Z+ gunzip
952024-07-31T18:26:59.561Z+ chmod +x /var/tmp/bins/dsc
962024-07-31T18:26:59.564Z+ export BINDIR=/var/tmp/bins
972024-07-31T18:26:59.564Z+ BINDIR=/var/tmp/bins
982024-07-31T18:26:59.564Z+ jobpid=1142
992024-07-31T18:26:59.568Z+ echo 'Setup debug logging'
1002024-07-31T18:26:59.568ZSetup debug logging
1012024-07-31T18:26:59.568Z+ mkdir /tmp/debug
1022024-07-31T18:26:59.568Z+ sleep 7200
1032024-07-31T18:26:59.568Z+ psrinfo -v
1042024-07-31T18:26:59.573Z+ df -h
1052024-07-31T18:26:59.585Z+ prstat -d d -mLc 1
1062024-07-31T18:26:59.588Z+ iostat -T d -xn 1
1072024-07-31T18:26:59.588Z+ mpstat -T d 1
1082024-07-31T18:26:59.591Z+ vmstat -T d -p 1
1092024-07-31T18:26:59.591Z+ pfexec dtrace -Z -s /input/build/work/scripts/perf-downstairs-tick.d
1102024-07-31T18:26:59.591Z+ banner test_up_unencrypted
1112024-07-31T18:26:59.591Z+ pfexec dtrace -Z -s /input/build/work/scripts/upstairs_info.d
1122024-07-31T18:26:59.594Z
1132024-07-31T18:26:59.594Z ##### ###### #### ##### # # ##### # # # #
1142024-07-31T18:26:59.594Z # # # # # # # # # # ## #
1152024-07-31T18:26:59.594Z # ##### #### # # # # # # # # # #
1162024-07-31T18:26:59.594Z # # # # # # ##### # # # # #
1172024-07-31T18:26:59.594Z # # # # # # # # # # # ##
1182024-07-31T18:26:59.594Z # ###### #### # ####### #### # ####### #### # #
1192024-07-31T18:26:59.594Z
1202024-07-31T18:26:59.594Z+ ptime -m bash /input/build/work/scripts/test_up.sh -N unencrypted
1212024-07-31T18:26:59.631Z/input/build/work
1222024-07-31T18:26:59.646ZTurn off color for downstairs dump
1232024-07-31T18:26:59.650Zdsc output goes to /tmp/test_up/dsc-out.txt
1242024-07-31T18:26:59.650ZCreating three downstairs regions
1252024-07-31T18:27:00.228ZStarting three downstairs
1262024-07-31T18:27:05.236ZDisable automatic restart on all downstairs
1272024-07-31T18:27:05.308Z
1282024-07-31T18:27:05.308ZBegin tests, output goes to /tmp/test_up/test_up_out.txt
1292024-07-31T18:27:05.312ZRunning test: span
1302024-07-31T18:27:09.363ZCompleted test: span
1312024-07-31T18:27:14.370ZRunning test: big
1322024-07-31T18:27:18.516ZCompleted test: big
1332024-07-31T18:27:23.523ZRunning test: dep
1342024-07-31T18:27:43.745ZCompleted test: dep
1352024-07-31T18:27:48.752ZRunning test: balloon
1362024-07-31T18:28:00.250ZCompleted test: balloon
1372024-07-31T18:28:05.257ZRunning test: deactivate
1382024-07-31T18:28:59.453ZCompleted test: deactivate
1392024-07-31T18:29:04.461ZRunning hammer
1402024-07-31T18:29:12.918ZRun repair tests
1412024-07-31T18:29:12.921Z/var/tmp/bins/crutest fill -g 31 -q -t 127.0.0.1:8810 -t 127.0.0.1:8820 -t 127.0.0.1:8830 --verify-out /var/tmp/test_up/verify_file
1422024-07-31T18:29:12.935Z{"msg":"Upstairs starts","v":0,"name":"crucible","level":30,"time":"2024-07-31T18:29:11.438861777Z","hostname":"w-01J450MRXTE9TPPNZEBAC250HX","pid":1220}
1432024-07-31T18:29:12.939Z{"msg":"Crucible Version: BuildInfo {\n version: \"0.0.1\",\n git_sha: \"5ae6bd0137b92ba7ccd4c1802a9f2f433ead0b4c\",\n git_commit_timestamp: \"2024-07-31T18:11:08.000000000Z\",\n git_branch: \"main\",\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-07-31T18:29:11.439393599Z","hostname":"w-01J450MRXTE9TPPNZEBAC250HX","pid":1220}
1442024-07-31T18:29:12.939Z{"msg":"Upstairs <-> Downstairs Message Version: 11","v":0,"name":"crucible","level":30,"time":"2024-07-31T18:29:11.439432304Z","hostname":"w-01J450MRXTE9TPPNZEBAC250HX","pid":1220}
1452024-07-31T18:29:12.939Z{"msg":"Crucible c75a95c7-a63b-40f9-a702-d166aa8e6f6d has session id: 4c3ecf05-cfa7-44b1-a125-4f08739c6335","v":0,"name":"crucible","level":30,"time":"2024-07-31T18:29:11.439499824Z","hostname":"w-01J450MRXTE9TPPNZEBAC250HX","pid":1220,"session_id":"4c3ecf05-cfa7-44b1-a125-4f08739c6335"}
1462024-07-31T18:29:12.939Z{"msg":"Upstairs opts: Upstairs UUID: c75a95c7-a63b-40f9-a702-d166aa8e6f6d, Targets: [127.0.0.1:8810, 127.0.0.1:8820, 127.0.0.1:8830], lossy: false, flush_timeout: None, key populated: false, cert_pem populated: false, key_pem populated: false, root_cert_pem populated: false, Control: None, read_only: false","v":0,"name":"crucible","level":30,"time":"2024-07-31T18:29:11.439568554Z","hostname":"w-01J450MRXTE9TPPNZEBAC250HX","pid":1220,"session_id":"4c3ecf05-cfa7-44b1-a125-4f08739c6335"}
1472024-07-31T18:29:12.939Z{"msg":"Crucible stats registered with UUID: c75a95c7-a63b-40f9-a702-d166aa8e6f6d","v":0,"name":"crucible","level":30,"time":"2024-07-31T18:29:11.439613477Z","hostname":"w-01J450MRXTE9TPPNZEBAC250HX","pid":1220,"session_id":"4c3ecf05-cfa7-44b1-a125-4f08739c6335"}
1482024-07-31T18:29:12.939ZCrucible runtime is spawned
1492024-07-31T18:29:12.939Z{"msg":"The guest has requested activation with gen:31","v":0,"name":"crucible","level":30,"time":"2024-07-31T18:29:11.439913554Z","hostname":"w-01J450MRXTE9TPPNZEBAC250HX","pid":1220}
1502024-07-31T18:29:12.939Z{"msg":"c75a95c7-a63b-40f9-a702-d166aa8e6f6d active request set","v":0,"name":"crucible","level":30,"time":"2024-07-31T18:29:11.439959617Z","hostname":"w-01J450MRXTE9TPPNZEBAC250HX","pid":1220,"session_id":"4c3ecf05-cfa7-44b1-a125-4f08739c6335"}
1512024-07-31T18:29:12.939Z{"msg":"sending connect oneshot to client","v":0,"name":"crucible","level":30,"time":"2024-07-31T18:29:11.439975105Z","hostname":"w-01J450MRXTE9TPPNZEBAC250HX","pid":1220,"client":"0","":"downstairs","session_id":"4c3ecf05-cfa7-44b1-a125-4f08739c6335"}
1522024-07-31T18:29:12.939Z{"msg":"client set_active_request while in New; waiting...","v":0,"name":"crucible","level":30,"time":"2024-07-31T18:29:11.440002901Z","hostname":"w-01J450MRXTE9TPPNZEBAC250HX","pid":1220,"client":"0","":"downstairs","session_id":"4c3ecf05-cfa7-44b1-a125-4f08739c6335"}
1532024-07-31T18:29:12.939Z{"msg":"sending connect oneshot to client","v":0,"name":"crucible","level":30,"time":"2024-07-31T18:29:11.440017639Z","hostname":"w-01J450MRXTE9TPPNZEBAC250HX","pid":1220,"client":"1","":"downstairs","session_id":"4c3ecf05-cfa7-44b1-a125-4f08739c6335"}
1542024-07-31T18:29:12.939Z{"msg":"client set_active_request while in New; waiting...","v":0,"name":"crucible","level":30,"time":"2024-07-31T18:29:11.440048694Z","hostname":"w-01J450MRXTE9TPPNZEBAC250HX","pid":1220,"client":"1","":"downstairs","session_id":"4c3ecf05-cfa7-44b1-a125-4f08739c6335"}
1552024-07-31T18:29:12.939Z{"msg":"sending connect oneshot to client","v":0,"name":"crucible","level":30,"time":"2024-07-31T18:29:11.44007307Z","hostname":"w-01J450MRXTE9TPPNZEBAC250HX","pid":1220,"client":"2","":"downstairs","session_id":"4c3ecf05-cfa7-44b1-a125-4f08739c6335"}
1562024-07-31T18:29:12.939Z{"msg":"client set_active_request while in New; waiting...","v":0,"name":"crucible","level":30,"time":"2024-07-31T18:29:11.440093687Z","hostname":"w-01J450MRXTE9TPPNZEBAC250HX","pid":1220,"client":"2","":"downstairs","session_id":"4c3ecf05-cfa7-44b1-a125-4f08739c6335"}
1572024-07-31T18:29:12.939Z{"msg":"connecting to 127.0.0.1:8810","v":0,"name":"crucible","level":30,"time":"2024-07-31T18:29:11.440123973Z","hostname":"w-01J450MRXTE9TPPNZEBAC250HX","pid":1220,"":"io task","client":"0","":"downstairs","session_id":"4c3ecf05-cfa7-44b1-a125-4f08739c6335"}
1582024-07-31T18:29:12.939Z{"msg":"connecting to 127.0.0.1:8820","v":0,"name":"crucible","level":30,"time":"2024-07-31T18:29:11.440158788Z","hostname":"w-01J450MRXTE9TPPNZEBAC250HX","pid":1220,"":"io task","client":"1","":"downstairs","session_id":"4c3ecf05-cfa7-44b1-a125-4f08739c6335"}
1592024-07-31T18:29:12.939Z{"msg":"connecting to 127.0.0.1:8830","v":0,"name":"crucible","level":30,"time":"2024-07-31T18:29:11.440183225Z","hostname":"w-01J450MRXTE9TPPNZEBAC250HX","pid":1220,"":"io task","client":"2","":"downstairs","session_id":"4c3ecf05-cfa7-44b1-a125-4f08739c6335"}
1602024-07-31T18:29:12.939Z{"msg":"ds_connection connected from Ok(127.0.0.1:56283)","v":0,"name":"crucible","level":30,"time":"2024-07-31T18:29:11.440264013Z","hostname":"w-01J450MRXTE9TPPNZEBAC250HX","pid":1220,"":"io task","client":"1","":"downstairs","session_id":"4c3ecf05-cfa7-44b1-a125-4f08739c6335"}
1612024-07-31T18:29:12.939Z{"msg":"ds_connection connected from Ok(127.0.0.1:33213)","v":0,"name":"crucible","level":30,"time":"2024-07-31T18:29:11.440307856Z","hostname":"w-01J450MRXTE9TPPNZEBAC250HX","pid":1220,"":"io task","client":"2","":"downstairs","session_id":"4c3ecf05-cfa7-44b1-a125-4f08739c6335"}
1622024-07-31T18:29:12.939Z{"msg":"ds_connection connected from Ok(127.0.0.1:39742)","v":0,"name":"crucible","level":30,"time":"2024-07-31T18:29:11.440689381Z","hostname":"w-01J450MRXTE9TPPNZEBAC250HX","pid":1220,"":"io task","client":"0","":"downstairs","session_id":"4c3ecf05-cfa7-44b1-a125-4f08739c6335"}
1632024-07-31T18:29:12.939Z{"msg":"ds_transition from New to WaitActive","v":0,"name":"crucible","level":30,"time":"2024-07-31T18:29:11.441182349Z","hostname":"w-01J450MRXTE9TPPNZEBAC250HX","pid":1220,"client":"1","":"downstairs","session_id":"4c3ecf05-cfa7-44b1-a125-4f08739c6335"}
1642024-07-31T18:29:12.939Z{"msg":"[1] Transition from New to WaitActive","v":0,"name":"crucible","level":30,"time":"2024-07-31T18:29:11.441218074Z","hostname":"w-01J450MRXTE9TPPNZEBAC250HX","pid":1220,"client":"1","":"downstairs","session_id":"4c3ecf05-cfa7-44b1-a125-4f08739c6335"}
1652024-07-31T18:29:12.939Z{"msg":"ds_transition from New to WaitActive","v":0,"name":"crucible","level":30,"time":"2024-07-31T18:29:11.441234342Z","hostname":"w-01J450MRXTE9TPPNZEBAC250HX","pid":1220,"client":"2","":"downstairs","session_id":"4c3ecf05-cfa7-44b1-a125-4f08739c6335"}
1662024-07-31T18:29:12.940Z{"msg":"[2] Transition from New to WaitActive","v":0,"name":"crucible","level":30,"time":"2024-07-31T18:29:11.441261998Z","hostname":"w-01J450MRXTE9TPPNZEBAC250HX","pid":1220,"client":"2","":"downstairs","session_id":"4c3ecf05-cfa7-44b1-a125-4f08739c6335"}
1672024-07-31T18:29:12.940Z{"msg":"ds_transition from New to WaitActive","v":0,"name":"crucible","level":30,"time":"2024-07-31T18:29:11.441285834Z","hostname":"w-01J450MRXTE9TPPNZEBAC250HX","pid":1220,"client":"0","":"downstairs","session_id":"4c3ecf05-cfa7-44b1-a125-4f08739c6335"}
1682024-07-31T18:29:12.940Z{"msg":"[0] Transition from New to WaitActive","v":0,"name":"crucible","level":30,"time":"2024-07-31T18:29:11.441319199Z","hostname":"w-01J450MRXTE9TPPNZEBAC250HX","pid":1220,"client":"0","":"downstairs","session_id":"4c3ecf05-cfa7-44b1-a125-4f08739c6335"}
1692024-07-31T18:29:12.940Z{"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-07-31T18:29:11.441887537Z","hostname":"w-01J450MRXTE9TPPNZEBAC250HX","pid":1220,"client":"2","":"downstairs","session_id":"4c3ecf05-cfa7-44b1-a125-4f08739c6335"}
1702024-07-31T18:29:12.940Z{"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-07-31T18:29:11.441924991Z","hostname":"w-01J450MRXTE9TPPNZEBAC250HX","pid":1220,"client":"0","":"downstairs","session_id":"4c3ecf05-cfa7-44b1-a125-4f08739c6335"}
1712024-07-31T18:29:12.940Z{"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-07-31T18:29:11.441948108Z","hostname":"w-01J450MRXTE9TPPNZEBAC250HX","pid":1220,"client":"1","":"downstairs","session_id":"4c3ecf05-cfa7-44b1-a125-4f08739c6335"}
1722024-07-31T18:29:12.943Z{"msg":"ds_transition from WaitActive to WaitQuorum","v":0,"name":"crucible","level":30,"time":"2024-07-31T18:29:11.44234785Z","hostname":"w-01J450MRXTE9TPPNZEBAC250HX","pid":1220,"client":"2","":"downstairs","session_id":"4c3ecf05-cfa7-44b1-a125-4f08739c6335"}
1732024-07-31T18:29:12.943Z{"msg":"[2] Transition from WaitActive to WaitQuorum","v":0,"name":"crucible","level":30,"time":"2024-07-31T18:29:11.442399482Z","hostname":"w-01J450MRXTE9TPPNZEBAC250HX","pid":1220,"client":"2","":"downstairs","session_id":"4c3ecf05-cfa7-44b1-a125-4f08739c6335"}
1742024-07-31T18:29:12.943Z{"msg":"Waiting for more clients to be ready","v":0,"name":"crucible","level":30,"time":"2024-07-31T18:29:11.442439237Z","hostname":"w-01J450MRXTE9TPPNZEBAC250HX","pid":1220,"session_id":"4c3ecf05-cfa7-44b1-a125-4f08739c6335"}
1752024-07-31T18:29:12.943Z{"msg":"ds_transition from WaitActive to WaitQuorum","v":0,"name":"crucible","level":30,"time":"2024-07-31T18:29:11.442473352Z","hostname":"w-01J450MRXTE9TPPNZEBAC250HX","pid":1220,"client":"0","":"downstairs","session_id":"4c3ecf05-cfa7-44b1-a125-4f08739c6335"}
1762024-07-31T18:29:12.943Z{"msg":"[0] Transition from WaitActive to WaitQuorum","v":0,"name":"crucible","level":30,"time":"2024-07-31T18:29:11.442495478Z","hostname":"w-01J450MRXTE9TPPNZEBAC250HX","pid":1220,"client":"0","":"downstairs","session_id":"4c3ecf05-cfa7-44b1-a125-4f08739c6335"}
1772024-07-31T18:29:12.943Z{"msg":"Waiting for more clients to be ready","v":0,"name":"crucible","level":30,"time":"2024-07-31T18:29:11.442529653Z","hostname":"w-01J450MRXTE9TPPNZEBAC250HX","pid":1220,"session_id":"4c3ecf05-cfa7-44b1-a125-4f08739c6335"}
1782024-07-31T18:29:12.943Z{"msg":"ds_transition from WaitActive to WaitQuorum","v":0,"name":"crucible","level":30,"time":"Wait for a query_work_queue command to finish before sending IO
1792024-07-31T18:29:12.943Z2024-07-31T18:29:11.442562879Z","hostname":"w-01J450MRXTE9TPPNZEBAC250HX","pid":1220,"client":"1","":"downstairs","session_id":"4c3ecf05-cfa7-44b1-a125-4f08739c6335"}
1802024-07-31T18:29:12.943Z{"msg":"[1] Transition from WaitActive to WaitQuorum","v":0,"name":"crucible","level":30,"time":"2024-07-31T18:29:11.442601643Z","hostname":"w-01J450MRXTE9TPPNZEBAC250HX","pid":1220,"client":"1","":"downstairs","session_id":"4c3ecf05-cfa7-44b1-a125-4f08739c6335"}
1812024-07-31T18:29:12.943Z{"msg":"[0]R flush_numbers: [1541, 1541, 1541, 1541, 1541]","v":0,"name":"crucible","level":30,"time":"2024-07-31T18:29:11.442638608Z","hostname":"w-01J450MRXTE9TPPNZEBAC250HX","pid":1220,"":"downstairs","":"downstairs","session_id":"4c3ecf05-cfa7-44b1-a125-4f08739c6335"}
1822024-07-31T18:29:12.943Z{"msg":"[0]R generation: [25, 25, 25, 25, 25]","v":0,"name":"crucible","level":30,"time":"2024-07-31T18:29:11.44269195Z","hostname":"w-01J450MRXTE9TPPNZEBAC250HX","pid":1220,"":"downstairs","":"downstairs","session_id":"4c3ecf05-cfa7-44b1-a125-4f08739c6335"}
1832024-07-31T18:29:12.943Z{"msg":"[0]R dirty: [false, false, false, false, false]","v":0,"name":"crucible","level":30,"time":"2024-07-31T18:29:11.442729094Z","hostname":"w-01J450MRXTE9TPPNZEBAC250HX","pid":1220,"":"downstairs","":"downstairs","session_id":"4c3ecf05-cfa7-44b1-a125-4f08739c6335"}
1842024-07-31T18:29:12.943Z{"msg":"[1]R flush_numbers: [1541, 1541, 1541, 1541, 1541]","v":0,"name":"crucible","level":30,"time":"2024-07-31T18:29:11.442770678Z","hostname":"w-01J450MRXTE9TPPNZEBAC250HX","pid":1220,"":"downstairs","":"downstairs","session_id":"4c3ecf05-cfa7-44b1-a125-4f08739c6335"}
1852024-07-31T18:29:12.943Z{"msg":"[1]R generation: [25, 25, 25, 25, 25]","v":0,"name":"crucible","level":30,"time":"2024-07-31T18:29:11.442809352Z","hostname":"w-01J450MRXTE9TPPNZEBAC250HX","pid":1220,"":"downstairs","":"downstairs","session_id":"4c3ecf05-cfa7-44b1-a125-4f08739c6335"}
1862024-07-31T18:29:12.943Z{"msg":"[1]R dirty: [false, false, false, false, false]","v":0,"name":"crucible","level":30,"time":"2024-07-31T18:29:11.442846507Z","hostname":"w-01J450MRXTE9TPPNZEBAC250HX","pid":1220,"":"downstairs","":"downstairs","session_id":"4c3ecf05-cfa7-44b1-a125-4f08739c6335"}
1872024-07-31T18:29:12.943Z{"msg":"[2]R flush_numbers: [1541, 1541, 1541, 1541, 1541]","v":0,"name":"crucible","level":30Region: es:10 ec:5 bs:4096 ts:204800 tb:50 max_io:50 or 204800
1882024-07-31T18:29:12.944Z,"time":"2024-07-31T18:29:11.442890871Z","hostname":"w-01J450MRXTE9TPPNZEBAC250HX","pid":1220,"":"downstairs","":"downstairs","session_id":"4c3ecf05-cfa7-44b1-a125-4f08739c6335"}
1892024-07-31T18:29:12.944Z{Fill test
1902024-07-31T18:29:12.944Z"msg":"[2]R generation: [25, 25, 25, 25, 25]","v":0,"name":"crucible","level":30,"time":"2024-07-31T18:29:11.442931045Z","hostname":"w-01J450MRXTE9TPPNZEBAC250HX","pid":1220,"":"downstairs","":"downstairs","session_id":"4c3ecf05-cfa7-44b1-a125-4f08739c6335"}
1912024-07-31T18:29:12.944Z{"msg":"[2]R dirty: [false, false, false, false, false]","v":0,"name":"crucible","level":30,"time":"2024-07-31T18:29:11.442969319Z","hostname":"w-01J450MRXTE9TPPNZEBAC250HX","pid":1220,"":"downstairs","":"downstairs","session_id":"4c3ecf05-cfa7-44b1-a125-4f08739c6335"}
1922024-07-31T18:29:12.944Z{"msg":"Max found gen is 26","v":0,"name":"crucible","level":30,"time":"2024-07-31T18:29:11.442987877Z","hostname":"w-01J450MRXTE9TPPNZEBAC250HX","pid":1220,"":"downstairs","":"downstairs","session_id":"4c3ecf05-cfa7-44b1-a125-4f08739c6335"}
1932024-07-31T18:29:12.944Z{"msg":"Generation requested: 31 >= found:26","v":0,"name":"crucible","level":30,"time":"2024-07-31T18:29:11.443009783Z","hostname":"w-01J450MRXTE9TPPNZEBAC250HX","pid":1220,"":"downstairs","":"downstairs","session_id":"4c3ecf05-cfa7-44b1-a125-4f08739c6335"}
1942024-07-31T18:29:12.944Z{"msg":"Next flush: 1542","v":0,"name":"crucible","level":30,"time":"2024-07-31T18:29:11.443023711Z","hostname":"w-01J450MRXTE9TPPNZEBAC250HX","pid":1220,"":"downstairs","":"downstairs","session_id":"4c3ecf05-cfa7-44b1-a125-4f08739c6335"}
1952024-07-31T18:29:12.944Z{"msg":"All extents match","v":0,"name":"crucible","level":30,"time":"2024-07-31T18:29:11.443043609Z","hostname":"w-01J450MRXTE9TPPNZEBAC250HX","pid":1220,"":"downstairs","":"downstairs","session_id":"4c3ecf05-cfa7-44b1-a125-4f08739c6335"}
1962024-07-31T18:29:12.944Z{"msg":"No downstairs reconciliation required","v":0,"name":"crucible","level":30,"time":"2024-07-31T18:29:11.443057307Z","hostname":"w-01J450MRXTE9TPPNZEBAC250HX","pid":1220,"session_id":"4c3ecf05-cfa7-44b1-a125-4f08739c6335"}
1972024-07-31T18:29:12.944Z{"msg":"Transition from WaitQuorum to Active","v":0,"name":"crucible","level":30,"time":"2024-07-31T18:29:11.443076724Z","hostname":"w-01J450MRXTE9TPPNZEBAC250HX","pid":1220,"client":"0","":"downstairs","session_id":"4c3ecf05-cfa7-44b1-a125-4f08739c6335"}
1982024-07-31T18:29:12.944Z{"msg":"Transition from WaitQuorum to Active","v":0,"name":"crucible","level":30,"time":"2024-07-31T18:29:11.443090452Z","hostname":"w-01J450MRXTE9TPPNZEBAC250HX","pid":1220,"client":"1","":"downstairs","session_id":"4c3ecf05-cfa7-44b1-a125-4f08739c6335"}
1992024-07-31T18:29:12.944Z{"msg":"Transition from WaitQuorum to Active","v":0,"name":"crucible","level":30,"time":"2024-07-31T18:29:11.44310412Z","hostname":"w-01J450MRXTE9TPPNZEBAC250HX","pid":1220,"client":"2","":"downstairs","session_id":"4c3ecf05-cfa7-44b1-a125-4f08739c6335"}
2002024-07-31T18:29:12.944Z{"msg":"All required reconciliation work is completed","v":0,"name":"crucible","level":30,"time":"2024-07-31T18:29:11.443117548Z","hostname":"w-01J450MRXTE9TPPNZEBAC250HX","pid":1220,"session_id":"4c3ecf05-cfa7-44b1-a125-4f08739c6335"}
2012024-07-31T18:29:12.944Z{"msg":"Set Downstairs and Upstairs active after reconciliation","v":0,"name":"crucible","level":30,"time":"2024-07-31T18:29:11.443137235Z","hostname":"w-01J450MRXTE9TPPNZEBAC250HX","pid":1220,"session_id":"4c3ecf05-cfa7-44b1-a125-4f08739c6335"}
2022024-07-31T18:29:12.944Z{"msg":"c75a95c7-a63b-40f9-a702-d166aa8e6f6d is now active with session: 4c3ecf05-cfa7-44b1-a125-4f08739c6335","v":0,"name":"crucible","level":30,"time":"2024-07-31T18:29:11.443150563Z","hostname":"w-01J450MRXTE9TPPNZEBAC250HX","pid":1220,"session_id":"4c3ecf05-cfa7-44b1-a125-4f08739c6335"}
2032024-07-31T18:29:12.944Z{"msg":"Set Active after no reconciliation","v":0,"name":"crucible","level":30,"time":"2024-07-31T18:29:11.443163181Z","hostname":"w-01J450MRXTE9TPPNZEBAC250HX","pid":1220,"session_id":"4c3ecf05-cfa7-44b1-a125-4f08739c6335"}
2042024-07-31T18:29:12.944Z{"msg":"The guest has finished waiting for activation with:31","v":0,"name":"crucible","level":30,"time":"2024-07-31T18:29:11.443194947Z","hostname":"w-01J450MRXTE9TPPNZEBAC250HX","pid":1220}
2052024-07-31T18:29:12.947ZRead and Verify all blocks (0..50 range:false)
2062024-07-31T18:29:12.951ZWrote out file "/var/tmp/test_up/verify_file"
2072024-07-31T18:29:12.951ZCLIENT: Tests done. All submitted work has been ACK'd
2082024-07-31T18:29:12.954Z----------------------------------------------------------------
2092024-07-31T18:29:12.954Z Crucible gen:31 GIO:true work queues: Upstairs:0 downstairs:1
2102024-07-31T18:29:12.954ZStates: Active Active Active
2112024-07-31T18:29:12.954ZGW_ID ACK DSID TYPE BKS/EXT DS:0 DS:1 DS:2 REPLAY
2122024-07-31T18:29:12.954Z 3 Acked 1002 Read 50 Done Done Done false
2132024-07-31T18:29:12.955Z STATES DS:0 DS:1 DS:2 TOTAL
2142024-07-31T18:29:12.955Z New 0 0 0 0
2152024-07-31T18:29:12.955Z Sent 0 0 0 0
2162024-07-31T18:29:12.955Z Done 1 1 1 3
2172024-07-31T18:29:12.955Z Skipped 0 0 0 0
2182024-07-31T18:29:12.955Z Error 0 0 0 0
2192024-07-31T18:29:12.955ZLast Flush: 1001 1001 1001
2202024-07-31T18:29:12.955ZDownstairs last five completed: 1001 1000
2212024-07-31T18:29:12.955ZUpstairs last five completed: 3 2 1
2222024-07-31T18:29:12.955ZCLIENT: Up:0 ds:1 act:3
2232024-07-31T18:29:16.954Z----------------------------------------------------------------
2242024-07-31T18:29:16.954Z Crucible gen:31 GIO:true work queues: Upstairs:0 downstairs:0
2252024-07-31T18:29:16.954ZDownstairs last five completed: 1003 1002 1001 1000
2262024-07-31T18:29:16.954ZUpstairs last five completed: 4 3 2 1
2272024-07-31T18:29:16.954ZCLIENT: Up:0 ds:0 act:3
2282024-07-31T18:29:16.954ZCLIENT: All crucible jobs finished, exiting program
2292024-07-31T18:29:16.957Z{"msg":"Guest handle has been dropped","v":0,"name":"crucible","level":40,"time":"2024-07-31T18:29:15.456998474Z","hostname":"w-01J450MRXTE9TPPNZEBAC250HX","pid":1220}
2302024-07-31T18:29:16.962ZRepair setup passed
2312024-07-31T18:29:16.966ZCopy the 8830 file
2322024-07-31T18:29:16.969Zcp -r /var/tmp/test_up/8830 /var/tmp/test_up/previous
2332024-07-31T18:29:16.972Z/var/tmp/bins/crutest repair -g 32 -q -t 127.0.0.1:8810 -t 127.0.0.1:8820 -t 127.0.0.1:8830 --verify-out /var/tmp/test_up/verify_file --verify-in /var/tmp/test_up/verify_file
2342024-07-31T18:29:16.983Z{"msg":"Upstairs starts","v":0,"name":"crucible","level":30,"time":"2024-07-31T18:29:15.486491574Z","hostname":"w-01J450MRXTE9TPPNZEBAC250HX","pid":1226}
2352024-07-31T18:29:16.987Z{"msg":"Crucible Version: BuildInfo {\n version: \"0.0.1\",\n git_sha: \"5ae6bd0137b92ba7ccd4c1802a9f2f433ead0b4c\",\n git_commit_timestamp: \"2024-07-31T18:11:08.000000000Z\",\n git_branch: \"main\",\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-07-31T18:29:15.486998801Z","hostname":"w-01J450MRXTE9TPPNZEBAC250HX","pid":1226}
2362024-07-31T18:29:16.987Z{"msg":"Upstairs <-> Downstairs Message Version: 11","v":0,"name":"crucible","level":30,"time":"2024-07-31T18:29:15.487057172Z","hostname":"w-01J450MRXTE9TPPNZEBAC250HX","pid":1226}
2372024-07-31T18:29:16.987Z{"msg":"Crucible ef7fd5ea-ea82-43ec-8284-8072bdea12b3 has session id: f2e0e4ab-3358-44e8-984d-3c11bf09fb52","v":0,"name":"crucible","level":30,"time":"2024-07-31T18:29:15.487188123Z","hostname":"w-01J450MRXTE9TPPNZEBAC250HX","pid":1226,"session_id":"f2e0e4ab-3358-44e8-984d-3c11bf09fb52"}
2382024-07-31T18:29:16.987Z{"msg":"Upstairs opts: Upstairs UUID: ef7fd5ea-ea82-43ec-8284-8072bdea12b3, Targets: [127.0.0.1:8810, 127.0.0.1:8820, 127.0.0.1:8830], lossy: false, flush_timeout: None, key populated: false, cert_pem populated: false, key_pem populated: false, root_cert_pem populated: false, Control: None, read_only: false","v":0,"name":"crucible","level":30,"time":"2024-07-31T18:29:15.487236626Z","hostname":"w-01J450MRXTE9TPPNZEBAC250HX","pid":1226,"session_id":"f2e0e4ab-3358-44e8-984d-3c11bf09fb52"}
2392024-07-31T18:29:16.987Z{"msg":"Crucible stats registered with UUID: ef7fd5ea-ea82-43ec-8284-8072bdea12b3","v":0,"name":"crucible","level":30,"time":"2024-07-31T18:29:15.487261263Z","hostname":"w-01J450MRXTE9TPPNZEBAC250HX","pid":1226,"session_id":"f2e0e4ab-3358-44e8-984d-3c11bf09fb52"}
2402024-07-31T18:29:16.987ZCrucible runtime is spawned
2412024-07-31T18:29:16.987Z{"msg":"The guest has requested activation with gen:32","v":0,"name":"crucible","level":30,"time":"2024-07-31T18:29:15.48762551Z","hostname":"w-01J450MRXTE9TPPNZEBAC250HX","pid":1226}
2422024-07-31T18:29:16.987Z{"msg":"ef7fd5ea-ea82-43ec-8284-8072bdea12b3 active request set","v":0,"name":"crucible","level":30,"time":"2024-07-31T18:29:15.487747182Z","hostname":"w-01J450MRXTE9TPPNZEBAC250HX","pid":1226,"session_id":"f2e0e4ab-3358-44e8-984d-3c11bf09fb52"}
2432024-07-31T18:29:16.987Z{"msg":"sending connect oneshot to client","v":0,"name":"crucible","level":30,"time":"2024-07-31T18:29:15.487785476Z","hostname":"w-01J450MRXTE9TPPNZEBAC250HX","pid":1226,"client":"0","":"downstairs","session_id":"f2e0e4ab-3358-44e8-984d-3c11bf09fb52"}
2442024-07-31T18:29:16.987Z{"msg":"client set_active_request while in New; waiting...","v":0,"name":"crucible","level":30,"time":"2024-07-31T18:29:15.487820501Z","hostname":"w-01J450MRXTE9TPPNZEBAC250HX","pid":1226,"client":"0","":"downstairs","session_id":"f2e0e4ab-3358-44e8-984d-3c11bf09fb52"}
2452024-07-31T18:29:16.987Z{"msg":"sending connect oneshot to client","v":0,"name":"crucible","level":30,"time":"2024-07-31T18:29:15.487842518Z","hostname":"w-01J450MRXTE9TPPNZEBAC250HX","pid":1226,"client":"1","":"downstairs","session_id":"f2e0e4ab-3358-44e8-984d-3c11bf09fb52"}
2462024-07-31T18:29:16.987Z{"msg":"client set_active_request while in New; waiting...","v":0,"name":"crucible","level":30,"time":"2024-07-31T18:29:15.487881272Z","hostname":"w-01J450MRXTE9TPPNZEBAC250HX","pid":1226,"client":"1","":"downstairs","session_id":"f2e0e4ab-3358-44e8-984d-3c11bf09fb52"}
2472024-07-31T18:29:16.987Z{"msg":"sending connect oneshot to client","v":0,"name":"crucible","level":30,"time":"2024-07-31T18:29:15.487903119Z","hostname":"w-01J450MRXTE9TPPNZEBAC250HX","pid":1226,"client":"2","":"downstairs","session_id":"f2e0e4ab-3358-44e8-984d-3c11bf09fb52"}
2482024-07-31T18:29:16.987Z{"msg":"client set_active_request while in New; waiting...","v":0,"name":"crucible","level":30,"time":"2024-07-31T18:29:15.487939634Z","hostname":"w-01J450MRXTE9TPPNZEBAC250HX","pid":1226,"client":"2","":"downstairs","session_id":"f2e0e4ab-3358-44e8-984d-3c11bf09fb52"}
2492024-07-31T18:29:16.987Z{"msg":"connecting to 127.0.0.1:8810","v":0,"name":"crucible","level":30,"time":"2024-07-31T18:29:15.487983348Z","hostname":"w-01J450MRXTE9TPPNZEBAC250HX","pid":1226,"":"io task","client":"0","":"downstairs","session_id":"f2e0e4ab-3358-44e8-984d-3c11bf09fb52"}
2502024-07-31T18:29:16.987Z{"msg":"connecting to 127.0.0.1:8820","v":0,"name":"crucible","level":30,"time":"2024-07-31T18:29:15.488054617Z","hostname":"w-01J450MRXTE9TPPNZEBAC250HX","pid":1226,"":"io task","client":"1","":"downstairs","session_id":"f2e0e4ab-3358-44e8-984d-3c11bf09fb52"}
2512024-07-31T18:29:16.987Z{"msg":"connecting to 127.0.0.1:8830","v":0,"name":"crucible","level":30,"time":"2024-07-31T18:29:15.488088632Z","hostname":"w-01J450MRXTE9TPPNZEBAC250HX","pid":1226,"":"io task","client":"2","":"downstairs","session_id":"f2e0e4ab-3358-44e8-984d-3c11bf09fb52"}
2522024-07-31T18:29:16.987Z{"msg":"ds_connection connected from Ok(127.0.0.1:52000)","v":0,"name":"crucible","level":30,"time":"2024-07-31T18:29:15.488122188Z","hostname":"w-01J450MRXTE9TPPNZEBAC250HX","pid":1226,"":"io task","client":"2","":"downstairs","session_id":"f2e0e4ab-3358-44e8-984d-3c11bf09fb52"}
2532024-07-31T18:29:16.987Z{"msg":"ds_connection connected from Ok(127.0.0.1:38153)","v":0,"name":"crucible","level":30,"time":"2024-07-31T18:29:15.488158302Z","hostname":"w-01J450MRXTE9TPPNZEBAC250HX","pid":1226,"":"io task","client":"0","":"downstairs","session_id":"f2e0e4ab-3358-44e8-984d-3c11bf09fb52"}
2542024-07-31T18:29:16.987Z{"msg":"ds_connection connected from Ok(127.0.0.1:62241)","v":0,"name":"crucible","level":30,"time":"2024-07-31T18:29:15.488350444Z","hostname":"w-01J450MRXTE9TPPNZEBAC250HX","pid":1226,"":"io task","client":"1","":"downstairs","session_id":"f2e0e4ab-3358-44e8-984d-3c11bf09fb52"}
2552024-07-31T18:29:16.987Z{"msg":"ds_transition from New to WaitActive","v":0,"name":"crucible","level":30,"time":"2024-07-31T18:29:15.489085427Z","hostname":"w-01J450MRXTE9TPPNZEBAC250HX","pid":1226,"client":"2","":"downstairs","session_id":"f2e0e4ab-3358-44e8-984d-3c11bf09fb52"}
2562024-07-31T18:29:16.987Z{"msg":"[2] Transition from New to WaitActive","v":0,"name":"crucible","level":30,"time":"2024-07-31T18:29:15.489122282Z","hostname":"w-01J450MRXTE9TPPNZEBAC250HX","pid":1226,"client":"2","":"downstairs","session_id":"f2e0e4ab-3358-44e8-984d-3c11bf09fb52"}
2572024-07-31T18:29:16.987Z{"msg":"ds_transition from New to WaitActive","v":0,"name":"crucible","level":30,"time":"2024-07-31T18:29:15.4891387Z","hostname":"w-01J450MRXTE9TPPNZEBAC250HX","pid":1226,"client":"0","":"downstairs","session_id":"f2e0e4ab-3358-44e8-984d-3c11bf09fb52"}
2582024-07-31T18:29:16.987Z{"msg":"[0] Transition from New to WaitActive","v":0,"name":"crucible","level":30,"time":"2024-07-31T18:29:15.489172365Z","hostname":"w-01J450MRXTE9TPPNZEBAC250HX","pid":1226,"client":"0","":"downstairs","session_id":"f2e0e4ab-3358-44e8-984d-3c11bf09fb52"}
2592024-07-31T18:29:16.987Z{"msg":"ds_transition from New to WaitActive","v":0,"name":"crucible","level":30,"time":"2024-07-31T18:29:15.489200101Z","hostname":"w-01J450MRXTE9TPPNZEBAC250HX","pid":1226,"client":"1","":"downstairs","session_id":"f2e0e4ab-3358-44e8-984d-3c11bf09fb52"}
2602024-07-31T18:29:16.987Z{"msg":"[1] Transition from New to WaitActive","v":0,"name":"crucible","level":30,"time":"2024-07-31T18:29:15.489240905Z","hostname":"w-01J450MRXTE9TPPNZEBAC250HX","pid":1226,"client":"1","":"downstairs","session_id":"f2e0e4ab-3358-44e8-984d-3c11bf09fb52"}
2612024-07-31T18:29:16.987Z{"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-07-31T18:29:15.489830829Z","hostname":"w-01J450MRXTE9TPPNZEBAC250HX","pid":1226,"client":"1","":"downstairs","session_id":"f2e0e4ab-3358-44e8-984d-3c11bf09fb52"}
2622024-07-31T18:29:16.987Z{"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-07-31T18:29:15.489868474Z","hostname":"w-01J450MRXTE9TPPNZEBAC250HX","pid":1226,"client":"2","":"downstairs","session_id":"f2e0e4ab-3358-44e8-984d-3c11bf09fb52"}
2632024-07-31T18:29:16.987Z{"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-07-31T18:29:15.489887841Z","hostname":"w-01J450MRXTE9TPPNZEBAC250HX","pid":1226,"client":"0","":"downstairs","session_id":"f2e0e4ab-3358-44e8-984d-3c11bf09fb52"}
2642024-07-31T18:29:16.991Z{"msg":"ds_transition from WaitActive to WaitQuorum","v":0,"name":"crucible","level":30,"time":"2024-07-31T18:29:15.490275194Z","hostname":"w-01J450MRXTE9TPPNZEBAC250HX","pid":1226,"client":"2","":"downstairs","session_id":"f2e0e4ab-3358-44e8-984d-3c11bf09fb52"}
2652024-07-31T18:29:16.991Z{"msg":"[2] Transition from WaitActive to WaitQuorum","v":0,"name":"crucible","level":30,"time":"2024-07-31T18:29:15.490319068Z","hostname":"w-01J450MRXTE9TPPNZEBAC250HX","pid":1226,"client":"2","":"downstairs","session_id":"f2e0e4ab-3358-44e8-984d-3c11bf09fb52"}
2662024-07-31T18:29:16.991Z{"msg":"Waiting for more clients to be ready","v":0,"name":"crucible","level":30,"time":"2024-07-31T18:29:15.490335595Z","hostname":"w-01J450MRXTE9TPPNZEBAC250HX","pid":1226,"session_id":"f2e0e4ab-3358-44e8-984d-3c11bf09fb52"}
2672024-07-31T18:29:16.991Z{"msg":"ds_transition from WaitActive to WaitQuorum","v":0,"name":"crucible","level":30,"time":"2024-07-31T18:29:15.490348953Z","hostname":"w-01J450MRXTE9TPPNZEBAC250HX","pid":1226,"client":"0","":"downstairs","session_id":"f2e0e4ab-3358-44e8-984d-3c11bf09fb52"}
2682024-07-31T18:29:16.991Z{"msg":"[0] Transition from WaitActive to WaitQuorum","v":0,"name":"crucible","level":30,"time":"2024-07-31T18:29:15.49037142Z","hostname":"w-01J450MRXTE9TPPNZEBAC250HX","pid":1226,"client":"0","":"downstairs","session_id":"f2e0e4ab-3358-44e8-984d-3c11bf09fb52"}
2692024-07-31T18:29:16.991Z{"msg":"Waiting for more clients to be ready","v":0,"name":"crucible","level":30,"time":"2024-07-31T18:29:15.490386438Z","hostname":"w-01J450MRXTE9TPPNZEBAC250HX","pid":1226,"session_id":"f2e0e4ab-3358-44e8-984d-3c11bf09fb52"}
2702024-07-31T18:29:16.991Z{"msg":"ds_transition from WaitActive to WaitQuorum","v":0,"name":"crucible","level":30,"time":"2024-07-31T18:29:15.490399576Z","hostname":"w-01J450MRXTE9TPPNZEBAC250HX","pid":1226,"client":"1","":"downstairs","session_id":"f2e0e4ab-3358-44e8-984d-3c11bf09fb52"}
2712024-07-31T18:29:16.991Z{"msg":"[1] Transition from WaitActive to WaitQuorum","v":0,"name":"crucible","level":30,"time":"2024-07-31T18:29:15.490421143Z","hostname":"w-01J450MRXTE9TPPNZEBAC250HX","pid":1226,"client":"1","":"downstairs","session_id":"f2e0e4ab-3358-44e8-984d-3c11bf09fb52"}
2722024-07-31T18:29:16.991Z{"msg":"[0]R flush_numbers: [1542, 1542, 1542, 1542, 1542]","v":0,"name":"crucible","level":30,"time":"2024-07-31T18:29:15.490436231Z","hostname":"w-01J450MRXTE9TPPNZEBAC250HX","pid":1226,"":"downstairs","":"downstairs","session_id":"f2e0e4ab-3358-44e8-984d-3c11bf09fb52"}
2732024-07-31T18:29:16.991Z{"msg":"[0]R generation: [31, 31, 31, 31, 31]","v":0,"name":"crucible","level":30,"time":"2024-07-31T18:29:15.490458398Z","hostname":"w-01J450MRXTE9TPPNZEBAC250HX","pid":1226,"":"downstairs","":"downstairs","session_id":"f2e0e4ab-3358-44e8-984d-3c11bf09fb52"}
2742024-07-31T18:29:16.991Z{"msg":"[0]R dirty: [false, false, false, false, false]","v":0,"name"Wait for a query_work_queue command to finish before sending IO
2752024-07-31T18:29:16.991Z:"crucible","level":30,"time":"2024-07-31T18:29:15.490476065Z","hostname":"w-01J450MRXTE9TPPNZEBAC250HX","pid":1226,"":"downstairs","":"downstairs","session_id":"f2e0e4ab-3358-44e8-984d-3c11bf09fb52"}
2762024-07-31T18:29:16.991Z{"msg":"[1]R flush_numbers: [1542, 1542, 1542, 1542, 1542]","v":0,"name":"crucible","level":30,"time":"2024-07-31T18:29:15.490491373Z","hostname":"w-01J450MRXTE9TPPNZEBAC250HX","pid":1226,"":"downstairs","":"downstairs","session_id":"f2e0e4ab-3358-44e8-984d-3c11bf09fb52"}
2772024-07-31T18:29:16.991Z{"msg":"[1]R generation: [31, 31, 31, 31, 31]","v":0,"name":"crucible","level":30,"time":"2024-07-31T18:29:15.490505991Z","hostname":"w-01J450MRXTE9TPPNZEBAC250HX","pid":1226,"":"downstairs","":"downstairs","session_id":"f2e0e4ab-3358-44e8-984d-3c11bf09fb52"}
2782024-07-31T18:29:16.991Z{"msg":"[1]R dirty: [false, false, false, false, false]","v":0,"name":"crucible","level":30,"time":"2024-07-31T18:29:15.490520719Z","hostname":"w-01J450MRXTE9TPPNZEBAC250HX","pid":1226,"":"downstairs","":"downstairs","session_id":"f2e0e4ab-3358-44e8-984d-3c11bf09fb52"}
2792024-07-31T18:29:16.991Z{"msg":"[2]R flush_numbers: [1542, 1542, 1542, 1542, 1542]","v":0,"name":"crucible","level":30,"time":"2024-07-31T18:29:15.490543475Z","hostname":"w-01J450MRXTE9TPPNZEBAC250HX","pid":1226,"":"downstairs","":"downstairs","session_id":"f2e0e4ab-3358-44e8-984d-3c11bf09fb52"}
2802024-07-31T18:29:16.991Z{"msg":"[2]R generation: [31, 31, 31, 31, 31]","v":0,"name":"crucible","level":30,"time":"2024-07-31T18:29:15.490558473Z","hostname":"w-01J450MRXTE9TPPNZEBAC250HX","pid":1226,"":"downstairs","":"downstairs","session_id":"f2e0e4ab-3358-44e8-984d-3c11bf09fb52"}
2812024-07-31T18:29:16.991Z{"msg":"[2]R dirty: [false, false, false, false, false]","v":0,"name":"crucible","level":30,"time":"2024-07-31T18:29:15.490585299Z","hostname":"w-01J450MRXTE9TPPNZEBAC250HX","pid":1226,"":"downstairs","":"downstairs","session_id":"f2e0e4ab-3358-44e8-984d-3c11bf09fb52"}
2822024-07-31T18:29:16.991Z{"msg":"Max found gen is 32","v":0,"name":"crucible","level":30,"time":"2024-07-31T18:29:15.490599657Z","hostname":"w-01J450MRXTE9TPPNZEBAC250HX","pid":1226,"":"downstairs","":"downstairs","session_id":"f2e0e4ab-3358-44e8-984d-3c11bf09fb52"}
2832024-07-31T18:29:16.991Z{"msg":"Generation requested: 32 >= found:32","v":0,"name":"crucible","level":30,"time":"2024-07-31T18:29:15.490614075Z","hostname":"w-01J450MRXTE9TPPNZEBAC250HX","pid":1226,"":"downstairs","":"downstairs","session_id":"f2e0e4ab-3358-44e8-984d-3c11bf09fb52"}
2842024-07-31T18:29:16.991Z{"msg":"Next flush: 1543","v":0,"name":"crucible","level":30,"time":"2024-07-31T18:29:15.490635272Z","hostname":"w-01J450MRXTE9TPPNZEBAC250HX","pid":1226,"":"downstairs","":"downstairs","session_id":"f2e0e4ab-3358-44e8-984d-3c11bf09fb52"}
2852024-07-31T18:29:16.991Z{"msg":"All extents match","v":0,"name":"crucible","level":30,"time":"2024-07-31T18:29:15.49064976Z","hostname":"w-01J450MRXTE9TPPNZEBAC250HX","pid":1226,"":"downstairs","":"downstairs","session_id":"f2e0e4ab-3358-44e8-984d-3c11bf09fb52"}
2862024-07-31T18:29:16.991Z{"msg":"No downstairs reconciliation required","v":0,"name":"crucible","level":30,"time":"2024-07-31T18:29:15.490671537Z","hostname":"w-01J450MRXTE9TPPNZEBAC250HX","pid":1226,"session_id":"f2e0e4ab-3358-44e8-984d-3c11bf09fb52"}
2872024-07-31T18:29:16.991Z{"msg":"Transition from WaitQuorum to Active","v":0,"name":"crucible","level":30,"time":"2024-07-31T18:29:15.490684705Z","hostname":"w-01J450MRXTE9TPPNZEBAC250HX","pid":1226,"client":"0","":"downstairs","session_id":"f2e0e4ab-3358-44e8-984d-3c11bf09fb52"}
2882024-07-31T18:29:16.991Z{"msg":"Transition from WaitQuorum to Active","v":0,"name":"crucible","level":30,"time":"2024-07-31T18:29:15.490699753Z","hostname":"w-01J450MRXTE9TPPNZEBAC250HX","pid":1226,"client":"1","":"downstairs","session_id":"f2e0e4ab-3358-44e8-984d-3c11bf09fb52"}
2892024-07-31T18:29:16.992Z{"msg":"Transition from WaitQuorum to Active","v":0,"name":"crucible","level":30,"time":"2024-07-31T18:29:15.49072075Z","hostname":"w-01J450MRXTE9TPPNZEBAC250HX","pid":1226,"client":"2","":"downstairs","session_id":"f2e0e4ab-3358-44e8-984d-3c11bf09fb52"}
2902024-07-31T18:29:16.992Z{"msg":"All required reconciliation work is completed","v":0,"name":"crucible","level":30,"time":"2024-07-31T18:29:15.490735427Z","hostname":"w-01J450MRXTE9TPPNZEBAC250HX","pid":1226,"session_id":"f2e0e4ab-3358-44e8-984d-3c11bf09fb52"}
2912024-07-31T18:29:16.992Z{"msg":"Set Downstairs and Upstairs active after reconciliation","v":0,"name":"crucible","level":30,"time":"2024-07-31T18:29:15.490755225Z","hostname":"w-01J450MRXTE9TPPNZEBAC250HX","pid":1226,"session_id":"f2e0e4ab-3358-44e8-984d-3c11bf09fb52"}
2922024-07-31T18:29:16.992Z{"msg":"ef7fd5ea-ea82-43ec-8284-8072bdea12b3 is now active with session: f2e0e4ab-3358-44e8-984d-3c11bf09fb52","v":0,"name":"crucible","level":30,"time":"2024-07-31T18:29:15.490769662Z","hostname":"w-01J450MRXTE9TPPNZEBAC250HX","pid":1226,"session_id":"f2e0e4ab-3358-44e8-984d-3c11bf09fb52"}
2932024-07-31T18:29:16.992Z{"msg":"Set Active after no reconciliation","v":0,"name":"crucible","level":30,"time":"2024-07-31T18:29:15.490782601Z","hostname":"w-01J450MRXTE9TPPNZEBAC250HX","pid":1226,"session_id":"f2e0e4ab-3358-44e8-984d-3c11bf09fb52"}
2942024-07-31T18:29:16.992Z{"msg":"The guest has finished waiting for activation with:32","v":0,"name":"crucible","level":30,"time":"2024-07-31T18:29:15.490795799Z","hostname":"w-01J450MRXTE9TPPNZEBAC250HX","pid":1226}
2952024-07-31T18:29:16.992ZRegion: es:10 ec:5 bs:4096 ts:204800 tb:50 max_io:50 or 204800
2962024-07-31T18:29:16.992ZLoading write count information from file "/var/tmp/test_up/verify_file"
2972024-07-31T18:29:16.992ZRun Repair workload
2982024-07-31T18:29:16.992Z01/10 Write block 40 len 12288 data: 2 2 2
2992024-07-31T18:29:16.992Z02/10 Flush
3002024-07-31T18:29:16.992Z03/10 Write block 30 len 8192 data: 2 2
3012024-07-31T18:29:16.995Z04/10 Read block 15 len 4096
3022024-07-31T18:29:16.995Z05/10 Write block 2 len 8192 data: 2 2
3032024-07-31T18:29:16.995Z06/10 Read block 9 len 32768
3042024-07-31T18:29:16.995Z07/10 Write block 29 len 32768 data: 2 3 3 2 2 2 2 2
3052024-07-31T18:29:16.995Z08/10 Write block 46 len 8192 data: 2 2
3062024-07-31T18:29:16.995Z09/10 Write block 15 len 36864 data: 2 2 2 2 2 2 2 2 2
3072024-07-31T18:29:16.995Z10/10 Read block 43 len 12288
3082024-07-31T18:29:16.998Z----------------------------------------------------------------
3092024-07-31T18:29:16.998Z Crucible gen:32 GIO:true work queues: Upstairs:0 downstairs:8
3102024-07-31T18:29:16.998ZStates: Active Active Active
3112024-07-31T18:29:16.998ZGW_ID ACK DSID TYPE BKS/EXT DS:0 DS:1 DS:2 REPLAY
3122024-07-31T18:29:16.998Z 3 Acked 1002 Write 2 Done Done Done false
3132024-07-31T18:29:16.998Z 4 Acked 1003 Read 1 Done Done Done false
3142024-07-31T18:29:16.998Z 5 Acked 1004 Write 2 Done Done Done false
3152024-07-31T18:29:16.998Z 6 Acked 1005 Read 8 Done Done Done false
3162024-07-31T18:29:16.998Z 7 Acked 1006 Write 8 Done Done Done false
3172024-07-31T18:29:16.998Z 8 Acked 1007 Write 2 Done Done Done false
3182024-07-31T18:29:16.998Z 9 Acked 1008 Write 9 Done Sent Done false
3192024-07-31T18:29:16.998Z 10 Acked 1009 Read 3 Done Sent Sent false
3202024-07-31T18:29:16.998Z STATES DS:0 DS:1 DS:2 TOTAL
3212024-07-31T18:29:16.998Z New 0 0 0 0
3222024-07-31T18:29:16.998Z Sent 0 2 1 3
3232024-07-31T18:29:16.998Z Done 8 6 7 21
3242024-07-31T18:29:16.999Z Skipped 0 0 0 0
3252024-07-31T18:29:16.999Z Error 0 0 0 0
3262024-07-31T18:29:16.999ZLast Flush: 1001 1001 1001
3272024-07-31T18:29:16.999ZDownstairs last five completed: 1001 1000
3282024-07-31T18:29:16.999ZUpstairs last five completed: 10 9 8 7 6
3292024-07-31T18:29:16.999Z{"msg":"Guest handle has been dropped","v":0,"name":"crucible","level":40,"time":"2024-07-31T18:29:15.499363722Z","hostname":"w-01J450MRXTE9TPPNZEBAC250HX","pid":1226}
3302024-07-31T18:29:16.999ZWrote out file "/var/tmp/test_up/verify_file"
3312024-07-31T18:29:17.002ZRepair part 1 passed
3322024-07-31T18:29:17.002Z
3332024-07-31T18:29:17.002ZKill the current downstairs
3342024-07-31T18:29:17.113Zrm -rf /var/tmp/test_up/8830
3352024-07-31T18:29:17.113ZNow put back the original so we have a mismatch
3362024-07-31T18:29:17.113Zmv /var/tmp/test_up/previous /var/tmp/test_up/8830
3372024-07-31T18:29:17.117ZRestart downstairs with old directory
3382024-07-31T18:29:17.171Z/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
3392024-07-31T18:29:17.190ZEXT BLOCKS GEN0 GEN1 GEN2 FL0 FL1 FL2 D0 D1 D2 DIFF
3402024-07-31T18:29:17.190Z 0 000-009 31 31 31 1542 1542 1542 T T F <---
3412024-07-31T18:29:17.194Z 1 010-019 31 31 31 1542 1542 1542 T T F <---
3422024-07-31T18:29:17.194Z 2 020-029 31 31 31 1542 1542 1542 T T F <---
3432024-07-31T18:29:17.194Z 3 030-039 31 31 31 1542 1542 1542 T T F <---
3442024-07-31T18:29:17.194Z 4 040-049 32 32 31 1543 1543 1542 T T F <---
3452024-07-31T18:29:17.194ZMax gen: 32, Max flush: 1543
3462024-07-31T18:29:17.194ZError: Difference in extent metadata found!
3472024-07-31T18:29:17.194Zdump test found error as expected
3482024-07-31T18:29:17.194Z
3492024-07-31T18:29:17.194Z
3502024-07-31T18:29:17.194Z/var/tmp/bins/crutest deactivate --range -g 33 -q -t 127.0.0.1:8810 -t 127.0.0.1:8820 -t 127.0.0.1:8830 --verify-out /var/tmp/test_up/verify_file --verify-in /var/tmp/test_up/verify_file
3512024-07-31T18:29:17.206Z{"msg":"Upstairs starts","v":0,"name":"crucible","level":30,"time":"2024-07-31T18:29:15.708965808Z","hostname":"w-01J450MRXTE9TPPNZEBAC250HX","pid":1233}
3522024-07-31T18:29:17.209Z{"msg":"Crucible Version: BuildInfo {\n version: \"0.0.1\",\n git_sha: \"5ae6bd0137b92ba7ccd4c1802a9f2f433ead0b4c\",\n git_commit_timestamp: \"2024-07-31T18:11:08.000000000Z\",\n git_branch: \"main\",\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-07-31T18:29:15.709419022Z","hostname":"w-01J450MRXTE9TPPNZEBAC250HX","pid":1233}
3532024-07-31T18:29:17.210Z{"msg":"Upstairs <-> Downstairs Message Version: 11","v":0,"name":"crucible","level":30,"time":"2024-07-31T18:29:15.709487572Z","hostname":"w-01J450MRXTE9TPPNZEBAC250HX","pid":1233}
3542024-07-31T18:29:17.210Z{"msg":"Crucible 80a52102-f967-4b3f-8c85-9166264c26e1 has session id: a7621ac6-e4a4-44ff-a3ab-018e145e44d2","v":0,"name":"crucible","level":30,"time":"2024-07-31T18:29:15.709677324Z","hostname":"w-01J450MRXTE9TPPNZEBAC250HX","pid":1233,"session_id":"a7621ac6-e4a4-44ff-a3ab-018e145e44d2"}
3552024-07-31T18:29:17.210Z{"msg":"Upstairs opts: Upstairs UUID: 80a52102-f967-4b3f-8c85-9166264c26e1, Targets: [127.0.0.1:8810, 127.0.0.1:8820, 127.0.0.1:8830], lossy: false, flush_timeout: None, key populated: false, cert_pem populated: false, key_pem populated: false, root_cert_pem populated: false, Control: None, read_only: false","v":0,"name":"crucible","level":30,"time":"2024-07-31T18:29:15.709734576Z","hostname":"w-01J450MRXTE9TPPNZEBAC250HX","pid":1233,"session_id":"a7621ac6-e4a4-44ff-a3ab-018e145e44d2"}
3562024-07-31T18:29:17.210Z{"msg":"Crucible stats registered with UUID: 80a52102-f967-4b3f-8c85-9166264c26e1","v":0,"name":"crucible","level":30,"time":"2024-07-31T18:29:15.709765701Z","hostname":"w-01J450MRXTE9TPPNZEBAC250HX","pid":1233,"session_id":"a7621ac6-e4a4-44ff-a3ab-018e145e44d2"}
3572024-07-31T18:29:17.210ZCrucible runtime is spawned
3582024-07-31T18:29:17.210Z{"msg":"The guest has requested activation with gen:33","v":0,"name":"crucible","level":30,"time":"2024-07-31T18:29:15.710088634Z","hostname":"w-01J450MRXTE9TPPNZEBAC250HX","pid":1233}
3592024-07-31T18:29:17.210Z{"msg":"80a52102-f967-4b3f-8c85-9166264c26e1 active request set","v":0,"name":"crucible","level":30,"time":"2024-07-31T18:29:15.71012111Z","hostname":"w-01J450MRXTE9TPPNZEBAC250HX","pid":1233,"session_id":"a7621ac6-e4a4-44ff-a3ab-018e145e44d2"}
3602024-07-31T18:29:17.210Z{"msg":"sending connect oneshot to client","v":0,"name":"crucible","level":30,"time":"2024-07-31T18:29:15.710142746Z","hostname":"w-01J450MRXTE9TPPNZEBAC250HX","pid":1233,"client":"0","":"downstairs","session_id":"a7621ac6-e4a4-44ff-a3ab-018e145e44d2"}
3612024-07-31T18:29:17.210Z{"msg":"client set_active_request while in New; waiting...","v":0,"name":"crucible","level":30,"time":"2024-07-31T18:29:15.71018637Z","hostname":"w-01J450MRXTE9TPPNZEBAC250HX","pid":1233,"client":"0","":"downstairs","session_id":"a7621ac6-e4a4-44ff-a3ab-018e145e44d2"}
3622024-07-31T18:29:17.210Z{"msg":"sending connect oneshot to client","v":0,"name":"crucible","level":30,"time":"2024-07-31T18:29:15.710210357Z","hostname":"w-01J450MRXTE9TPPNZEBAC250HX","pid":1233,"client":"1","":"downstairs","session_id":"a7621ac6-e4a4-44ff-a3ab-018e145e44d2"}
3632024-07-31T18:29:17.210Z{"msg":"client set_active_request while in New; waiting...","v":0,"name":"crucible","level":30,"time":"2024-07-31T18:29:15.710244852Z","hostname":"w-01J450MRXTE9TPPNZEBAC250HX","pid":1233,"client":"1","":"downstairs","session_id":"a7621ac6-e4a4-44ff-a3ab-018e145e44d2"}
3642024-07-31T18:29:17.210Z{"msg":"sending connect oneshot to client","v":0,"name":"crucible","level":30,"time":"2024-07-31T18:29:15.710261429Z","hostname":"w-01J450MRXTE9TPPNZEBAC250HX","pid":1233,"client":"2","":"downstairs","session_id":"a7621ac6-e4a4-44ff-a3ab-018e145e44d2"}
3652024-07-31T18:29:17.210Z{"msg":"client set_active_request while in New; waiting...","v":0,"name":"crucible","level":30,"time":"2024-07-31T18:29:15.710292935Z","hostname":"w-01J450MRXTE9TPPNZEBAC250HX","pid":1233,"client":"2","":"downstairs","session_id":"a7621ac6-e4a4-44ff-a3ab-018e145e44d2"}
3662024-07-31T18:29:17.210Z{"msg":"connecting to 127.0.0.1:8810","v":0,"name":"crucible","level":30,"time":"2024-07-31T18:29:15.710314961Z","hostname":"w-01J450MRXTE9TPPNZEBAC250HX","pid":1233,"":"io task","client":"0","":"downstairs","session_id":"a7621ac6-e4a4-44ff-a3ab-018e145e44d2"}
3672024-07-31T18:29:17.210Z{"msg":"connecting to 127.0.0.1:8830","v":0,"name":"crucible","level":30,"time":"2024-07-31T18:29:15.710352086Z","hostname":"w-01J450MRXTE9TPPNZEBAC250HX","pid":1233,"":"io task","client":"2","":"downstairs","session_id":"a7621ac6-e4a4-44ff-a3ab-018e145e44d2"}
3682024-07-31T18:29:17.210Z{"msg":"connecting to 127.0.0.1:8820","v":0,"name":"crucible","level":30,"time":"2024-07-31T18:29:15.710386941Z","hostname":"w-01J450MRXTE9TPPNZEBAC250HX","pid":1233,"":"io task","client":"1","":"downstairs","session_id":"a7621ac6-e4a4-44ff-a3ab-018e145e44d2"}
3692024-07-31T18:29:17.210Z{"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-07-31T18:29:15.710417877Z","hostname":"w-01J450MRXTE9TPPNZEBAC250HX","pid":1233,"":"io task","client":"2","":"downstairs","session_id":"a7621ac6-e4a4-44ff-a3ab-018e145e44d2"}
3702024-07-31T18:29:17.210Z{"msg":"client task is sending Done(ConnectionFailed(Os { code: 146, kind: ConnectionRefused, message: \"Connection refused\" }))","v":0,"name":"crucible","level":40,"time":"2024-07-31T18:29:15.710444963Z","hostname":"w-01J450MRXTE9TPPNZEBAC250HX","pid":1233,"":"io task","client":"2","":"downstairs","session_id":"a7621ac6-e4a4-44ff-a3ab-018e145e44d2"}
3712024-07-31T18:29:17.210Z{"msg":"ds_connection connected from Ok(127.0.0.1:54531)","v":0,"name":"crucible","level":30,"time":"2024-07-31T18:29:15.710477708Z","hostname":"w-01J450MRXTE9TPPNZEBAC250HX","pid":1233,"":"io task","client":"0","":"downstairs","session_id":"a7621ac6-e4a4-44ff-a3ab-018e145e44d2"}
3722024-07-31T18:29:17.210Z{"msg":"ds_connection connected from Ok(127.0.0.1:50688)","v":0,"name":"crucible","level":30,"time":"2024-07-31T18:29:15.710501174Z","hostname":"w-01J450MRXTE9TPPNZEBAC250HX","pid":1233,"":"io task","client":"1","":"downstairs","session_id":"a7621ac6-e4a4-44ff-a3ab-018e145e44d2"}
3732024-07-31T18:29:17.210Z{"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-07-31T18:29:15.710538479Z","hostname":"w-01J450MRXTE9TPPNZEBAC250HX","pid":1233,"session_id":"a7621ac6-e4a4-44ff-a3ab-018e145e44d2"}
3742024-07-31T18:29:17.210Z{"msg":"Gone missing, transition from New to Disconnected","v":0,"name":"crucible","level":30,"time":"2024-07-31T18:29:15.710562016Z","hostname":"w-01J450MRXTE9TPPNZEBAC250HX","pid":1233,"client":"2","":"downstairs","session_id":"a7621ac6-e4a4-44ff-a3ab-018e145e44d2"}
3752024-07-31T18:29:17.210Z{"msg":"Disconnected -> New","v":0,"name":"crucible","level":30,"time":"2024-07-31T18:29:15.710684778Z","hostname":"w-01J450MRXTE9TPPNZEBAC250HX","pid":1233,"client":"2","":"downstairs","session_id":"a7621ac6-e4a4-44ff-a3ab-018e145e44d2"}
3762024-07-31T18:29:17.210Z{"msg":"client task is exiting","v":0,"name":"crucible","level":30,"time":"2024-07-31T18:29:15.710731601Z","hostname":"w-01J450MRXTE9TPPNZEBAC250HX","pid":1233,"":"io task","client":"2","":"downstairs","session_id":"a7621ac6-e4a4-44ff-a3ab-018e145e44d2"}
3772024-07-31T18:29:17.210Z{"msg":"ds_transition from New to WaitActive","v":0,"name":"crucible","level":30,"time":"2024-07-31T18:29:15.711293339Z","hostname":"w-01J450MRXTE9TPPNZEBAC250HX","pid":1233,"client":"0","":"downstairs","session_id":"a7621ac6-e4a4-44ff-a3ab-018e145e44d2"}
3782024-07-31T18:29:17.210Z{"msg":"[0] Transition from New to WaitActive","v":0,"name":"crucible","level":30,"time":"2024-07-31T18:29:15.711367528Z","hostname":"w-01J450MRXTE9TPPNZEBAC250HX","pid":1233,"client":"0","":"downstairs","session_id":"a7621ac6-e4a4-44ff-a3ab-018e145e44d2"}
3792024-07-31T18:29:17.211Z{"msg":"ds_transition from New to WaitActive","v":0,"name":"crucible","level":30,"time":"2024-07-31T18:29:15.711402883Z","hostname":"w-01J450MRXTE9TPPNZEBAC250HX","pid":1233,"client":"1","":"downstairs","session_id":"a7621ac6-e4a4-44ff-a3ab-018e145e44d2"}
3802024-07-31T18:29:17.211Z{"msg":"[1] Transition from New to WaitActive","v":0,"name":"crucible","level":30,"time":"2024-07-31T18:29:15.711418911Z","hostname":"w-01J450MRXTE9TPPNZEBAC250HX","pid":1233,"client":"1","":"downstairs","session_id":"a7621ac6-e4a4-44ff-a3ab-018e145e44d2"}
3812024-07-31T18:29:17.211Z{"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-07-31T18:29:15.71191088Z","hostname":"w-01J450MRXTE9TPPNZEBAC250HX","pid":1233,"client":"1","":"downstairs","session_id":"a7621ac6-e4a4-44ff-a3ab-018e145e44d2"}
3822024-07-31T18:29:17.211Z{"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-07-31T18:29:15.712095962Z","hostname":"w-01J450MRXTE9TPPNZEBAC250HX","pid":1233,"client":"0","":"downstairs","session_id":"a7621ac6-e4a4-44ff-a3ab-018e145e44d2"}
3832024-07-31T18:29:17.211Z{"msg":"ds_transition from WaitActive to WaitQuorum","v":0,"name":"crucible","level":30,"time":"2024-07-31T18:29:15.712218235Z","hostname":"w-01J450MRXTE9TPPNZEBAC250HX","pid":1233,"client":"1","":"downstairs","session_id":"a7621ac6-e4a4-44ff-a3ab-018e145e44d2"}
3842024-07-31T18:29:17.211Z{"msg":"[1] Transition from WaitActive to WaitQuorum","v":0,"name":"crucible","level":30,"time":"2024-07-31T18:29:15.712258639Z","hostname":"w-01J450MRXTE9TPPNZEBAC250HX","pid":1233,"client":"1","":"downstairs","session_id":"a7621ac6-e4a4-44ff-a3ab-018e145e44d2"}
3852024-07-31T18:29:17.211Z{"msg":"Waiting for more clients to be ready","v":0,"name":"crucible","level":30,"time":"2024-07-31T18:29:15.712284295Z","hostname":"w-01J450MRXTE9TPPNZEBAC250HX","pid":1233,"session_id":"a7621ac6-e4a4-44ff-a3ab-018e145e44d2"}
3862024-07-31T18:29:17.211Z{"msg":"ds_transition from WaitActive to WaitQuorum","v":0,"name":"crucible","level":30,"time":"2024-07-31T18:29:15.712349306Z","hostname":"w-01J450MRXTE9TPPNZEBAC250HX","pid":1233,"client":"0","":"downstairs","session_id":"a7621ac6-e4a4-44ff-a3ab-018e145e44d2"}
3872024-07-31T18:29:17.211Z{"msg":"[0] Transition from WaitActive to WaitQuorum","v":0,"name":"crucible","level":30,"time":"2024-07-31T18:29:15.71238713Z","hostname":"w-01J450MRXTE9TPPNZEBAC250HX","pid":1233,"client":"0","":"downstairs","session_id":"a7621ac6-e4a4-44ff-a3ab-018e145e44d2"}
3882024-07-31T18:29:17.211Z{"msg":"Waiting for more clients to be ready","v":0,"name":"crucible","level":30,"time":"2024-07-31T18:29:15.712423285Z","hostname":"w-01J450MRXTE9TPPNZEBAC250HX","pid":1233,"session_id":"a7621ac6-e4a4-44ff-a3ab-018e145e44d2"}
3892024-07-31T18:29:27.211Z{"msg":"connecting to 127.0.0.1:8830","v":0,"name":"crucible","level":30,"time":"2024-07-31T18:29:25.711974428Z","hostname":"w-01J450MRXTE9TPPNZEBAC250HX","pid":1233,"":"io task","client":"2","":"downstairs","session_id":"a7621ac6-e4a4-44ff-a3ab-018e145e44d2"}
3902024-07-31T18:29:27.211Z{"msg":"ds_connection connected from Ok(127.0.0.1:43327)","v":0,"name":"crucible","level":30,"time":"2024-07-31T18:29:25.712121007Z","hostname":"w-01J450MRXTE9TPPNZEBAC250HX","pid":1233,"":"io task","client":"2","":"downstairs","session_id":"a7621ac6-e4a4-44ff-a3ab-018e145e44d2"}
3912024-07-31T18:29:27.217Z{"msg":"ds_transition from New to WaitActive","v":0,"name":"crucible","level":30,"time":"2024-07-31T18:29:25.713077498Z","hostname":"w-01J450MRXTE9TPPNZEBAC250HX","pid":1233,"client":"2","":"downstairs","session_id":"a7621ac6-e4a4-44ff-a3ab-018e145e44d2"}
3922024-07-31T18:29:27.217Z{"msg":"[2] Transition from New to WaitActive","v":0,"name":"crucible","level":30,"time":"2024-07-31T18:29:25.713104744Z","hostname":"w-01J450MRXTE9TPPNZEBAC250HX","pid":1233,"client":"2","":"downstairs","session_id":"a7621ac6-e4a4-44ff-a3ab-018e145e44d2"}
3932024-07-31T18:29:27.217Z{"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-07-31T18:29:25.713621279Z","hostname":"w-01J450MRXTE9TPPNZEBAC250HX","pid":1233,"client":"2","":"downstairs","session_id":"a7621ac6-e4a4-44ff-a3ab-018e145e44d2"}
3942024-07-31T18:29:27.217Z{"msg":"ds_transition from WaitActive to WaitQuorum","v":0,"name":"crucible","level":30,"time":"2024-07-31T18:29:25.71402846Z","hostname":"w-01J450MRXTE9TPPNZEBAC250HX","pid":1233,"client":"2","":"downstairs","session_id":"a7621ac6-e4a4-44ff-a3ab-018e145e44d2"}
3952024-07-31T18:29:27.217Z{"msg":"[2] Transition from WaitActive to WaitQuorum","v":0,"name":"crucible","level":30,"time":"2024-07-31T18:29:25.714060895Z","hostname":"w-01J450MRXTE9TPPNZEBAC250HX","pid":1233,"client":"2","":"downstairs","session_id":"a7621ac6-e4a4-44ff-a3ab-018e145e44d2"}
3962024-07-31T18:29:27.217Z{"msg":"[0]R flush_numbers: [1542, 1542, 1542, 1542, 1543]","v":0,"name":"crucible","level":30,"time":"2024-07-31T18:29:25.714076213Z","hostname":"w-01J450MRXTE9TPPNZEBAC250HX","pid":1233,"":"downstairs","":"downstairs","session_id":"a7621ac6-e4a4-44ff-a3ab-018e145e44d2"}
3972024-07-31T18:29:27.217Z{"msg":"[0]R generation: [31, 31, 31, 31, 32]","v":0,"name":"crucible","level":30,"time":"2024-07-31T18:29:25.714091291Z","hostname":"w-01J450MRXTE9TPPNZEBAC250HX","pid":1233,"":"downstairs","":"downstairs","session_id":"a7621ac6-e4a4-44ff-a3ab-018e145e44d2"}
3982024-07-31T18:29:27.217Z{"msg":"[0]R dirty: [true, true, true, true, true]","v":0,"name":"crucible","level":30,"time":"2024-07-31T18:29:25.714113347Z","hostname":"w-01J450MRXTE9TPPNZEBAC250HX","pid":1233,"":"downstairs","":"downstairs","session_id":"a7621ac6-e4a4-44ff-a3ab-018e145e44d2"}
3992024-07-31T18:29:27.217Z{"msg":"[1]R flush_numbers: [1542, 1542, 1542, 1542, 1543]","v":0,"name":"crucible","level":30,"time":"2024-07-31T18:29:25.714128295Z","hostname":"w-01J450MRXTE9TPPNZEBAC250HX","pid":1233,"":"downstairs","":"downstairs","session_id":"a7621ac6-e4a4-44ff-a3ab-018e145e44d2"}
4002024-07-31T18:29:27.217Z{"msg":"[1]R generation: [31, 31, 31, 31, 32]","v":0,"name":"crucible","level":30,"time":"2024-07-31T18:29:25.714149152Z","hostname":"w-01J450MRXTE9TPPNZEBAC250HX","pid":1233,"":"downstairs","":"downstairs","session_id":"a7621ac6-e4a4-44ff-a3ab-018e145e44d2"}
4012024-07-31T18:29:27.217Z{"msg":"[1]R dirty: [true, true, true, true, true]","v":0,"name":"crucible","level":30,"time":"2024-07-31T18:29:25.71416295Z","hostname":"w-01J450MRXTE9TPPNZEBAC250HX","pid":1233,"":"downstairs","":"downstairs","session_id":"a7621ac6-e4a4-44ff-a3ab-018e145e44d2"}
4022024-07-31T18:29:27.217Z{"msg":"[2]R flush_numbers: [1542, 1542, 1542, 1542, 1542]","v":0,"name":"crucible","level":30,"time":"2024-07-31T18:29:25.714183317Z","hostname":"w-01J450MRXTE9TPPNZEBAC250HX","pid":1233,"":"downstairs","":"downstairs","session_id":"a7621ac6-e4a4-44ff-a3ab-018e145e44d2"}
4032024-07-31T18:29:27.217Z{"msg":"[2]R generation: [31, 31, 31, 31, 31]","v":0,"name":"crucible","level":30,"time":"2024-07-31T18:29:25.714197355Z","hostname":"w-01J450MRXTE9TPPNZEBAC250HX","pid":1233,"":"downstairs","":"downstairs","session_id":"a7621ac6-e4a4-44ff-a3ab-018e145e44d2"}
4042024-07-31T18:29:27.217Z{"msg":"[2]R dirty: [false, false, false, false, false]","v":0,"name":"crucible","level":30,"time":"2024-07-31T18:29:25.714210693Z","hostname":"w-01J450MRXTE9TPPNZEBAC250HX","pid":1233,"":"downstairs","":"downstairs","session_id":"a7621ac6-e4a4-44ff-a3ab-018e145e44d2"}
4052024-07-31T18:29:27.217Z{"msg":"Max found gen is 33","v":0,"name":"crucible","level":30,"time":"2024-07-31T18:29:25.71423067Z","hostname":"w-01J450MRXTE9TPPNZEBAC250HX","pid":1233,"":"downstairs","":"downstairs","session_id":"a7621ac6-e4a4-44ff-a3ab-018e145e44d2"}
4062024-07-31T18:29:27.217Z{"msg":"Generation requested: 33 >= found:33","v":0,"name":"crucible","level":30,"time":"2024-07-31T18:29:25.714244558Z","hostname":"w-01J450MRXTE9TPPNZEBAC250HX","pid":1233,"":"downstairs","":"downstairs","session_id":"a7621ac6-e4a4-44ff-a3ab-018e145e44d2"}
4072024-07-31T18:29:27.217Z{"msg":"Next flush: 1544","v":0,"name":"crucible","level":30,"time":"2024-07-31T18:29:25.714263895Z","hostname":"w-01J450MRXTE9TPPNZEBAC250HX","pid":1233,"":"downstairs","":"downstairs","session_id":"a7621ac6-e4a4-44ff-a3ab-018e145e44d2"}
4082024-07-31T18:29:27.217Z{"msg":"Extents 0 dirty","v":0,"name":"crucible","level":30,"time":"2024-07-31T18:29:25.714277224Z","hostname":"w-01J450MRXTE9TPPNZEBAC250HX","pid":1233,"":"mend","":"downstairs","":"downstairs","session_id":"a7621ac6-e4a4-44ff-a3ab-018e145e44d2"}
4092024-07-31T18:29:27.217Z{"msg":"First source client ID for extent 0","v":0,"name":"crucible","level":30,"time":"2024-07-31T18:29:25.71429737Z","hostname":"w-01J450MRXTE9TPPNZEBAC250HX","pid":1233,"mrl":"dirty","":"mend","":"downstairs","":"downstairs","session_id":"a7621ac6-e4a4-44ff-a3ab-018e145e44d2"}
4102024-07-31T18:29:27.217Z{"msg":"extent:0 gens: 31 31 31","v":0,"name":"crucible","level":30,"time":"2024-07-31T18:29:25.714311978Z","hostname":"w-01J450MRXTE9TPPNZEBAC250HX","pid":1233,"mrl":"dirty","":"mend","":"downstairs","":"downstairs","session_id":"a7621ac6-e4a4-44ff-a3ab-018e145e44d2"}
4112024-07-31T18:29:27.218Z{"msg":"extent:0 flush: 1542 1542 1542 scs: [ClientId(0), ClientId(1), ClientId(2)]","v":0,"name":"crucible","level":30,"time":"2024-07-31T18:29:25.714333635Z","hostname":"w-01J450MRXTE9TPPNZEBAC250HX","pid":1233,"mrl":"dirty","":"mend","":"downstairs","":"downstairs","session_id":"a7621ac6-e4a4-44ff-a3ab-018e145e44d2"}
4122024-07-31T18:29:27.218Z{"msg":"max_flush now has: [ClientId(0), ClientId(1), ClientId(2)]","v":0,"name":"crucible","level":30,"time":"2024-07-31T18:29:25.714348523Z","hostname":"w-01J450MRXTE9TPPNZEBAC250HX","pid":1233,"mrl":"dirty","":"mend","":"downstairs","":"downstairs","session_id":"a7621ac6-e4a4-44ff-a3ab-018e145e44d2"}
4132024-07-31T18:29:27.218Z{"msg":"extent:0 dirty: true true false","v":0,"name":"crucible","level":30,"time":"2024-07-31T18:29:25.71436917Z","hostname":"w-01J450MRXTE9TPPNZEBAC250HX","pid":1233,"mrl":"dirty","":"mend","":"downstairs","":"downstairs","session_id":"a7621ac6-e4a4-44ff-a3ab-018e145e44d2"}
4142024-07-31T18:29:27.218Z{"msg":"find dest for source 0 for extent at index 0","v":0,"name":"crucible","level":30,"time":"2024-07-31T18:29:25.714383708Z","hostname":"w-01J450MRXTE9TPPNZEBAC250HX","pid":1233,"mrl":"dirty","":"mend","":"downstairs","":"downstairs","session_id":"a7621ac6-e4a4-44ff-a3ab-018e145e44d2"}
4152024-07-31T18:29:27.218Z{"msg":"source 0, add dest 1 source flush","v":0,"name":"crucible","level":30,"time":"2024-07-31T18:29:25.714397836Z","hostname":"w-01J450MRXTE9TPPNZEBAC250HX","pid":1233,"mrl":"dirty","":"mend","":"downstairs","":"downstairs","session_id":"a7621ac6-e4a4-44ff-a3ab-018e145e44d2"}
4162024-07-31T18:29:27.218Z{"msg":"source 0, add dest 2 source flush","v":0,"name":"crucible","level":30,"time":"2024-07-31T18:29:25.714412674Z","hostname":"w-01J450MRXTE9TPPNZEBAC250HX","pid":1233,"mrl":"dirty","":"mend","":"downstairs","":"downstairs","session_id":"a7621ac6-e4a4-44ff-a3ab-018e145e44d2"}
4172024-07-31T18:29:27.218Z{"msg":"Extents 1 dirty","v":0,"name":"crucible","level":30,"time":"2024-07-31T18:29:25.714427242Z","hostname":"w-01J450MRXTE9TPPNZEBAC250HX","pid":1233,"":"mend","":"downstairs","":"downstairs","session_id":"a7621ac6-e4a4-44ff-a3ab-018e145e44d2"}
4182024-07-31T18:29:27.218Z{"msg":"First source client ID for extent 1","v":0,"name":"crucible","level":30,"time":"2024-07-31T18:29:25.714448699Z","hostname":"w-01J450MRXTE9TPPNZEBAC250HX","pid":1233,"mrl":"dirty","":"mend","":"downstairs","":"downstairs","session_id":"a7621ac6-e4a4-44ff-a3ab-018e145e44d2"}
4192024-07-31T18:29:27.218Z{"msg":"extent:1 gens: 31 31 31","v":0,"name":"crucible","level":30,"time":"2024-07-31T18:29:25.714462937Z","hostname":"w-01J450MRXTE9TPPNZEBAC250HX","pid":1233,"mrl":"dirty","":"mend","":"downstairs","":"downstairs","session_id":"a7621ac6-e4a4-44ff-a3ab-018e145e44d2"}
4202024-07-31T18:29:27.218Z{"msg":"extent:1 flush: 1542 1542 1542 scs: [ClientId(0), ClientId(1), ClientId(2)]","v":0,"name":"crucible","level":30,"time":"2024-07-31T18:29:25.714484453Z","hostname":"w-01J450MRXTE9TPPNZEBAC250HX","pid":1233,"mrl":"dirty","":"mend","":"downstairs","":"downstairs","session_id":"a7621ac6-e4a4-44ff-a3ab-018e145e44d2"}
4212024-07-31T18:29:27.218Z{"msg":"max_flush now has: [ClientId(0), ClientId(1), ClientId(2)]","v":0,"name":"crucible","level":30,"time":"2024-07-31T18:29:25.714499301Z","hostname":"w-01J450MRXTE9TPPNZEBAC250HX","pid":1233,"mrl":"dirty","":"mend","":"downstairs","":"downstairs","session_id":"a7621ac6-e4a4-44ff-a3ab-018e145e44d2"}
4222024-07-31T18:29:27.218Z{"msg":"extent:1 dirty: true true false","v":0,"name":"crucible","level":30,"time":"2024-07-31T18:29:25.714520118Z","hostname":"w-01J450MRXTE9TPPNZEBAC250HX","pid":1233,"mrl":"dirty","":"mend","":"downstairs","":"downstairs","session_id":"a7621ac6-e4a4-44ff-a3ab-018e145e44d2"}
4232024-07-31T18:29:27.218Z{"msg":"find dest for source 0 for extent at index 1","v":0,"name":"crucible","level":30,"time":"2024-07-31T18:29:25.714534856Z","hostname":"w-01J450MRXTE9TPPNZEBAC250HX","pid":1233,"mrl":"dirty","":"mend","":"downstairs","":"downstairs","session_id":"a7621ac6-e4a4-44ff-a3ab-018e145e44d2"}
4242024-07-31T18:29:27.218Z{"msg":"source 0, add dest 1 source flush","v":0,"name":"crucible","level":30,"time":"2024-07-31T18:29:25.714555463Z","hostname":"w-01J450MRXTE9TPPNZEBAC250HX","pid":1233,"mrl":"dirty","":"mend","":"downstairs","":"downstairs","session_id":"a7621ac6-e4a4-44ff-a3ab-018e145e44d2"}
4252024-07-31T18:29:27.218Z{"msg":"source 0, add dest 2 source flush","v":0,"name":"crucible","level":30,"time":"2024-07-31T18:29:25.714569851Z","hostname":"w-01J450MRXTE9TPPNZEBAC250HX","pid":1233,"mrl":"dirty","":"mend","":"downstairs","":"downstairs","session_id":"a7621ac6-e4a4-44ff-a3ab-018e145e44d2"}
4262024-07-31T18:29:27.218Z{"msg":"Extents 2 dirty","v":0,"name":"crucible","level":30,"time":"2024-07-31T18:29:25.714587038Z","hostname":"w-01J450MRXTE9TPPNZEBAC250HX","pid":1233,"":"mend","":"downstairs","":"downstairs","session_id":"a7621ac6-e4a4-44ff-a3ab-018e145e44d2"}
4272024-07-31T18:29:27.218Z{"msg":"First source client ID for extent 2","v":0,"name":"crucible","level":30,"time":"2024-07-31T18:29:25.714607056Z","hostname":"w-01J450MRXTE9TPPNZEBAC250HX","pid":1233,"mrl":"dirty","":"mend","":"downstairs","":"downstairs","session_id":"a7621ac6-e4a4-44ff-a3ab-018e145e44d2"}
4282024-07-31T18:29:27.218Z{"msg":"extent:2 gens: 31 31 31","v":0,"name":"crucible","level":30,"time":"2024-07-31T18:29:25.714621443Z","hostname":"w-01J450MRXTE9TPPNZEBAC250HX","pid":1233,"mrl":"dirty","":"mend","":"downstairs","":"downstairs","session_id":"a7621ac6-e4a4-44ff-a3ab-018e145e44d2"}
4292024-07-31T18:29:27.218Z{"msg":"extent:2 flush: 1542 1542 1542 scs: [ClientId(0), ClientId(1), ClientId(2)]","v":0,"name":"crucible","level":30,"time":"2024-07-31T18:29:25.71464284Z","hostname":"w-01J450MRXTE9TPPNZEBAC250HX","pid":1233,"mrl":"dirty","":"mend","":"downstairs","":"downstairs","session_id":"a7621ac6-e4a4-44ff-a3ab-018e145e44d2"}
4302024-07-31T18:29:27.218Z{"msg":"max_flush now has: [ClientId(0), ClientId(1), ClientId(2)]","v":0,"name":"crucible","level":30,"time":"2024-07-31T18:29:25.714657728Z","hostname":"w-01J450MRXTE9TPPNZEBAC250HX","pid":1233,"mrl":"dirty","":"mend","":"downstairs","":"downstairs","session_id":"a7621ac6-e4a4-44ff-a3ab-018e145e44d2"}
4312024-07-31T18:29:27.218Z{"msg":"extent:2 dirty: true true false","v":0,"name":"crucible","level":30,"time":"2024-07-31T18:29:25.714683264Z","hostname":"w-01J450MRXTE9TPPNZEBAC250HX","pid":1233,"mrl":"dirty","":"mend","":"downstairs","":"downstairs","session_id":"a7621ac6-e4a4-44ff-a3ab-018e145e44d2"}
4322024-07-31T18:29:27.218Z{"msg":"find dest for source 0 for extent at index 2","v":0,"name":"crucible","level":30,"time":"2024-07-31T18:29:25.714697802Z","hostname":"w-01J450MRXTE9TPPNZEBAC250HX","pid":1233,"mrl":"dirty","":"mend","":"downstairs","":"downstairs","session_id":"a7621ac6-e4a4-44ff-a3ab-018e145e44d2"}
4332024-07-31T18:29:27.218Z{"msg":"source 0, add dest 1 source flush","v":0,"name":"crucible","level":30,"time":"2024-07-31T18:29:25.714718269Z","hostname":"w-01J450MRXTE9TPPNZEBAC250HX","pid":1233,"mrl":"dirty","":"mend","":"downstairs","":"downstairs","session_id":"a7621ac6-e4a4-44ff-a3ab-018e145e44d2"}
4342024-07-31T18:29:27.218Z{"msg":"source 0, add dest 2 source flush","v":0,"name":"crucible","level":30,"time":"2024-07-31T18:29:25.714732587Z","hostname":"w-01J450MRXTE9TPPNZEBAC250HX","pid":1233,"mrl":"dirty","":"mend","":"downstairs","":"downstairs","session_id":"a7621ac6-e4a4-44ff-a3ab-018e145e44d2"}
4352024-07-31T18:29:27.218Z{"msg":"Extents 3 dirty","v":0,"name":"crucible","level":30,"time":"2024-07-31T18:29:25.714753264Z","hostname":"w-01J450MRXTE9TPPNZEBAC250HX","pid":1233,"":"mend","":"downstairs","":"downstairs","session_id":"a7621ac6-e4a4-44ff-a3ab-018e145e44d2"}
4362024-07-31T18:29:27.219Z{"msg":"First source client ID for extent 3","v":0,"name":"crucible","level":30,"time":"2024-07-31T18:29:25.714767182Z","hostname":"w-01J450MRXTE9TPPNZEBAC250HX","pid":1233,"mrl":"dirty","":"mend","":"downstairs","":"downstairs","session_id":"a7621ac6-e4a4-44ff-a3ab-018e145e44d2"}
4372024-07-31T18:29:27.219Z{"msg":"extent:3 gens: 31 31 31","v":0,"name":"crucible","level":30,"time":"2024-07-31T18:29:25.714787879Z","hostname":"w-01J450MRXTE9TPPNZEBAC250HX","pid":1233,"mrl":"dirty","":"mend","":"downstairs","":"downstairs","session_id":"a7621ac6-e4a4-44ff-a3ab-018e145e44d2"}
4382024-07-31T18:29:27.219Z{"msg":"extent:3 flush: 1542 1542 1542 scs: [ClientId(0), ClientId(1), ClientId(2)]","v":0,"name":"crucible","level":30,"time":"2024-07-31T18:29:25.714803147Z","hostname":"w-01J450MRXTE9TPPNZEBAC250HX","pid":1233,"mrl":"dirty","":"mend","":"downstairs","":"downstairs","session_id":"a7621ac6-e4a4-44ff-a3ab-018e145e44d2"}
4392024-07-31T18:29:27.219Z{"msg":"max_flush now has: [ClientId(0), ClientId(1), ClientId(2)]","v":0,"name":"crucible","level":30,"time":"2024-07-31T18:29:25.714824224Z","hostname":"w-01J450MRXTE9TPPNZEBAC250HX","pid":1233,"mrl":"dirty","":"mend","":"downstairs","":"downstairs","session_id":"a7621ac6-e4a4-44ff-a3ab-018e145e44d2"}
4402024-07-31T18:29:27.219Z{"msg":"extent:3 dirty: true true false","v":0,"name":"crucible","level":30,"time":"2024-07-31T18:29:25.714838652Z","hostname":"w-01J450MRXTE9TPPNZEBAC250HX","pid":1233,"mrl":"dirty","":"mend","":"downstairs","":"downstairs","session_id":"a7621ac6-e4a4-44ff-a3ab-018e145e44d2"}
4412024-07-31T18:29:27.219Z{"msg":"find dest for source 0 for extent at index 3","v":0,"name":"crucible","level":30,"time":"2024-07-31T18:29:25.714860139Z","hostname":"w-01J450MRXTE9TPPNZEBAC250HX","pid":1233,"mrl":"dirty","":"mend","":"downstairs","":"downstairs","session_id":"a7621ac6-e4a4-44ff-a3ab-018e145e44d2"}
4422024-07-31T18:29:27.219Z{"msg":"source 0, add dest 1 source flush","v":0,"name":"crucible","level":30,"time":"2024-07-31T18:29:25.714874497Z","hostname":"w-01J450MRXTE9TPPNZEBAC250HX","pid":1233,"mrl":"dirty","":"mend","":"downstairs","":"downstairs","session_id":"a7621ac6-e4a4-44ff-a3ab-018e145e44d2"}
4432024-07-31T18:29:27.219Z{"msg":"source 0, add dest 2 source flush","v":0,"name":"crucible","level":30,"time":"2024-07-31T18:29:25.714895334Z","hostname":"w-01J450MRXTE9TPPNZEBAC250HX","pid":1233,"mrl":"dirty","":"mend","":"downstairs","":"downstairs","session_id":"a7621ac6-e4a4-44ff-a3ab-018e145e44d2"}
4442024-07-31T18:29:27.219Z{"msg":"Extents 4 dirty","v":0,"name":"crucible","level":30,"time":"2024-07-31T18:29:25.714909572Z","hostname":"w-01J450MRXTE9TPPNZEBAC250HX","pid":1233,"":"mend","":"downstairs","":"downstairs","session_id":"a7621ac6-e4a4-44ff-a3ab-018e145e44d2"}
4452024-07-31T18:29:27.219Z{"msg":"First source client ID for extent 4","v":0,"name":"crucible","level":30,"time":"2024-07-31T18:29:25.714929778Z","hostname":"w-01J450MRXTE9TPPNZEBAC250HX","pid":1233,"mrl":"dirty","":"mend","":"downstairs","":"downstairs","session_id":"a7621ac6-e4a4-44ff-a3ab-018e145e44d2"}
4462024-07-31T18:29:27.219Z{"msg":"extent:4 gens: 32 32 31","v":0,"name":"crucible","level":30,"time":"2024-07-31T18:29:25.714944107Z","hostname":"w-01J450MRXTE9TPPNZEBAC250HX","pid":1233,"mrl":"dirty","":"mend","":"downstairs","":"downstairs","session_id":"a7621ac6-e4a4-44ff-a3ab-018e145e44d2"}
4472024-07-31T18:29:27.219Z{"msg":"extent:4 flush: 1543 1543 1542 scs: [ClientId(0), ClientId(1)]","v":0,"name":"crucible","level":30,"time":"2024-07-31T18:29:25.714965103Z","hostname":"w-01J450MRXTE9TPPNZEBAC250HX","pid":1233,"mrl":"dirty","":"mend","":"downstairs","":"downstairs","session_id":"a7621ac6-e4a4-44ff-a3ab-018e145e44d2"}
4482024-07-31T18:29:27.219Z{"msg":"max_flush now has: [ClientId(0), ClientId(1)]","v":0,"name":"crucible","level":30,"time":"2024-07-31T18:29:25.714979811Z","hostname":"w-01J450MRXTE9TPPNZEBAC250HX","pid":1233,"mrl":"dirty","":"mend","":"downstairs","":"downstairs","session_id":"a7621ac6-e4a4-44ff-a3ab-018e145e44d2"}
4492024-07-31T18:29:27.219Z{"msg":"extent:4 dirty: true true false","v":0,"name":"crucible","level":30,"time":"2024-07-31T18:29:25.715000928Z","hostname":"w-01J450MRXTE9TPPNZEBAC250HX","pid":1233,"mrl":"dirty","":"mend","":"downstairs","":"downstairs","session_id":"a7621ac6-e4a4-44ff-a3ab-018e145e44d2"}
4502024-07-31T18:29:27.219Z{"msg":"find dest for source 0 for extent at index 4","v":0,"name":"crucible","level":30,"time":"2024-07-31T18:29:25.715015486Z","hostname":"w-01J450MRXTE9TPPNZEBAC250HX","pid":1233,"mrl":"dirty","":"mend","":"downstairs","":"downstairs","session_id":"a7621ac6-e4a4-44ff-a3ab-018e145e44d2"}
4512024-07-31T18:29:27.219Z{"msg":"source 0, add dest 1 source flush","v":0,"name":"crucible","level":30,"time":"2024-07-31T18:29:25.715036363Z","hostname":"w-01J450MRXTE9TPPNZEBAC250HX","pid":1233,"mrl":"dirty","":"mend","":"downstairs","":"downstairs","session_id":"a7621ac6-e4a4-44ff-a3ab-018e145e44d2"}
4522024-07-31T18:29:27.219Z{"msg":"source 0, add dest 2 gen","v":0,"name":"crucible","level":30,"time":"2024-07-31T18:29:25.715050761Z","hostname":"w-01J450MRXTE9TPPNZEBAC250HX","pid":1233,"mrl":"dirty","":"mend","":"downstairs","":"downstairs","session_id":"a7621ac6-e4a4-44ff-a3ab-018e145e44d2"}
4532024-07-31T18:29:27.219Z{"msg":"Transition from WaitQuorum to Reconcile","v":0,"name":"crucible","level":30,"time":"2024-07-31T18:29:25.715071728Z","hostname":"w-01J450MRXTE9TPPNZEBAC250HX","pid":1233,"client":"0","":"downstairs","session_id":"a7621ac6-e4a4-44ff-a3ab-018e145e44d2"}
4542024-07-31T18:29:27.219Z{"msg":"Transition from WaitQuorum to Reconcile","v":0,"name":"crucible","level":30,"time":"2024-07-31T18:29:25.715085276Z","hostname":"w-01J450MRXTE9TPPNZEBAC250HX","pid":1233,"client":"1","":"downstairs","session_id":"a7621ac6-e4a4-44ff-a3ab-018e145e44d2"}
4552024-07-31T18:29:27.219Z{"msg":"Transition from WaitQuorum to Reconcile","v":0,"name":"crucible","level":30,"time":"2024-07-31T18:29:25.715105013Z","hostname":"w-01J450MRXTE9TPPNZEBAC250HX","pid":1233,"client":"2","":"downstairs","session_id":"a7621ac6-e4a4-44ff-a3ab-018e145e44d2"}
4562024-07-31T18:29:27.219Z{"msg":"starting reconciliation 8a3a1b07-5e4e-4de3-aedb-10dd361f7600: found 5 extents that need repair","v":0,"name":"crucible","level":30,"time":"2024-07-31T18:29:25.715119571Z","hostname":"w-01J450MRXTE9TPPNZEBAC250HX","pid":1233,"":"downstairs","":"downstairs","session_id":"a7621ac6-e4a4-44ff-a3ab-018e145e44d2"}
4572024-07-31T18:29:27.219Z{"msg":"Full repair list: {ExtentId(0): ExtentFix { source: ClientId(0), dest: [ClientId(1), ClientId(2)] }, ExtentId(4): ExtentFix { source: ClientId(0), dest: [ClientId(1), ClientId(2)] }, ExtentId(2): ExtentFix { source: ClientId(0), dest: [ClientId(1), ClientId(2)] }, ExtentId(1): 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-07-31T18:29:25.715145517Z","hostname":"w-01J450MRXTE9TPPNZEBAC250HX","pid":1233,"":"downstairs","":"downstairs","session_id":"a7621ac6-e4a4-44ff-a3ab-018e145e44d2"}
4582024-07-31T18:29:27.219Z{"msg":"Task list: [ReconcileIO { id: ReconciliationId(0), op: ExtentFlush { repair_id: ReconciliationId(0), extent_id: ExtentId(0), client_id: ClientId(0), flush_number: 1544, gen_number: 33 }, state: ClientData([New, New, New]) }, ReconcileIO { id: ReconciliationId(1), op: ExtentClose { repair_id: ReconciliationId(1), extent_id: ExtentId(0) }, state: ClientData([New, New, New]) }, ReconcileIO { id: ReconciliationId(2), op: ExtentRepair { repair_id: ReconciliationId(2), extent_id: ExtentId(0), source_client_id: ClientId(0), source_repair_address: 0.0.0.0:12810, dest_clients: [ClientId(1), ClientId(2)] }, state: ClientData([New, New, New]) }, ReconcileIO { id: ReconciliationId(3), op: ExtentReopen { repair_id: ReconciliationId(3), extent_id: ExtentId(0) }, state: ClientData([New, New, New]) }, ReconcileIO { id: ReconciliationId(4), op: ExtentFlush { repair_id: ReconciliationId(4), extent_id: ExtentId(4), client_id: ClientId(0), flush_number: 1544, gen_number: 33 }, state: ClientData([New, New, New]) }, ReconcileIO { id: ReconciliationId(5), op: ExtentClose { repair_id: ReconciliationId(5), extent_id: ExtentId(4) }, state: ClientData([New, New, New]) }, ReconcileIO { id: ReconciliationId(6), op: ExtentRepair { repair_id: ReconciliationId(6), 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(7), op: ExtentReopen { repair_id: ReconciliationId(7), extent_id: ExtentId(4) }, state: ClientData([New, New, New]) }, ReconcileIO { id: ReconciliationId(8), op: ExtentFlush { repair_id: ReconciliationId(8), extent_id: ExtentId(2), client_id: ClientId(0), flush_number: 1544, gen_number: 33 }, state: ClientData([New, New, New]) }, ReconcileIO { id: ReconciliationId(9), op: ExtentClose { repair_id: ReconciliationId(9), extent_id: ExtentId(2) }, state: ClientData([New, New, New]) }, ReconcileIO { id: ReconciliationId(10), op: ExtentRepair { repair_id: ReconciliationId(10), extent_id: ExtentId(2), source_client_id: ClientId(0), source_repair_address: 0.0.0.0:12810, dest_clients: [ClientId(1), ClientId(2)] }, state: ClientData([New, New, New]) }, ReconcileIO { id: ReconciliationId(11), op: ExtentReopen { repair_id: ReconciliationId(11), extent_id: ExtentId(2) }, state: ClientData([New, New, New]) }, ReconcileIO { id: ReconciliationId(12), op: ExtentFlush { repair_id: ReconciliationId(12), extent_id: ExtentId(1), client_id: ClientId(0), flush_number: 1544, gen_number: 33 }, state: ClientData([New, New, New]) }, ReconcileIO { id: ReconciliationId(13), op: ExtentClose { repair_id: ReconciliationId(13), extent_id: ExtentId(1) }, state: ClientData([New, New, New]) }, ReconcileIO { id: ReconciliationId(14), op: ExtentRepair { repair_id: ReconciliationId(14), extent_id: ExtentId(1), source_client_id: ClientId(0), source_repair_address: 0.0.0.0:12810, dest_clients: [ClientId(1), ClientId(2)] }, state: ClientData([New, New, New]) }, ReconcileIO { id: ReconciliationId(15), op: ExtentReopen { repair_id: ReconciliationId(15), extent_id: ExtentId(1) }, state: ClientData([New, New, New]) }, ReconcileIO { id: ReconciliationId(16), op: ExtentFlush { repair_id: ReconciliationId(16), extent_id: ExtentId(3), client_id: ClientId(0), flush_number: 1544, gen_number: 33 }, state: ClientData([New, New, New]) }, ReconcileIO { id: ReconciliationId(17), op: ExtentClose { repair_id: ReconciliationId(17), extent_id: ExtentId(3) }, state: ClientData([New, New, New]) }, ReconcileIO { id: ReconciliationId(18), op: ExtentRepair { repair_id: ReconciliationId(18), 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(19), op: ExtentReopen { repair_id: ReconciliationId(19), extent_id: ExtentId(3) }, state: ClientData([New, New, New]) }]","v":0,"name":"crucible","level":30,"time":"2024-07-31T18:29:25.715240603Z","hostname":"w-01J450MRXTE9TPPNZEBAC250HX","pid":1233,"":"downstairs","":"downstairs","session_id":"a7621ac6-e4a4-44ff-a3ab-018e145e44d2"}
4592024-07-31T18:29:27.223Z{"msg":"sending reconcile request ReconciliationId(2)","v":0,"name":"crucible","level":30,"time":"2024-07-31T18:29:25.7159513Z","hostname":"w-01J450MRXTE9TPPNZEBAC250HX","pid":1233,"client":"1","":"downstairs","session_id":"a7621ac6-e4a4-44ff-a3ab-018e145e44d2"}
4602024-07-31T18:29:27.223Z{"msg":"sending reconcile request ReconciliationId(2)","v":0,"name":"crucible","level":30,"time":"2024-07-31T18:29:25.716004042Z","hostname":"w-01J450MRXTE9TPPNZEBAC250HX","pid":1233,"client":"2","":"downstairs","session_id":"a7621ac6-e4a4-44ff-a3ab-018e145e44d2"}
4612024-07-31T18:29:27.230Z{"msg":"sending reconcile request ReconciliationId(6)","v":0,"name":"crucible","level":30,"time":"2024-07-31T18:29:25.731232618Z","hostname":"w-01J450MRXTE9TPPNZEBAC250HX","pid":1233,"client":"1","":"downstairs","session_id":"a7621ac6-e4a4-44ff-a3ab-018e145e44d2"}
4622024-07-31T18:29:27.230Z{"msg":"sending reconcile request ReconciliationId(6)","v":0,"name":"crucible","level":30,"time":"2024-07-31T18:29:25.731276121Z","hostname":"w-01J450MRXTE9TPPNZEBAC250HX","pid":1233,"client":"2","":"downstairs","session_id":"a7621ac6-e4a4-44ff-a3ab-018e145e44d2"}
4632024-07-31T18:29:27.240Z{"msg":"sending reconcile request ReconciliationId(10)","v":0,"name":"crucible","level":30,"time":"2024-07-31T18:29:25.741636014Z","hostname":"w-01J450MRXTE9TPPNZEBAC250HX","pid":1233,"client":"1","":"downstairs","session_id":"a7621ac6-e4a4-44ff-a3ab-018e145e44d2"}
4642024-07-31T18:29:27.240Z{"msg":"sending reconcile request ReconciliationId(10)","v":0,"name":"crucible","level":30,"time":"2024-07-31T18:29:25.741684477Z","hostname":"w-01J450MRXTE9TPPNZEBAC250HX","pid":1233,"client":"2","":"downstairs","session_id":"a7621ac6-e4a4-44ff-a3ab-018e145e44d2"}
4652024-07-31T18:29:27.251Z{"msg":"sending reconcile request ReconciliationId(14)","v":0,"name":"crucible","level":30,"time":"2024-07-31T18:29:25.752276557Z","hostname":"w-01J450MRXTE9TPPNZEBAC250HX","pid":1233,"client":"1","":"downstairs","session_id":"a7621ac6-e4a4-44ff-a3ab-018e145e44d2"}
4662024-07-31T18:29:27.251Z{"msg":"sending reconcile request ReconciliationId(14)","v":0,"name":"crucible","level":30,"time":"2024-07-31T18:29:25.752314381Z","hostname":"w-01J450MRXTE9TPPNZEBAC250HX","pid":1233,"client":"2","":"downstairs","session_id":"a7621ac6-e4a4-44ff-a3ab-018e145e44d2"}
4672024-07-31T18:29:27.260Z{"msg":"sending reconcile request ReconciliationId(18)","v":0,"name":"crucible","level":30,"time":"2024-07-31T18:29:25.761568865Z","hostname":"w-01J450MRXTE9TPPNZEBAC250HX","pid":1233,"client":"1","":"downstairs","session_id":"a7621ac6-e4a4-44ff-a3ab-018e145e44d2"}
4682024-07-31T18:29:27.260Z{"msg":"sending reconcile request ReconciliationId(18)","v":0,"name":"crucible","level":30,"time":"2024-07-31T18:29:25.761609519Z","hostname":"w-01J450MRXTE9TPPNZEBAC250HX","pid":1233,"client":"2","":"downstairs","session_id":"a7621ac6-e4a4-44ff-a3ab-018e145e44d2"}
4692024-07-31T18:29:27.269Z{"msg":"done with reconciliation","v":0,"name":"crucible","level":30,"time":"2024-07-31T18:29:25.770386593Z","hostname":"w-01J450MRXTE9TPPNZEBAC250HX","pid":1233,"":"downstairs","":"downstairs","session_id":"a7621ac6-e4a4-44ff-a3ab-018e145e44d2"}
4702024-07-31T18:29:27.269Z{"msg":"Transition from Reconcile to Active","v":0,"name":"crucible","level":30Wait for a query_work_queue command to finish before sending IO
4712024-07-31T18:29:27.269Z,"time":"2024-07-31T18:29:25.770423967Z","hostname":"w-01J450MRXTE9TPPNZEBAC250HX","pid":1233,"client":"0","":"downstairs","session_id":"a7621ac6-e4a4-44ff-a3ab-018e145e44d2"}
4722024-07-31T18:29:27.269Z{"msg":"Transition from Reconcile to Active","v":0,"name":"crucible","level":30,"time":"2024-07-31T18:29:25.770441095Z","hostname":"w-01J450MRXTE9TPPNZEBAC250HX","pid":1233,"client":"1","":"downstairs","session_id":"a7621ac6-e4a4-44ff-a3ab-018e145e44d2"}
4732024-07-31T18:29:27.273Z{"msg":"Transition from Reconcile to Active","v":0,"name":"crucible","level":30,"time":"2024-07-31T18:29:25.770455093Z","hostname":"w-01J450MRXTE9TPPNZEBAC250HX","pid":1233,"client":"2","":"downstairs","session_id":"a7621ac6-e4a4-44ff-a3ab-018e145e44d2"}
4742024-07-31T18:29:27.273Z{"msg":"All required reconciliation work is completed","v":0,"name":"crucible","level":30,"time":"2024-07-31T18:29:25.7704765Z","hostname":"w-01J450MRXTE9TPPNZEBAC250HX","pid":1233,"session_id":"a7621ac6-e4a4-44ff-a3ab-018e145e44d2"}
4752024-07-31T18:29:27.273Z{"msg":"Set Downstairs and Upstairs active after reconciliation","v":0,"name":"crucible","level":30,"time":"2024-07-31T18:29:25.770499436Z","hostname":"w-01J450MRXTE9TPPNZEBAC250HX","pid":1233,"session_id":"a7621ac6-e4a4-44ff-a3ab-018e145e44d2"}
4762024-07-31T18:29:27.273Z{"msg":"80a52102-f967-4b3f-8c85-9166264c26e1 is now active with session: a7621ac6-e4a4-44ff-a3ab-018e145e44d2","v":0,"name":"crucible","level":30,"time":"2024-07-31T18:29:25.770535911Z","hostname":"w-01J450MRXTE9TPPNZEBAC250HX","pid":1233,"session_id":"a7621ac6-e4a4-44ff-a3ab-018e145e44d2"}
4772024-07-31T18:29:27.273Z{"msg":"The guest has finished waiting for activation with:33","v":0,"name":"crucible","level":30,"time":"2024-07-31T18:29:25.770570036Z","hostname":"w-01J450MRXTE9TPPNZEBAC250HX","pid":1233}
4782024-07-31T18:29:27.273ZRegion: es:10 ec:5 bs:4096 ts:204800 tb:50 max_io:50 or 204800
4792024-07-31T18:29:27.273ZLoading write count information from file "/var/tmp/test_up/verify_file"
4802024-07-31T18:29:27.273ZRead and Verify all blocks (0..50 range:true)
4812024-07-31T18:29:27.277ZWrote out file "/var/tmp/test_up/verify_file"
4822024-07-31T18:29:27.277ZVerify test completed
4832024-07-31T18:29:27.277ZWrote out file "/var/tmp/test_up/verify_file"
4842024-07-31T18:29:27.277ZCLIENT: Tests done. All submitted work has been ACK'd
4852024-07-31T18:29:27.277Z----------------------------------------------------------------
4862024-07-31T18:29:27.277Z Crucible gen:33 GIO:true work queues: Upstairs:0 downstairs:1
4872024-07-31T18:29:27.277ZStates: Active Active Active
4882024-07-31T18:29:27.277ZGW_ID ACK DSID TYPE BKS/EXT DS:0 DS:1 DS:2 REPLAY
4892024-07-31T18:29:27.277Z 1 Acked 1000 Read 50 Done Done Done false
4902024-07-31T18:29:27.277Z STATES DS:0 DS:1 DS:2 TOTAL
4912024-07-31T18:29:27.277Z New 0 0 0 0
4922024-07-31T18:29:27.277Z Sent 0 0 0 0
4932024-07-31T18:29:27.278Z Done 1 1 1 3
4942024-07-31T18:29:27.278Z Skipped 0 0 0 0
4952024-07-31T18:29:27.278Z Error 0 0 0 0
4962024-07-31T18:29:27.278ZLast Flush: 0 0 0
4972024-07-31T18:29:27.278ZDownstairs last five completed:
4982024-07-31T18:29:27.278ZUpstairs last five completed: 1
4992024-07-31T18:29:27.278ZCLIENT: Up:0 ds:1 act:3
5002024-07-31T18:29:31.277Z----------------------------------------------------------------
5012024-07-31T18:29:31.277Z Crucible gen:33 GIO:true work queues: Upstairs:0 downstairs:0
5022024-07-31T18:29:31.277ZDownstairs last five completed: 1001 1000
5032024-07-31T18:29:31.277ZUpstairs last five completed: 2 1
5042024-07-31T18:29:31.277ZCLIENT: Up:0 ds:0 act:3
5052024-07-31T18:29:31.277ZCLIENT: All crucible jobs finished, exiting program
5062024-07-31T18:29:31.280Z{"msg":"Guest handle has been dropped","v":0,"name":"crucible","level":40,"time":"2024-07-31T18:29:29.778640547Z","hostname":"w-01J450MRXTE9TPPNZEBAC250HX","pid":1233}
5072024-07-31T18:29:31.283ZRepair part 2 passed
5082024-07-31T18:29:31.283Z/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
5092024-07-31T18:29:31.298ZEXT BLOCKS GEN0 GEN1 GEN2 FL0 FL1 FL2 D0 D1 D2 DIFF
5102024-07-31T18:29:31.298Z 0 000-009 33 33 33 1544 1544 1544 F F F
5112024-07-31T18:29:31.298Z 1 010-019 33 33 33 1544 1544 1544 F F F
5122024-07-31T18:29:31.298Z 2 020-029 33 33 33 1544 1544 1544 F F F
5132024-07-31T18:29:31.298Z 3 030-039 33 33 33 1544 1544 1544 F F F
5142024-07-31T18:29:31.299Z 4 040-049 33 33 33 1544 1544 1544 F F F
5152024-07-31T18:29:31.299ZMax gen: 33, Max flush: 1544
5162024-07-31T18:29:31.301Zdump test passed
5172024-07-31T18:29:31.304Z/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
5182024-07-31T18:29:31.316Z Extent 1
5192024-07-31T18:29:31.319ZGEN 33 33 33
5202024-07-31T18:29:31.319ZFLUSH_ID 1544 1544 1544
5212024-07-31T18:29:31.319ZDIRTY
5222024-07-31T18:29:31.319Z
5232024-07-31T18:29:31.319ZBLOCK D0 D1 D2 C0 C1 C2 DIFF
5242024-07-31T18:29:31.319Z010 A A A A A A
5252024-07-31T18:29:31.322Z011 A A A A A A
5262024-07-31T18:29:31.322Z012 A A A A A A
5272024-07-31T18:29:31.322Z013 A A A A A A
5282024-07-31T18:29:31.324Z014 A A A A A A
5292024-07-31T18:29:31.327Z015 A A A A A A
5302024-07-31T18:29:31.327Z016 A A A A A A
5312024-07-31T18:29:31.327Z017 A A A A A A
5322024-07-31T18:29:31.329Z018 A A A A A A
5332024-07-31T18:29:31.332Z019 A A A A A A
5342024-07-31T18:29:31.334Zdump extent test passed
5352024-07-31T18:29:31.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 -b 20
5362024-07-31T18:29:31.347ZExtent 2 Block in extent 0 Actual block 20
5372024-07-31T18:29:31.347Z
5382024-07-31T18:29:31.350Z DATA SHA256 VER
5392024-07-31T18:29:31.350Z------ ---------------------------------------------------------------- ---
5402024-07-31T18:29:31.350Z 0 ad3d0e88276af7eb1f904413516e1a8c1f9c2fa8b17b86b2d842d08303e90aa2 A
5412024-07-31T18:29:31.353Z 1 ad3d0e88276af7eb1f904413516e1a8c1f9c2fa8b17b86b2d842d08303e90aa2 A
5422024-07-31T18:29:31.353Z 2 ad3d0e88276af7eb1f904413516e1a8c1f9c2fa8b17b86b2d842d08303e90aa2 A
5432024-07-31T18:29:31.353Z
5442024-07-31T18:29:31.353ZNONCES 0 1 2 DIFF
5452024-07-31T18:29:31.353Z------ ------------------------ ------------------------ ------------------------ -----
5462024-07-31T18:29:31.353Z
5472024-07-31T18:29:31.353Z TAGS 0 1 2 DIFF
5482024-07-31T18:29:31.353Z------ -------------------------------- -------------------------------- -------------------------------- -----
5492024-07-31T18:29:31.353Z
5502024-07-31T18:29:31.353ZHASHES 0 1 2 DIFF
5512024-07-31T18:29:31.353Z------ ---------------- ---------------- ---------------- -----
5522024-07-31T18:29:31.353Z 0 42916ab6fa364c70 42916ab6fa364c70 42916ab6fa364c70
5532024-07-31T18:29:31.353Z
5542024-07-31T18:29:31.356Zdump block test passed
5552024-07-31T18:29:31.356ZUpstairs tests have completed, stopping all downstairs
5562024-07-31T18:29:36.416ZCreating four larger downstairs regions
5572024-07-31T18:29:36.813ZStarting four downstairs
5582024-07-31T18:29:41.821ZNow do the replace-reconcile test
5592024-07-31T18:32:31.812ZCompleted test: replace-reconcile
5602024-07-31T18:32:31.816ZNow do the replace-before-active test
5612024-07-31T18:35:09.775ZCompleted test: replace-before-active
5622024-07-31T18:35:09.775ZTests have completed, stopping all downstairs
5632024-07-31T18:35:09.832Z
5642024-07-31T18:35:09.832ZAll Tests have passed
5652024-07-31T18:35:09.834Z8:10 Test duration
5662024-07-31T18:35:09.835Z
5672024-07-31T18:35:09.835Zreal 8:10.140060643
5682024-07-31T18:35:09.835Zuser 1:12.531948457
5692024-07-31T18:35:09.835Zsys 14.223264460
5702024-07-31T18:35:09.835Ztrap 0.243623467
5712024-07-31T18:35:09.835Ztflt 0.020950860
5722024-07-31T18:35:09.835Zdflt 0.019600587
5732024-07-31T18:35:09.835Zkflt 0.002714790
5742024-07-31T18:35:09.835Zlock 6:09:38.451174501
5752024-07-31T18:35:09.835Zslp 26:56.300531150
5762024-07-31T18:35:09.835Zlat 15.376424406
5772024-07-31T18:35:09.835Zstop 0.149574592
5782024-07-31T18:35:09.835Z+ echo 'test-up-unencrypted ends'
5792024-07-31T18:35:09.835Ztest-up-unencrypted ends
5802024-07-31T18:35:14.839Zprocess exited: duration 497848 ms, exit code 0
5812024-07-31T18:35:14.839Zexec warning: : stdio descriptors remain open after task exit; waiting 60 seconds for them to close
5822024-07-31T18:36:14.854Zexec warning: : stdout descriptor may be held open by a background process; giving up!
5832024-07-31T18:36:14.854Zexec warning: : stderr descriptor may be held open by a background process; giving up!
 
5842024-07-31T18:36:14.867Zfound 14 output files
5852024-07-31T18:36:14.867Zuploading: /tmp/test_up/dsc-out.txt (23489 bytes)
5862024-07-31T18:36:15.881Zuploaded: /tmp/test_up/dsc-out.txt
5872024-07-31T18:36:15.881Zuploading: /tmp/test_up/test_up_out.txt (10267589 bytes)
5882024-07-31T18:36:17.085Zuploaded: /tmp/test_up/test_up_out.txt
5892024-07-31T18:36:17.088Zuploading: /tmp/test_up/dsc/downstairs-8810.txt (2469 bytes)
5902024-07-31T18:36:18.095Zuploaded: /tmp/test_up/dsc/downstairs-8810.txt
5912024-07-31T18:36:18.095Zuploading: /tmp/test_up/dsc/downstairs-8820.txt (140427 bytes)
5922024-07-31T18:36:19.116Zuploaded: /tmp/test_up/dsc/downstairs-8820.txt
5932024-07-31T18:36:19.116Zuploading: /tmp/test_up/dsc/downstairs-8830.txt (246815 bytes)
5942024-07-31T18:36:20.144Zuploaded: /tmp/test_up/dsc/downstairs-8830.txt
5952024-07-31T18:36:20.144Zuploading: /tmp/test_up/dsc/downstairs-8840.txt (135181 bytes)
5962024-07-31T18:36:21.167Zuploaded: /tmp/test_up/dsc/downstairs-8840.txt
5972024-07-31T18:36:21.167Zuploading: /tmp/debug/df.txt (1270 bytes)
5982024-07-31T18:36:22.176Zuploaded: /tmp/debug/df.txt
5992024-07-31T18:36:22.179Zuploading: /tmp/debug/dtrace.txt (520679 bytes)
6002024-07-31T18:36:23.215Zuploaded: /tmp/debug/dtrace.txt
6012024-07-31T18:36:23.215Zuploading: /tmp/debug/iostat.txt (165214 bytes)
6022024-07-31T18:36:23.233Zupload warning: file "/tmp/debug/iostat.txt" changed size mid upload: 165214 -> 167590
6032024-07-31T18:36:24.239Zuploaded: /tmp/debug/iostat.txt
6042024-07-31T18:36:24.242Zuploading: /tmp/debug/mpstat.txt (403658 bytes)
6052024-07-31T18:36:24.268Zupload warning: file "/tmp/debug/mpstat.txt" changed size mid upload: 403658 -> 410192
6062024-07-31T18:36:25.277Zuploaded: /tmp/debug/mpstat.txt
6072024-07-31T18:36:25.280Zuploading: /tmp/debug/paging.txt (71120 bytes)
6082024-07-31T18:36:25.289Zupload warning: file "/tmp/debug/paging.txt" changed size mid upload: 71120 -> 72398
6092024-07-31T18:36:26.297Zuploaded: /tmp/debug/paging.txt
6102024-07-31T18:36:26.297Zuploading: /tmp/debug/prstat.txt (764873 bytes)
6112024-07-31T18:36:26.337Zupload warning: file "/tmp/debug/prstat.txt" changed size mid upload: 764873 -> 779067
6122024-07-31T18:36:27.345Zuploaded: /tmp/debug/prstat.txt
6132024-07-31T18:36:27.345Zuploading: /tmp/debug/psrinfo.txt (1528 bytes)
6142024-07-31T18:36:28.356Zuploaded: /tmp/debug/psrinfo.txt
6152024-07-31T18:36:28.356Zuploading: /tmp/debug/upstairs-info.txt (88500 bytes)
6162024-07-31T18:36:29.374Zuploaded: /tmp/debug/upstairs-info.txt