01JEW0KXEC54NA77SEZG3Z3MPM: test-up-encrypted

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

Buildomat Job: 01JEW0M6CK1WBS8BY61D8WEPY7

Tags:

Artefacts:

Output:

SEQ GLOBAL TIME DETAILS
12024-12-11T23:38:59.948Zjob dependencies complete; ready to run (waiting for 14 m 10 s)
22024-12-11T23:40:03.090Zjob assigned to worker 01JEW1EECADXAJNR7ZZ07QNGFT [factory aws, i-0a378b0b5f7c99f3f] (queued for 1 m 3 s)
32024-12-11T23:40:12.375Zdownloading input: /input/build/work/bins/crucible-downstairs.gz
42024-12-11T23:40:13.467Zdownloaded input: /input/build/work/bins/crucible-downstairs.gz
52024-12-11T23:40:13.467Zdownloading input: /input/build/work/bins/crucible-hammer.gz
62024-12-11T23:40:14.526Zdownloaded input: /input/build/work/bins/crucible-hammer.gz
72024-12-11T23:40:14.526Zdownloading input: /input/build/work/bins/crutest.gz
82024-12-11T23:40:15.645Zdownloaded input: /input/build/work/bins/crutest.gz
92024-12-11T23:40:15.645Zdownloading input: /input/build/work/bins/dsc.gz
102024-12-11T23:40:16.313Zdownloaded input: /input/build/work/bins/dsc.gz
112024-12-11T23:40:16.316Zdownloading input: /input/build/work/scripts/perf-downstairs-tick.d
122024-12-11T23:40:16.331Zdownloaded input: /input/build/work/scripts/perf-downstairs-tick.d
132024-12-11T23:40:16.331Zdownloading input: /input/build/work/scripts/test_ds.sh
142024-12-11T23:40:16.349Zdownloaded input: /input/build/work/scripts/test_ds.sh
152024-12-11T23:40:16.349Zdownloading input: /input/build/work/scripts/test_live_repair.sh
162024-12-11T23:40:16.366Zdownloaded input: /input/build/work/scripts/test_live_repair.sh
172024-12-11T23:40:16.366Zdownloading input: /input/build/work/scripts/test_repair.sh
182024-12-11T23:40:16.392Zdownloaded input: /input/build/work/scripts/test_repair.sh
192024-12-11T23:40:16.392Zdownloading input: /input/build/work/scripts/test_replay.sh
202024-12-11T23:40:16.410Zdownloaded input: /input/build/work/scripts/test_replay.sh
212024-12-11T23:40:16.410Zdownloading input: /input/build/work/scripts/test_up.sh
222024-12-11T23:40:16.426Zdownloaded input: /input/build/work/scripts/test_up.sh
232024-12-11T23:40:16.426Zdownloading input: /input/build/work/scripts/upstairs_info.d
242024-12-11T23:40:16.443Zdownloaded input: /input/build/work/scripts/upstairs_info.d
252024-12-11T23:40:16.445Zdownloading input: /input/build/tmp/cargo-test-out.log
262024-12-11T23:40:17.165Zdownloaded input: /input/build/tmp/cargo-test-out.log
 
272024-12-11T23:40:17.165Zstarting task 0: "setup"
282024-12-11T23:40:17.173Z++ uname -s
292024-12-11T23:40:17.176Z+ kern=SunOS
302024-12-11T23:40:17.176Z+ case "$kern" in
312024-12-11T23:40:17.176Z+ groupadd -g 12345 build
322024-12-11T23:40:17.178Z+ useradd -u 12345 -g build -d /home/build -s /bin/bash -c build -P 'Primary Administrator' build
332024-12-11T23:40:19.186Z+ zfs create -o mountpoint=/work rpool/work
342024-12-11T23:40:19.379Z++ awk '$2 == "/home" { print $3 }' /etc/mnttab
352024-12-11T23:40:19.383Z+ home_fs=zfs
362024-12-11T23:40:19.383Z+ [[ zfs == autofs ]]
372024-12-11T23:40:19.383Z+ mkdir -p /home/build
382024-12-11T23:40:19.386Z+ chown build:build /home/build /work
392024-12-11T23:40:21.386Z+ chmod 0700 /home/build /work
402024-12-11T23:40:21.389Zprocess exited: duration 4225 ms, exit code 0
 
412024-12-11T23:40:21.395Zstarting task 1: "authentication"
422024-12-11T23:40:21.412Zprocess exited: duration 17 ms, exit code 0
 
432024-12-11T23:40:21.417Zstarting task 2: "build"
442024-12-11T23:40:21.423Z+ banner cores
452024-12-11T23:40:21.447Z
462024-12-11T23:40:21.447Z #### #### ##### ###### ####
472024-12-11T23:40:21.447Z # # # # # # # #
482024-12-11T23:40:21.447Z # # # # # ##### ####
492024-12-11T23:40:21.447Z # # # ##### # #
502024-12-11T23:40:21.447Z # # # # # # # # #
512024-12-11T23:40:21.447Z #### #### # # ###### ####
522024-12-11T23:40:21.447Z
532024-12-11T23:40:21.450Z+ pfexec coreadm -i /tmp/core.%f.%p -g /tmp/core.%f.%p -e global -e log -e proc-setid -e global-setid
542024-12-11T23:40:21.455Z+ echo 'input bins dir contains:'
552024-12-11T23:40:21.455Zinput bins dir contains:
562024-12-11T23:40:21.455Z+ ls -ltr /input/build/work/bins
572024-12-11T23:40:21.458Ztotal 760638
582024-12-11T23:40:21.458Z-rw-r--r-- 1 root root 109276510 Dec 11 23:40 crucible-downstairs.gz
592024-12-11T23:40:21.458Z-rw-r--r-- 1 root root 104518811 Dec 11 23:40 crucible-hammer.gz
602024-12-11T23:40:21.458Z-rw-r--r-- 1 root root 108906373 Dec 11 23:40 crutest.gz
612024-12-11T23:40:21.458Z-rw-r--r-- 1 root root 66480704 Dec 11 23:40 dsc.gz
622024-12-11T23:40:21.458Z+ banner unpack
632024-12-11T23:40:21.461Z
642024-12-11T23:40:21.461Z # # # # ##### ## #### # #
652024-12-11T23:40:21.461Z # # ## # # # # # # # # #
662024-12-11T23:40:21.461Z # # # # # # # # # # ####
672024-12-11T23:40:21.461Z # # # # # ##### ###### # # #
682024-12-11T23:40:21.461Z # # # ## # # # # # # #
692024-12-11T23:40:21.461Z #### # # # # # #### # #
702024-12-11T23:40:21.461Z
712024-12-11T23:40:21.461Z+ mkdir -p /var/tmp/bins
722024-12-11T23:40:21.462Z+ for t in "$input/bins/"*.gz
732024-12-11T23:40:21.465Z++ basename /input/build/work/bins/crucible-downstairs.gz
742024-12-11T23:40:21.465Z+ b=crucible-downstairs.gz
752024-12-11T23:40:21.465Z+ b=crucible-downstairs
762024-12-11T23:40:21.465Z+ gunzip
772024-12-11T23:40:23.716Z+ chmod +x /var/tmp/bins/crucible-downstairs
782024-12-11T23:40:23.719Z+ for t in "$input/bins/"*.gz
792024-12-11T23:40:23.722Z++ basename /input/build/work/bins/crucible-hammer.gz
802024-12-11T23:40:23.722Z+ b=crucible-hammer.gz
812024-12-11T23:40:23.722Z+ b=crucible-hammer
822024-12-11T23:40:23.722Z+ gunzip
832024-12-11T23:40:25.878Z+ chmod +x /var/tmp/bins/crucible-hammer
842024-12-11T23:40:25.880Z+ for t in "$input/bins/"*.gz
852024-12-11T23:40:25.882Z++ basename /input/build/work/bins/crutest.gz
862024-12-11T23:40:25.882Z+ b=crutest.gz
872024-12-11T23:40:25.882Z+ b=crutest
882024-12-11T23:40:25.882Z+ gunzip
892024-12-11T23:40:28.175Z+ chmod +x /var/tmp/bins/crutest
902024-12-11T23:40:28.177Z+ for t in "$input/bins/"*.gz
912024-12-11T23:40:28.180Z++ basename /input/build/work/bins/dsc.gz
922024-12-11T23:40:28.180Z+ b=dsc.gz
932024-12-11T23:40:28.180Z+ b=dsc
942024-12-11T23:40:28.180Z+ gunzip
952024-12-11T23:40:29.558Z+ chmod +x /var/tmp/bins/dsc
962024-12-11T23:40:29.561Z+ export BINDIR=/var/tmp/bins
972024-12-11T23:40:29.561Z+ BINDIR=/var/tmp/bins
982024-12-11T23:40:29.561Z+ jobpid=1140
992024-12-11T23:40:29.563Z+ echo 'Setup debug logging'
1002024-12-11T23:40:29.563ZSetup debug logging
1012024-12-11T23:40:29.563Z+ mkdir /tmp/debug
1022024-12-11T23:40:29.563Z+ sleep 3600
1032024-12-11T23:40:29.563Z+ psrinfo -v
1042024-12-11T23:40:29.566Z+ df -h
1052024-12-11T23:40:29.592Z+ prstat -d d -mLc 1
1062024-12-11T23:40:29.594Z+ iostat -T d -xn 1
1072024-12-11T23:40:29.595Z+ mpstat -T d 1
1082024-12-11T23:40:29.595Z+ vmstat -T d -p 1
1092024-12-11T23:40:29.597Z+ pfexec dtrace -Z -s /input/build/work/scripts/perf-downstairs-tick.d
1102024-12-11T23:40:29.597Z+ banner test_up_encrypted
1112024-12-11T23:40:29.597Z+ pfexec dtrace -Z -s /input/build/work/scripts/upstairs_info.d
1122024-12-11T23:40:29.600Z
1132024-12-11T23:40:29.600Z ##### ###### #### ##### # # ##### ###### # #
1142024-12-11T23:40:29.600Z # # # # # # # # # ## #
1152024-12-11T23:40:29.600Z # ##### #### # # # # # ##### # # #
1162024-12-11T23:40:29.600Z # # # # # # ##### # # # #
1172024-12-11T23:40:29.600Z # # # # # # # # # # ##
1182024-12-11T23:40:29.600Z # ###### #### # ####### #### # ####### ###### # #
1192024-12-11T23:40:29.600Z
1202024-12-11T23:40:29.600Z+ ptime -m bash /input/build/work/scripts/test_up.sh -N encrypted
1212024-12-11T23:40:29.609Z/input/build/work
1222024-12-11T23:40:29.640ZTurn off color for downstairs dump
1232024-12-11T23:40:29.674ZUpstairs using key: AQg69ATuOFkflT1lQvu2o0+Avqp7yDvZbvte6DgK0jc=
1242024-12-11T23:40:29.677Zdsc output goes to /tmp/test_up-build/dsc-out.txt
1252024-12-11T23:40:29.677ZCreating 3 downstairs regions
1262024-12-11T23:40:29.989ZStarting 3 downstairs
1272024-12-11T23:40:29.992Zdsc started at PID: 1186
1282024-12-11T23:40:35.178ZDisable automatic restart on all downstairs
1292024-12-11T23:40:35.235Z
1302024-12-11T23:40:35.235ZBegin tests, output goes to /tmp/test_up-build/test_up_out.txt
1312024-12-11T23:40:35.238ZRunning test: span
1322024-12-11T23:40:39.354ZCompleted test: span
1332024-12-11T23:40:44.362ZRunning test: big
1342024-12-11T23:40:48.681ZCompleted test: big
1352024-12-11T23:40:53.689ZRunning test: dep
1362024-12-11T23:41:46.134ZCompleted test: dep
1372024-12-11T23:41:51.142ZRunning test: balloon
1382024-12-11T23:42:31.769ZCompleted test: balloon
1392024-12-11T23:42:36.777ZRunning test: deactivate
1402024-12-11T23:43:31.428ZCompleted test: deactivate
1412024-12-11T23:43:36.436ZRunning hammer
1422024-12-11T23:43:49.358ZRun repair tests
1432024-12-11T23:43:49.361Z/var/tmp/bins/crutest fill -g 31 -q --key AQg69ATuOFkflT1lQvu2o0+Avqp7yDvZbvte6DgK0jc= --dsc 127.0.0.1:9998 --verify-out /var/tmp/test_up-build/verify_file
1442024-12-11T23:43:49.421Z{"msg":"Use this region info from dsc: RegionExtentInfo { block_size: 4096, blocks_per_extent: 10, extent_count: 5 }","v":0,"name":"crucible","level":30,"time":"2024-12-11T23:43:48.518489428Z","hostname":"w-01JEW1EECADXAJNR7ZZ07QNGFT","pid":1223,"task":"crutest"}
1452024-12-11T23:43:49.424Z{"msg":"dsc has 3 regions. This means 1 sub_volumes","v":0,"name":"crucible","level":30,"time":"2024-12-11T23:43:48.519073086Z","hostname":"w-01JEW1EECADXAJNR7ZZ07QNGFT","pid":1223,"task":"crutest"}
1462024-12-11T23:43:49.424Z{"msg":"SV 0 has targets: [127.0.0.1:8810, 127.0.0.1:8820, 127.0.0.1:8830]","v":0,"name":"crucible","level":30,"time":"2024-12-11T23:43:48.52075787Z","hostname":"w-01JEW1EECADXAJNR7ZZ07QNGFT","pid":1223,"task":"crutest"}
1472024-12-11T23:43:49.424Z{"msg":"Upstairs starts","v":0,"name":"crucible","level":30,"time":"2024-12-11T23:43:48.521009066Z","hostname":"w-01JEW1EECADXAJNR7ZZ07QNGFT","pid":1223}
1482024-12-11T23:43:49.424Z{"msg":"Crucible Version: BuildInfo {\n version: \"0.0.1\",\n git_sha: \"d81f7fe7d3a87a2a3c58f4f5d619f7f37b0a05d0\",\n git_commit_timestamp: \"2024-12-11T23:24:14.000000000Z\",\n git_branch: \"mkeeter/separate-notify-task\",\n rustc_semver: \"1.82.0\",\n rustc_channel: \"stable\",\n rustc_host_triple: \"x86_64-unknown-illumos\",\n rustc_commit_sha: \"f6e511eec7342f59a25f7c0534f1dbea00d01b14\",\n cargo_triple: \"x86_64-unknown-illumos\",\n debug: true,\n opt_level: 0,\n}","v":0,"name":"crucible","level":30,"time":"2024-12-11T23:43:48.521078564Z","hostname":"w-01JEW1EECADXAJNR7ZZ07QNGFT","pid":1223}
1492024-12-11T23:43:49.424Z{"msg":"Upstairs <-> Downstairs Message Version: 12","v":0,"name":"crucible","level":30,"time":"2024-12-11T23:43:48.521111758Z","hostname":"w-01JEW1EECADXAJNR7ZZ07QNGFT","pid":1223}
1502024-12-11T23:43:49.424Z{"msg":"Using region definition RegionDefinition { block_size: 4096, extent_size: Block { value: 10, shift: 12 }, extent_count: 5, uuid: 00000000-0000-0000-0000-000000000000, encrypted: true, database_read_version: 1, database_write_version: 1 }","v":0,"name":"crucible","level":30,"time":"2024-12-11T23:43:48.521130975Z","hostname":"w-01JEW1EECADXAJNR7ZZ07QNGFT","pid":1223}
1512024-12-11T23:43:49.427Z{"msg":"Crucible fe8488bd-12a0-435f-856b-9a6bf752b50c has session id: 4686e8df-1cb4-42d0-99ff-44e240b26313","v":0,"name":"crucible","level":30,"time":"2024-12-11T23:43:48.521646204Z","hostname":"w-01JEW1EECADXAJNR7ZZ07QNGFT","pid":1223,"session_id":"4686e8df-1cb4-42d0-99ff-44e240b26313"}
1522024-12-11T23:43:49.427Z{"msg":"Upstairs opts: Upstairs UUID: fe8488bd-12a0-435f-856b-9a6bf752b50c, Targets: [127.0.0.1:8810, 127.0.0.1:8820, 127.0.0.1:8830], lossy: false, flush_timeout: None, key populated: true, cert_pem populated: false, key_pem populated: false, root_cert_pem populated: false, Control: None, read_only: false","v":0,"name":"crucible","level":30,"time":"2024-12-11T23:43:48.521700505Z","hostname":"w-01JEW1EECADXAJNR7ZZ07QNGFT","pid":1223,"session_id":"4686e8df-1cb4-42d0-99ff-44e240b26313"}
1532024-12-11T23:43:49.427Z{"msg":"Crucible stats registered with UUID: fe8488bd-12a0-435f-856b-9a6bf752b50c","v":0,"name":"crucible","level":30,"time":"2024-12-11T23:43:48.521737248Z","hostname":"w-01JEW1EECADXAJNR7ZZ07QNGFT","pid":1223,"session_id":"4686e8df-1cb4-42d0-99ff-44e240b26313"}
1542024-12-11T23:43:49.427Z{"msg":"could not find Downstairs address for Nexus","v":0,"name":"crucible","level":40,"time":"2024-12-11T23:43:48.521760114Z","hostname":"w-01JEW1EECADXAJNR7ZZ07QNGFT","pid":1223,"session_id":"4686e8df-1cb4-42d0-99ff-44e240b26313"}
1552024-12-11T23:43:49.427Z{"msg":"Downstairs in volume = 3","v":0,"name":"crucible","level":30,"time":"2024-12-11T23:43:48.522742192Z","hostname":"w-01JEW1EECADXAJNR7ZZ07QNGFT","pid":1223,"task":"crutest"}
1562024-12-11T23:43:49.427Z{"msg":"The guest has requested activation with gen:31","v":0,"name":"crucible","level":30,"time":"2024-12-11T23:43:48.52281172Z","hostname":"w-01JEW1EECADXAJNR7ZZ07QNGFT","pid":1223}
1572024-12-11T23:43:49.427Z{"msg":"fe8488bd-12a0-435f-856b-9a6bf752b50c active request set","v":0,"name":"crucible","level":30,"time":"2024-12-11T23:43:48.522839705Z","hostname":"w-01JEW1EECADXAJNR7ZZ07QNGFT","pid":1223,"session_id":"4686e8df-1cb4-42d0-99ff-44e240b26313"}
1582024-12-11T23:43:49.427Z{"msg":"sending connect oneshot to client","v":0,"name":"crucible","level":30,"time":"2024-12-11T23:43:48.522873739Z","hostname":"w-01JEW1EECADXAJNR7ZZ07QNGFT","pid":1223,"client":"0","":"downstairs","session_id":"4686e8df-1cb4-42d0-99ff-44e240b26313"}
1592024-12-11T23:43:49.427Z{"msg":"client set_active_request while in New; waiting...","v":0,"name":"crucible","level":30,"time":"2024-12-11T23:43:48.522918231Z","hostname":"w-01JEW1EECADXAJNR7ZZ07QNGFT","pid":1223,"client":"0","":"downstairs","session_id":"4686e8df-1cb4-42d0-99ff-44e240b26313"}
1602024-12-11T23:43:49.427Z{"msg":"sending connect oneshot to client","v":0,"name":"crucible","level":30,"time":"2024-12-11T23:43:48.522952405Z","hostname":"w-01JEW1EECADXAJNR7ZZ07QNGFT","pid":1223,"client":"1","":"downstairs","session_id":"4686e8df-1cb4-42d0-99ff-44e240b26313"}
1612024-12-11T23:43:49.427Z{"msg":"client set_active_request while in New; waiting...","v":0,"name":"crucible","level":30,"time":"2024-12-11T23:43:48.52298219Z","hostname":"w-01JEW1EECADXAJNR7ZZ07QNGFT","pid":1223,"client":"1","":"downstairs","session_id":"4686e8df-1cb4-42d0-99ff-44e240b26313"}
1622024-12-11T23:43:49.427Z{"msg":"sending connect oneshot to client","v":0,"name":"crucible","level":30,"time":"2024-12-11T23:43:48.523020363Z","hostname":"w-01JEW1EECADXAJNR7ZZ07QNGFT","pid":1223,"client":"2","":"downstairs","session_id":"4686e8df-1cb4-42d0-99ff-44e240b26313"}
1632024-12-11T23:43:49.427Z{"msg":"client set_active_request while in New; waiting...","v":0,"name":"crucible","level":30,"time":"2024-12-11T23:43:48.523064575Z","hostname":"w-01JEW1EECADXAJNR7ZZ07QNGFT","pid":1223,"client":"2","":"downstairs","session_id":"4686e8df-1cb4-42d0-99ff-44e240b26313"}
1642024-12-11T23:43:49.427Z{"msg":"connecting to 127.0.0.1:8830","v":0,"name":"crucible","level":30,"time":"2024-12-11T23:43:48.523087271Z","hostname":"w-01JEW1EECADXAJNR7ZZ07QNGFT","pid":1223,"":"io task","client":"2","":"downstairs","session_id":"4686e8df-1cb4-42d0-99ff-44e240b26313"}
1652024-12-11T23:43:49.427Z{"msg":"connecting to 127.0.0.1:8810","v":0,"name":"crucible","level":30,"time":"2024-12-11T23:43:48.523130224Z","hostname":"w-01JEW1EECADXAJNR7ZZ07QNGFT","pid":1223,"":"io task","client":"0","":"downstairs","session_id":"4686e8df-1cb4-42d0-99ff-44e240b26313"}
1662024-12-11T23:43:49.427Z{"msg":"connecting to 127.0.0.1:8820","v":0,"name":"crucible","level":30,"time":"2024-12-11T23:43:48.523158899Z","hostname":"w-01JEW1EECADXAJNR7ZZ07QNGFT","pid":1223,"":"io task","client":"1","":"downstairs","session_id":"4686e8df-1cb4-42d0-99ff-44e240b26313"}
1672024-12-11T23:43:49.427Z{"msg":"ds_connection connected from Ok(127.0.0.1:50567)","v":0,"name":"crucible","level":30,"time":"2024-12-11T23:43:48.523183044Z","hostname":"w-01JEW1EECADXAJNR7ZZ07QNGFT","pid":1223,"":"io task","client":"2","":"downstairs","session_id":"4686e8df-1cb4-42d0-99ff-44e240b26313"}
1682024-12-11T23:43:49.427Z{"msg":"ds_connection connected from Ok(127.0.0.1:35218)","v":0,"name":"crucible","level":30,"time":"2024-12-11T23:43:48.5232069Z","hostname":"w-01JEW1EECADXAJNR7ZZ07QNGFT","pid":1223,"":"io task","client":"0","":"downstairs","session_id":"4686e8df-1cb4-42d0-99ff-44e240b26313"}
1692024-12-11T23:43:49.427Z{"msg":"ds_connection connected from Ok(127.0.0.1:64190)","v":0,"name":"crucible","level":30,"time":"2024-12-11T23:43:48.523229746Z","hostname":"w-01JEW1EECADXAJNR7ZZ07QNGFT","pid":1223,"":"io task","client":"1","":"downstairs","session_id":"4686e8df-1cb4-42d0-99ff-44e240b26313"}
1702024-12-11T23:43:49.427Z{"msg":"ds_transition from New to WaitActive","v":0,"name":"crucible","level":30,"time":"2024-12-11T23:43:48.523828671Z","hostname":"w-01JEW1EECADXAJNR7ZZ07QNGFT","pid":1223,"client":"1","":"downstairs","session_id":"4686e8df-1cb4-42d0-99ff-44e240b26313"}
1712024-12-11T23:43:49.427Z{"msg":"[1] Transition from New to WaitActive","v":0,"name":"crucible","level":30,"time":"2024-12-11T23:43:48.523875423Z","hostname":"w-01JEW1EECADXAJNR7ZZ07QNGFT","pid":1223,"client":"1","":"downstairs","session_id":"4686e8df-1cb4-42d0-99ff-44e240b26313"}
1722024-12-11T23:43:49.427Z{"msg":"ds_transition from New to WaitActive","v":0,"name":"crucible","level":30,"time":"2024-12-11T23:43:48.52389309Z","hostname":"w-01JEW1EECADXAJNR7ZZ07QNGFT","pid":1223,"client":"2","":"downstairs","session_id":"4686e8df-1cb4-42d0-99ff-44e240b26313"}
1732024-12-11T23:43:49.427Z{"msg":"[2] Transition from New to WaitActive","v":0,"name":"crucible","level":30,"time":"2024-12-11T23:43:48.523908297Z","hostname":"w-01JEW1EECADXAJNR7ZZ07QNGFT","pid":1223,"client":"2","":"downstairs","session_id":"4686e8df-1cb4-42d0-99ff-44e240b26313"}
1742024-12-11T23:43:49.427Z{"msg":"ds_transition from New to WaitActive","v":0,"name":"crucible","level":30,"time":"2024-12-11T23:43:48.524003971Z","hostname":"w-01JEW1EECADXAJNR7ZZ07QNGFT","pid":1223,"client":"0","":"downstairs","session_id":"4686e8df-1cb4-42d0-99ff-44e240b26313"}
1752024-12-11T23:43:49.427Z{"msg":"[0] Transition from New to WaitActive","v":0,"name":"crucible","level":30,"time":"2024-12-11T23:43:48.524046023Z","hostname":"w-01JEW1EECADXAJNR7ZZ07QNGFT","pid":1223,"client":"0","":"downstairs","session_id":"4686e8df-1cb4-42d0-99ff-44e240b26313"}
1762024-12-11T23:43:49.430Z{"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-12-11T23:43:48.524528968Z","hostname":"w-01JEW1EECADXAJNR7ZZ07QNGFT","pid":1223,"client":"0","":"downstairs","session_id":"4686e8df-1cb4-42d0-99ff-44e240b26313"}
1772024-12-11T23:43:49.430Z{"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-12-11T23:43:48.52469194Z","hostname":"w-01JEW1EECADXAJNR7ZZ07QNGFT","pid":1223,"client":"1","":"downstairs","session_id":"4686e8df-1cb4-42d0-99ff-44e240b26313"}
1782024-12-11T23:43:49.430Z{"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-12-11T23:43:48.524733492Z","hostname":"w-01JEW1EECADXAJNR7ZZ07QNGFT","pid":1223,"client":"2","":"downstairs","session_id":"4686e8df-1cb4-42d0-99ff-44e240b26313"}
1792024-12-11T23:43:49.431Z{"msg":"ds_transition from WaitActive to WaitQuorum","v":0,"name":"crucible","level":30,"time":"2024-12-11T23:43:48.524892015Z","hostname":"w-01JEW1EECADXAJNR7ZZ07QNGFT","pid":1223,"client":"0","":"downstairs","session_id":"4686e8df-1cb4-42d0-99ff-44e240b26313"}
1802024-12-11T23:43:49.431Z{"msg":"[0] Transition from WaitActive to WaitQuorum","v":0,"name":"crucible","level":30,"time":"2024-12-11T23:43:48.524944615Z","hostname":"w-01JEW1EECADXAJNR7ZZ07QNGFT","pid":1223,"client":"0","":"downstairs","session_id":"4686e8df-1cb4-42d0-99ff-44e240b26313"}
1812024-12-11T23:43:49.431Z{"msg":"Waiting for more clients to be ready","v":0,"name":"crucible","level":30,"time":"2024-12-11T23:43:48.52497715Z","hostname":"w-01JEW1EECADXAJNR7ZZ07QNGFT","pid":1223,"session_id":"4686e8df-1cb4-42d0-99ff-44e240b26313"}
1822024-12-11T23:43:49.431Z{"msg":"ds_transition from WaitActive to WaitQuorum","v":0,"name":"crucible","level":30,"time":"2024-12-11T23:43:48.525153899Z","hostname":"w-01JEW1EECADXAJNR7ZZ07QNGFT","pid":1223,"client":"1","":"downstairs","session_id":"4686e8df-1cb4-42d0-99ff-44e240b26313"}
1832024-12-11T23:43:49.431Z{"msg":"[1] Transition from WaitActive to WaitQuorum","v":0,"name":"crucible","level":30,"time":"2024-12-11T23:43:48.525192682Z","hostname":"w-01JEW1EECADXAJNR7ZZ07QNGFT","pid":1223,"client":"1","":"downstairs","session_id":"4686e8df-1cb4-42d0-99ff-44e240b26313"}
1842024-12-11T23:43:49.431Z{"msg":"Waiting for more clients to be ready","v":0,"name":"crucible","level":30,"time":"2024-12-11T23:43:48.525209969Z","hostname":"w-01JEW1EECADXAJNR7ZZ07QNGFT","pid":1223,"session_id":"4686e8df-1cb4-42d0-99ff-44e240b26313"}
1852024-12-11T23:43:49.431Z{"msg":"ds_transition from WaitActive to WaitQuorum","v":0,"name":"crucible","level":30,"time":"2024-12-11T23:43:48.525243053Z","hostname":"w-01JEW1EECADXAJNR7ZZ07QNGFT","pid":1223,"client":"2","":"downstairs","session_id":"4686e8df-1cb4-42d0-99ff-44e240b26313"}
1862024-12-11T23:43:49.431Z{"msg":"[2] Transition from WaitActive to WaitQuorum","v":0,"name":"crucible","level":30,"time":"2024-12-11T23:43:48.525275807Z","hostname":"w-01JEW1EECADXAJNR7ZZ07QNGFT","pid":1223,"client":"2","":"downstairs","session_id":"4686e8df-1cb4-42d0-99ff-44e240b26313"}
1872024-12-11T23:43:49.431Z{"msg":"[0]R flush_numbers: [1500, 1500, 1500, 1500, 1500]","v":0,"name":"crucible","level":30,"time":"2024-12-11T23:43:48.525308862Z","hostname":"w-01JEW1EECADXAJNR7ZZ07QNGFT","pid":1223,"":"downstairs","":"downstairs","session_id":"4686e8df-1cb4-42d0-99ff-44e240b26313"}
1882024-12-11T23:43:49.431Z{"msg":"[0]R generation: [25, 25, 25, 25, 25]","v":0,"name":"crucible","level":30,"time":"2024-12-11T23:43:48.525330358Z","hostname":"w-01JEW1EECADXAJNR7ZZ07QNGFT","pid":1223,"":"downstairs","":"downstairs","session_id":"4686e8df-1cb4-42d0-99ff-44e240b26313"}
1892024-12-11T23:43:49.431Z{"msg":"[0]R dirty: [false, false, false, false, false]","v":0,"name":"crucible","level":30,"time":"Wait for a query_work_queue command to finish before sending IO
1902024-12-11T23:43:49.431Z2024-12-11T23:43:48.525361332Z","hostname":"w-01JEW1EECADXAJNR7ZZ07QNGFT","pid":1223,"":"downstairs","":"downstairs","session_id":"4686e8df-1cb4-42d0-99ff-44e240b26313"}
1912024-12-11T23:43:49.431Z{"msg":"[1]R flush_numbers: [1500, 1500, 1500, 1500, 1500]","v":0,"name":"crucible","level":30,"time":"2024-12-11T23:43:48.525391327Z","hostname":"w-01JEW1EECADXAJNR7ZZ07QNGFT","pid":1223,"":"downstairs","":"downstairs","session_id":"4686e8df-1cb4-42d0-99ff-44e240b26313"}
1922024-12-11T23:43:49.431Z{"msg":"[1]R generation: [25, 25, 25, 25, 25]","v":0,"name":"crucible","level":30,"time":"2024-12-11T23:43:48.525416703Z","hostname":"w-01JEW1EECADXAJNR7ZZ07QNGFT","pid":1223,"":"downstairs","":"downstairs","session_id":"4686e8df-1cb4-42d0-99ff-44e240b26313"}
1932024-12-11T23:43:49.431Z{"msg":"[1]R dirty: [false, false, false, false, false]","v":0,"name":"crucible","level":30,"time":"2024-12-11T23:43:48.525453796Z","hostname":"w-01JEW1EECADXAJNR7ZZ07QNGFT","pid":1223,"":"downstairs","":"downstairs","session_id":"4686e8df-1cb4-42d0-99ff-44e240b26313"}
1942024-12-11T23:43:49.431Z{"msg":"[2]R flush_numbers: [1500, 1500, 1500, 1500, 1500]","v":0,"name":"crucible","level":30,"time":"2024-12-11T23:43:48.525476702Z","hostname":"w-01JEW1EECADXAJNR7ZZ07QNGFT","pid":1223,"":"downstairs","":"downstairs","session_id":"4686e8df-1cb4-42d0-99ff-44e240b26313"}
1952024-12-11T23:43:49.431Z{"msg":"[2]R generation: [25, 25, 25, 25, 25]","v":0,"name":"crucible","level":30,"time":"2024-12-11T23:43:48.525508276Z","hostname":"w-01JEW1EECADXAJNR7ZZ07QNGFT","pid":1223,"":"downstairs","":"downstairs","session_id":"4686e8df-1cb4-42d0-99ff-44e240b26313"}
1962024-12-11T23:43:49.431Z{"msg":"[2]R dirty: [false, false, false, false, false]","v":0,"name":"crucible","level":30,"time":"2024-12-11T23:43:48.525524324Z","hostname":"w-01JEW1EECADXAJNR7ZZ07QNGFT","pid":1223,"":"downstairs","":"downstairs","session_id":"4686e8df-1cb4-42d0-99ff-44e240b26313"}
1972024-12-11T23:43:49.431Z{"msg":"Max found gen is 26","v":0,"name":"crucible","level":30,"time":"2024-12-11T23:43:48.525556018Z","hostname":"w-01JEW1EECADXAJNR7ZZ07QNGFT","pid":1223,"":"downstairs","":"downstairs","session_id":"4686e8df-1cb4-42d0-99ff-44e240b26313"}
1982024-12-11T23:43:49.431Z{"msg":"Generation requested: 31 >= found:26","v":0,"name":"crucible","level":30,"time":"2024-12-11T23:43:48.525574825Z","hostname":"w-01JEW1EECADXAJNR7ZZ07QNGFT","pid":1223,"":"downstairs","":"downstairs","session_id":"4686e8df-1cb4-42d0-99ff-44e240b26313"}
1992024-12-11T23:43:49.431Z{"msg":"Next flush: 1501","v":0,"name":"crucible","level":30,"time":"2024-12-11T23:43:48.525606129Z","hostname":"w-01JEW1EECADXAJNR7ZZ07QNGFT","pid":1223,"":"Disk: sv:1 bs:4096 ts:204800 tb:50 max_io:50 or 204800
2002024-12-11T23:43:49.431Zdownstairs","":"downstairs","session_id":"4686e8df-1cb4-42d0-99ff-44e240b26313"}
2012024-12-11T23:43:49.432Z{"msg":"All extents match","v":0,"name":"crucible","level":30,"time":"2024-12-11T23:43:48.525628355Z","hostname":"w-01JEW1EECADXAJNR7ZZ07QNGFT","pid":1223,"":"downstairs","":"downstairs","session_id":"4686e8df-1cb4-42d0-99ff-44e240b26313"}
2022024-12-11T23:43:49.432ZFill test
2032024-12-11T23:43:49.432Z{"msg":"No downstairs reconciliation required","v":0,"name":"crucible","level":30,"time":"2024-12-11T23:43:48.52566059Z","hostname":"w-01JEW1EECADXAJNR7ZZ07QNGFT","pid":1223,"session_id":"4686e8df-1cb4-42d0-99ff-44e240b26313"}
2042024-12-11T23:43:49.432Z{"msg":"Transition from WaitQuorum to Active","v":0,"name":"crucible","level":30,"time":"2024-12-11T23:43:48.525676257Z","hostname":"w-01JEW1EECADXAJNR7ZZ07QNGFT","pid":1223,"client":"0","":"downstairs","session_id":"4686e8df-1cb4-42d0-99ff-44e240b26313"}
2052024-12-11T23:43:49.432Z{"msg":"Transition from WaitQuorum to Active","v":0,"name":"crucible","level":30,"time":"2024-12-11T23:43:48.525708381Z","hostname":"w-01JEW1EECADXAJNR7ZZ07QNGFT","pid":1223,"client":"1","":"downstairs","session_id":"4686e8df-1cb4-42d0-99ff-44e240b26313"}
2062024-12-11T23:43:49.432Z{"msg":"Transition from WaitQuorum to Active","v":0,"name":"crucible","level":30,"time":"2024-12-11T23:43:48.525725158Z","hostname":"w-01JEW1EECADXAJNR7ZZ07QNGFT","pid":1223,"client":"2","":"downstairs","session_id":"4686e8df-1cb4-42d0-99ff-44e240b26313"}
2072024-12-11T23:43:49.432Z{"msg":"All required reconciliation work is completed","v":0,"name":"crucible","level":30,"time":"2024-12-11T23:43:48.525756093Z","hostname":"w-01JEW1EECADXAJNR7ZZ07QNGFT","pid":1223,"session_id":"4686e8df-1cb4-42d0-99ff-44e240b26313"}
2082024-12-11T23:43:49.432Z{"msg":"Set Downstairs and Upstairs active after reconciliation","v":0,"name":"crucible","level":30,"time":"2024-12-11T23:43:48.52577129Z","hostname":"w-01JEW1EECADXAJNR7ZZ07QNGFT","pid":1223,"session_id":"4686e8df-1cb4-42d0-99ff-44e240b26313"}
2092024-12-11T23:43:49.432Z{"msg":"fe8488bd-12a0-435f-856b-9a6bf752b50c is now active with session: 4686e8df-1cb4-42d0-99ff-44e240b26313","v":0,"name":"crucible","level":30,"time":"2024-12-11T23:43:48.525802595Z","hostname":"w-01JEW1EECADXAJNR7ZZ07QNGFT","pid":1223,"session_id":"4686e8df-1cb4-42d0-99ff-44e240b26313"}
2102024-12-11T23:43:49.433Z{"msg":"Set Active after no reconciliation","v":0,"name":"crucible","level":30,"time":"2024-12-11T23:43:48.525817612Z","hostname":"w-01JEW1EECADXAJNR7ZZ07QNGFT","pid":1223,"session_id":"4686e8df-1cb4-42d0-99ff-44e240b26313"}
2112024-12-11T23:43:49.433Z{"msg":"The guest has finished waiting for activation with:31","v":0,"name":"crucible","level":30,"time":"2024-12-11T23:43:48.525847857Z","hostname":"w-01JEW1EECADXAJNR7ZZ07QNGFT","pid":1223}
2122024-12-11T23:43:49.467ZRead and Verify all blocks (0..50 range:false)
2132024-12-11T23:43:49.506ZWrote out file "/var/tmp/test_up-build/verify_file"
2142024-12-11T23:43:49.506ZCLIENT: Tests done. All submitted work has been ACK'd
2152024-12-11T23:43:49.509Z----------------------------------------------------------------
2162024-12-11T23:43:49.509Z Crucible gen:31 GIO:true work queues: Upstairs:0 downstairs:1
2172024-12-11T23:43:49.509ZStates: Active Active Active
2182024-12-11T23:43:49.509ZJOBID ACK TYPE BKS/EXT DS:0 DS:1 DS:2 REPLAY
2192024-12-11T23:43:49.509Z 1002 Acked Read 50 Done Sent Sent false
2202024-12-11T23:43:49.509Z STATES DS:0 DS:1 DS:2 TOTAL
2212024-12-11T23:43:49.509Z Sent 0 1 1 2
2222024-12-11T23:43:49.509Z Done 1 0 0 1
2232024-12-11T23:43:49.509Z Skipped 0 0 0 0
2242024-12-11T23:43:49.509Z Error 0 0 0 0
2252024-12-11T23:43:49.509ZLast Flush: 1001 1001 1001
2262024-12-11T23:43:49.509ZDownstairs last five completed: 1001 1000
2272024-12-11T23:43:49.509ZUpstairs last five completed: 1002 1001 1000
2282024-12-11T23:43:49.509ZCLIENT: Up:0 ds:1 act:3
2292024-12-11T23:43:53.508Z----------------------------------------------------------------
2302024-12-11T23:43:53.508Z Crucible gen:31 GIO:true work queues: Upstairs:0 downstairs:0
2312024-12-11T23:43:53.508ZDownstairs last five completed: 1003 1002 1001 1000
2322024-12-11T23:43:53.508ZUpstairs last five completed: 1003 1002 1001 1000
2332024-12-11T23:43:53.508ZCLIENT: Up:0 ds:0 act:3
2342024-12-11T23:43:53.508ZCLIENT: All crucible jobs finished, exiting program
2352024-12-11T23:43:53.512Z{"msg":"Guest handle has been dropped","v":0,"name":"crucible","level":40,"time":"2024-12-11T23:43:52.605231128Z","hostname":"w-01JEW1EECADXAJNR7ZZ07QNGFT","pid":1223}
2362024-12-11T23:43:53.519ZRepair setup passed
2372024-12-11T23:43:53.523ZCopy the region for /var/tmp/test_up-build/8830
2382024-12-11T23:43:53.526Zcp -r /var/tmp/test_up-build/8830 /var/tmp/test_up-build/previous
2392024-12-11T23:43:53.528Z/var/tmp/bins/crutest fill -g 32 -q --key AQg69ATuOFkflT1lQvu2o0+Avqp7yDvZbvte6DgK0jc= --dsc 127.0.0.1:9998 --verify-out /var/tmp/test_up-build/verify_file --verify-in /var/tmp/test_up-build/verify_file
2402024-12-11T23:43:53.589Z{"msg":"Use this region info from dsc: RegionExtentInfo { block_size: 4096, blocks_per_extent: 10, extent_count: 5 }","v":0,"name":"crucible","level":30,"time":"2024-12-11T23:43:52.685054116Z","hostname":"w-01JEW1EECADXAJNR7ZZ07QNGFT","pid":1229,"task":"crutest"}
2412024-12-11T23:43:53.591Z{"msg":"dsc has 3 regions. This means 1 sub_volumes","v":0,"name":"crucible","level":30,"time":"2024-12-11T23:43:52.685631394Z","hostname":"w-01JEW1EECADXAJNR7ZZ07QNGFT","pid":1229,"task":"crutest"}
2422024-12-11T23:43:53.591Z{"msg":"SV 0 has targets: [127.0.0.1:8810, 127.0.0.1:8820, 127.0.0.1:8830]","v":0,"name":"crucible","level":30,"time":"2024-12-11T23:43:52.687278885Z","hostname":"w-01JEW1EECADXAJNR7ZZ07QNGFT","pid":1229,"task":"crutest"}
2432024-12-11T23:43:53.591Z{"msg":"Upstairs starts","v":0,"name":"crucible","level":30,"time":"2024-12-11T23:43:52.68753491Z","hostname":"w-01JEW1EECADXAJNR7ZZ07QNGFT","pid":1229}
2442024-12-11T23:43:53.592Z{"msg":"Crucible Version: BuildInfo {\n version: \"0.0.1\",\n git_sha: \"d81f7fe7d3a87a2a3c58f4f5d619f7f37b0a05d0\",\n git_commit_timestamp: \"2024-12-11T23:24:14.000000000Z\",\n git_branch: \"mkeeter/separate-notify-task\",\n rustc_semver: \"1.82.0\",\n rustc_channel: \"stable\",\n rustc_host_triple: \"x86_64-unknown-illumos\",\n rustc_commit_sha: \"f6e511eec7342f59a25f7c0534f1dbea00d01b14\",\n cargo_triple: \"x86_64-unknown-illumos\",\n debug: true,\n opt_level: 0,\n}","v":0,"name":"crucible","level":30,"time":"2024-12-11T23:43:52.687579642Z","hostname":"w-01JEW1EECADXAJNR7ZZ07QNGFT","pid":1229}
2452024-12-11T23:43:53.592Z{"msg":"Upstairs <-> Downstairs Message Version: 12","v":0,"name":"crucible","level":30,"time":"2024-12-11T23:43:52.687616796Z","hostname":"w-01JEW1EECADXAJNR7ZZ07QNGFT","pid":1229}
2462024-12-11T23:43:53.592Z{"msg":"Using region definition RegionDefinition { block_size: 4096, extent_size: Block { value: 10, shift: 12 }, extent_count: 5, uuid: 00000000-0000-0000-0000-000000000000, encrypted: true, database_read_version: 1, database_write_version: 1 }","v":0,"name":"crucible","level":30,"time":"2024-12-11T23:43:52.687642351Z","hostname":"w-01JEW1EECADXAJNR7ZZ07QNGFT","pid":1229}
2472024-12-11T23:43:53.592Z{"msg":"Crucible d71ef062-11d4-4ff5-9203-0cceffc69f50 has session id: 41f8b614-a609-4030-a340-e16fdadd2b75","v":0,"name":"crucible","level":30,"time":"2024-12-11T23:43:52.688114159Z","hostname":"w-01JEW1EECADXAJNR7ZZ07QNGFT","pid":1229,"session_id":"41f8b614-a609-4030-a340-e16fdadd2b75"}
2482024-12-11T23:43:53.592Z{"msg":"Upstairs opts: Upstairs UUID: d71ef062-11d4-4ff5-9203-0cceffc69f50, Targets: [127.0.0.1:8810, 127.0.0.1:8820, 127.0.0.1:8830], lossy: false, flush_timeout: None, key populated: true, cert_pem populated: false, key_pem populated: false, root_cert_pem populated: false, Control: None, read_only: false","v":0,"name":"crucible","level":30,"time":"2024-12-11T23:43:52.688170039Z","hostname":"w-01JEW1EECADXAJNR7ZZ07QNGFT","pid":1229,"session_id":"41f8b614-a609-4030-a340-e16fdadd2b75"}
2492024-12-11T23:43:53.595Z{"msg":"Crucible stats registered with UUID: d71ef062-11d4-4ff5-9203-0cceffc69f50","v":0,"name":"crucible","level":30,"time":"2024-12-11T23:43:52.688201193Z","hostname":"w-01JEW1EECADXAJNR7ZZ07QNGFT","pid":1229,"session_id":"41f8b614-a609-4030-a340-e16fdadd2b75"}
2502024-12-11T23:43:53.595Z{"msg":"could not find Downstairs address for Nexus","v":0,"name":"crucible","level":40,"time":"2024-12-11T23:43:52.688237767Z","hostname":"w-01JEW1EECADXAJNR7ZZ07QNGFT","pid":1229,"session_id":"41f8b614-a609-4030-a340-e16fdadd2b75"}
2512024-12-11T23:43:53.595Z{"msg":"Downstairs in volume = 3","v":0,"name":"crucible","level":30,"time":"2024-12-11T23:43:52.689407292Z","hostname":"w-01JEW1EECADXAJNR7ZZ07QNGFT","pid":1229,"task":"crutest"}
2522024-12-11T23:43:53.595Z{"msg":"The guest has requested activation with gen:32","v":0,"name":"crucible","level":30,"time":"2024-12-11T23:43:52.689457403Z","hostname":"w-01JEW1EECADXAJNR7ZZ07QNGFT","pid":1229}
2532024-12-11T23:43:53.595Z{"msg":"d71ef062-11d4-4ff5-9203-0cceffc69f50 active request set","v":0,"name":"crucible","level":30,"time":"2024-12-11T23:43:52.68953006Z","hostname":"w-01JEW1EECADXAJNR7ZZ07QNGFT","pid":1229,"session_id":"41f8b614-a609-4030-a340-e16fdadd2b75"}
2542024-12-11T23:43:53.595Z{"msg":"sending connect oneshot to client","v":0,"name":"crucible","level":30,"time":"2024-12-11T23:43:52.689591479Z","hostname":"w-01JEW1EECADXAJNR7ZZ07QNGFT","pid":1229,"client":"0","":"downstairs","session_id":"41f8b614-a609-4030-a340-e16fdadd2b75"}
2552024-12-11T23:43:53.595Z{"msg":"client set_active_request while in New; waiting...","v":0,"name":"crucible","level":30,"time":"2024-12-11T23:43:52.689656068Z","hostname":"w-01JEW1EECADXAJNR7ZZ07QNGFT","pid":1229,"client":"0","":"downstairs","session_id":"41f8b614-a609-4030-a340-e16fdadd2b75"}
2562024-12-11T23:43:53.595Z{"msg":"sending connect oneshot to client","v":0,"name":"crucible","level":30,"time":"2024-12-11T23:43:52.68970231Z","hostname":"w-01JEW1EECADXAJNR7ZZ07QNGFT","pid":1229,"client":"1","":"downstairs","session_id":"41f8b614-a609-4030-a340-e16fdadd2b75"}
2572024-12-11T23:43:53.595Z{"msg":"client set_active_request while in New; waiting...","v":0,"name":"crucible","level":30,"time":"2024-12-11T23:43:52.689730785Z","hostname":"w-01JEW1EECADXAJNR7ZZ07QNGFT","pid":1229,"client":"1","":"downstairs","session_id":"41f8b614-a609-4030-a340-e16fdadd2b75"}
2582024-12-11T23:43:53.595Z{"msg":"sending connect oneshot to client","v":0,"name":"crucible","level":30,"time":"2024-12-11T23:43:52.68975659Z","hostname":"w-01JEW1EECADXAJNR7ZZ07QNGFT","pid":1229,"client":"2","":"downstairs","session_id":"41f8b614-a609-4030-a340-e16fdadd2b75"}
2592024-12-11T23:43:53.595Z{"msg":"client set_active_request while in New; waiting...","v":0,"name":"crucible","level":30,"time":"2024-12-11T23:43:52.689823819Z","hostname":"w-01JEW1EECADXAJNR7ZZ07QNGFT","pid":1229,"client":"2","":"downstairs","session_id":"41f8b614-a609-4030-a340-e16fdadd2b75"}
2602024-12-11T23:43:53.595Z{"msg":"connecting to 127.0.0.1:8830","v":0,"name":"crucible","level":30,"time":"2024-12-11T23:43:52.689865771Z","hostname":"w-01JEW1EECADXAJNR7ZZ07QNGFT","pid":1229,"":"io task","client":"2","":"downstairs","session_id":"41f8b614-a609-4030-a340-e16fdadd2b75"}
2612024-12-11T23:43:53.595Z{"msg":"connecting to 127.0.0.1:8810","v":0,"name":"crucible","level":30,"time":"2024-12-11T23:43:52.689896076Z","hostname":"w-01JEW1EECADXAJNR7ZZ07QNGFT","pid":1229,"":"io task","client":"0","":"downstairs","session_id":"41f8b614-a609-4030-a340-e16fdadd2b75"}
2622024-12-11T23:43:53.596Z{"msg":"connecting to 127.0.0.1:8820","v":0,"name":"crucible","level":30,"time":"2024-12-11T23:43:52.689925081Z","hostname":"w-01JEW1EECADXAJNR7ZZ07QNGFT","pid":1229,"":"io task","client":"1","":"downstairs","session_id":"41f8b614-a609-4030-a340-e16fdadd2b75"}
2632024-12-11T23:43:53.596Z{"msg":"ds_connection connected from Ok(127.0.0.1:52971)","v":0,"name":"crucible","level":30,"time":"2024-12-11T23:43:52.689976022Z","hostname":"w-01JEW1EECADXAJNR7ZZ07QNGFT","pid":1229,"":"io task","client":"0","":"downstairs","session_id":"41f8b614-a609-4030-a340-e16fdadd2b75"}
2642024-12-11T23:43:53.596Z{"msg":"ds_connection connected from Ok(127.0.0.1:37141)","v":0,"name":"crucible","level":30,"time":"2024-12-11T23:43:52.690074455Z","hostname":"w-01JEW1EECADXAJNR7ZZ07QNGFT","pid":1229,"":"io task","client":"2","":"downstairs","session_id":"41f8b614-a609-4030-a340-e16fdadd2b75"}
2652024-12-11T23:43:53.596Z{"msg":"ds_connection connected from Ok(127.0.0.1:46386)","v":0,"name":"crucible","level":30,"time":"2024-12-11T23:43:52.690147182Z","hostname":"w-01JEW1EECADXAJNR7ZZ07QNGFT","pid":1229,"":"io task","client":"1","":"downstairs","session_id":"41f8b614-a609-4030-a340-e16fdadd2b75"}
2662024-12-11T23:43:53.596Z{"msg":"ds_transition from New to WaitActive","v":0,"name":"crucible","level":30,"time":"2024-12-11T23:43:52.690747806Z","hostname":"w-01JEW1EECADXAJNR7ZZ07QNGFT","pid":1229,"client":"0","":"downstairs","session_id":"41f8b614-a609-4030-a340-e16fdadd2b75"}
2672024-12-11T23:43:53.596Z{"msg":"[0] Transition from New to WaitActive","v":0,"name":"crucible","level":30,"time":"2024-12-11T23:43:52.690811605Z","hostname":"w-01JEW1EECADXAJNR7ZZ07QNGFT","pid":1229,"client":"0","":"downstairs","session_id":"41f8b614-a609-4030-a340-e16fdadd2b75"}
2682024-12-11T23:43:53.596Z{"msg":"ds_transition from New to WaitActive","v":0,"name":"crucible","level":30,"time":"2024-12-11T23:43:52.690871115Z","hostname":"w-01JEW1EECADXAJNR7ZZ07QNGFT","pid":1229,"client":"1","":"downstairs","session_id":"41f8b614-a609-4030-a340-e16fdadd2b75"}
2692024-12-11T23:43:53.596Z{"msg":"[1] Transition from New to WaitActive","v":0,"name":"crucible","level":30,"time":"2024-12-11T23:43:52.690913767Z","hostname":"w-01JEW1EECADXAJNR7ZZ07QNGFT","pid":1229,"client":"1","":"downstairs","session_id":"41f8b614-a609-4030-a340-e16fdadd2b75"}
2702024-12-11T23:43:53.596Z{"msg":"ds_transition from New to WaitActive","v":0,"name":"crucible","level":30,"time":"2024-12-11T23:43:52.69095528Z","hostname":"w-01JEW1EECADXAJNR7ZZ07QNGFT","pid":1229,"client":"2","":"downstairs","session_id":"41f8b614-a609-4030-a340-e16fdadd2b75"}
2712024-12-11T23:43:53.596Z{"msg":"[2] Transition from New to WaitActive","v":0,"name":"crucible","level":30,"time":"2024-12-11T23:43:52.690985004Z","hostname":"w-01JEW1EECADXAJNR7ZZ07QNGFT","pid":1229,"client":"2","":"downstairs","session_id":"41f8b614-a609-4030-a340-e16fdadd2b75"}
2722024-12-11T23:43:53.599Z{"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-12-11T23:43:52.691629031Z","hostname":"w-01JEW1EECADXAJNR7ZZ07QNGFT","pid":1229,"client":"1","":"downstairs","session_id":"41f8b614-a609-4030-a340-e16fdadd2b75"}
2732024-12-11T23:43:53.599Z{"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-12-11T23:43:52.691684882Z","hostname":"w-01JEW1EECADXAJNR7ZZ07QNGFT","pid":1229,"client":"2","":"downstairs","session_id":"41f8b614-a609-4030-a340-e16fdadd2b75"}
2742024-12-11T23:43:53.599Z{"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-12-11T23:43:52.691796482Z","hostname":"w-01JEW1EECADXAJNR7ZZ07QNGFT","pid":1229,"client":"0","":"downstairs","session_id":"41f8b614-a609-4030-a340-e16fdadd2b75"}
2752024-12-11T23:43:53.599Z{"msg":"ds_transition from WaitActive to WaitQuorum","v":0,"name":"crucible","level":30,"time":"2024-12-11T23:43:52.692172746Z","hostname":"w-01JEW1EECADXAJNR7ZZ07QNGFT","pid":1229,"client":"1","":"downstairs","session_id":"41f8b614-a609-4030-a340-e16fdadd2b75"}
2762024-12-11T23:43:53.599Z{"msg":"[1] Transition from WaitActive to WaitQuorum","v":0,"name":"crucible","level":30,"time":"2024-12-11T23:43:52.69220821Z","hostname":"w-01JEW1EECADXAJNR7ZZ07QNGFT","pid":1229,"client":"1","":"downstairs","session_id":"41f8b614-a609-4030-a340-e16fdadd2b75"}
2772024-12-11T23:43:53.599Z{"msg":"Waiting for more clients to be ready","v":0,"name":"crucible","level":30,"time":"2024-12-11T23:43:52.692224577Z","hostname":"w-01JEW1EECADXAJNR7ZZ07QNGFT","pid":1229,"session_id":"41f8b614-a609-4030-a340-e16fdadd2b75"}
2782024-12-11T23:43:53.599Z{"msg":"ds_transition from WaitActive to WaitQuorum","v":0,"name":"crucible","level":30,"time":"2024-12-11T23:43:52.69226325Z","hostname":"w-01JEW1EECADXAJNR7ZZ07QNGFT","pid":1229,"client":"0","":"downstairs","session_id":"41f8b614-a609-4030-a340-e16fdadd2b75"}
2792024-12-11T23:43:53.599Z{"msg":"[0] Transition from WaitActive to WaitQuorum","v":0,"name":"crucible","level":30,"time":"2024-12-11T23:43:52.692289826Z","hostname":"w-01JEW1EECADXAJNR7ZZ07QNGFT","pid":1229,"client":"0","":"downstairs","session_id":"41f8b614-a609-4030-a340-e16fdadd2b75"}
2802024-12-11T23:43:53.599Z{"msg":"Waiting for more clients to be ready","v":0,"name":"crucible","level":30,"time":"2024-12-11T23:43:52.69232036Z","hostname":"w-01JEW1EECADXAJNR7ZZ07QNGFT","pid":1229,"session_id":"41f8b614-a609-4030-a340-e16fdadd2b75"}
2812024-12-11T23:43:53.599Z{"msg":"ds_transition from WaitActive to WaitQuorum","v":0,"name":"crucible","level":30,"time":"2024-12-11T23:43:52.692334288Z","hostname":"w-01JEW1EECADXAJNR7ZZ07QNGFT","pid":1229,"client":"2","":"downstairs","session_id":"41f8b614-a609-4030-a340-e16fdadd2b75"}
2822024-12-11T23:43:53.599Z{"msg":"[2] Transition from WaitActive to WaitQuorum","v":0,"name":"crucible","level":30,"time":"2024-12-11T23:43:52.692350745Z","hostname":"w-01JEW1EECADXAJNR7ZZ07QNGFT","pid":1229,"client":"2","":"downstairs","session_id":"41f8b614-a609-4030-a340-e16fdadd2b75"}
2832024-12-11T23:43:53.599Z{"msg":"[0]R flush_numbers: [1501, 1501, 1501, 1501, 1501]","v":0,"name":"crucible","level":30,"time":"2024-12-11T23:43:52.692381339Z","hostname":"w-01JEW1EECADXAJNR7ZZ07QNGFT","pid":1229,"":"downstairs","":"downstairs","session_id":"41f8b614-a609-4030-a340-e16fdadd2b75"}
2842024-12-11T23:43:53.599Z{"msg":"[0]R generation: [31, 31, 31, 31, 31]","v":0,"name":"crucible","level":30,"time":"2024-12-11T23:43:52.692397747Z","hostname":"w-01JEW1EECADXAJNR7ZZ07QNGFT","pid":1229,"":"downstairs","":"downstairs","session_id":"41f8b614-a609-4030-a340-e16fdadd2b75"}
2852024-12-11T23:43:53.599Z{"msg":"[0]R dirty: [false, false, false, false, false]","v":0,"name":"crucible","level":30,"time":"2024-12-11T23:43:52.692429481Z","hostname":"w-01JEW1EECADXAJNR7ZZ07QNGFT","pid":1229,"":"downstairs","":"downstairs","session_id":"41f8b614-a609-4030-a340-e16fdadd2b75"}
2862024-12-11T23:43:53.599Z{"msg":"[1]R flush_numbers: [1501, 1501, 1501, 1501, 1501]","v":0,"name":"crucible","level":30,"time":"2024-12-11T23:43:52.692445848Z","hostname":"w-01JEW1EECADXAJNR7ZZ07QNGFT","pid":1229,"":"downstairs","":"downstairs","session_id":"41f8b614-a609-4030-a340-e16fdadd2b75"}
2872024-12-11T23:43:53.599Z{"msg":"[1]R generation: [31, 31, 31, 31, 31]","v":0,"name":"crucible","level":30,"time":"2024-12-11T23:43:52.692464025Z","hostname":"w-01JEW1EECADXAJNR7ZZ07QNGFT","pid":1229,"":"downstairs","":"downstairs","session_id":"41f8b614-a609-4030-a340-e16fdadd2b75"}
2882024-12-11T23:43:53.599Z{"msg":"[1]R dirty: [false, false, false, false, false]","v":0,"name":"crucible","level":30,"time":"2024-12-11T23:43:52.692496629Z","hostname":"w-01JEW1EECADXAJNR7ZZ07QNGFT","pid":1229,"":"downstairs","":"downstairs","session_id":"41f8b614-a609-4030-a340-e16fdadd2b75"}
2892024-12-11T23:43:53.599Z{"msg":"[2]R flush_numbers: [1501, 1501, 1501, 1501, 1501]","v":0,"name":"crucible","level":30,"time":"2024-12-11T23:43:52.692513846Z","hostname":"w-01JEW1EECADXAJNR7ZZ07QNGFT","pid":1229,"":"downstairs","":"downstairs","session_id":"41f8b614-a609-4030-a340-e16fdadd2b75"}
2902024-12-11T23:43:53.599Z{"msg":"[2]R generation: [31, 31, 31, 31, 31]","v":0,"name":"crucible","level":30,"time":"2024-12-11T23:43:52.692534503Z","hostname":"w-01JEW1EECADXAJNR7ZZ07QNGFT","pid":1229,"":"downstairs","":"downstairs","session_id":"41f8b614-a609-4030-a340-e16fdadd2b75"}
2912024-12-11T23:43:53.599Z{"msg":"[2]R dirty: [false, false, false, false, false]","v":0,"name":"crucible","level":30,"time":"2024-12-11T23:43:52.692563478Z","hostname":"Wait for a query_work_queue command to finish before sending IO
2922024-12-11T23:43:53.600Zw-01JEW1EECADXAJNR7ZZ07QNGFT","pid":1229,"":"downstairs","":"downstairs","session_id":"41f8b614-a609-4030-a340-e16fdadd2b75"}
2932024-12-11T23:43:53.600Z{"msg":"Max found gen is 32","v":0,"name":"crucible","level":30,"time":"2024-12-11T23:43:52.692585424Z","hostname":"w-01JEW1EECADXAJNR7ZZ07QNGFT","pid":1229,"":"downstairs","":"downstairs","session_id":"41f8b614-a609-4030-a340-e16fdadd2b75"}
2942024-12-11T23:43:53.600Z{"msg":"Generation requested: 32 >= found:32","v":0,"name":"crucible","level":30,"time":"2024-12-11T23:43:52.692617368Z","hostname":"w-01JEW1EECADXAJNR7ZZ07QNGFT","pid":1229,"":"downstairs","":"downstairs","session_id":"41f8b614-a609-4030-a340-e16fdadd2b75"}
2952024-12-11T23:43:53.600Z{"msg":"Next flush: 1502","v":0,"name":"crucible","level":30,"time":"2024-12-11T23:43:52.692632775Z","hostname":"w-01JEW1EECADXAJNR7ZZ07QNGFT","pid":1229,"":"downstairs","":"downstairs","session_id":"41f8b614-a609-4030-a340-e16fdadd2b75"}
2962024-12-11T23:43:53.600Z{"msg":"All extents match","v":0,"name":"crucible","level":30,"time":"2024-12-11T23:43:52.69266338Z","hostname":"w-01JEW1EECADXAJNR7ZZ07QNGFT","pid":1229,"":"downstairs","":"downstairs","session_id":"41f8b614-a609-4030-a340-e16fdadd2b75"}
2972024-12-11T23:43:53.600Z{"msg":"No downstairs reconciliation required","v":0,"name":"crucible","level":30,"time":"2024-12-11T23:43:52.692680517Z","hostname":"w-01JEW1EECADXAJNR7ZZ07QNGFT","pid":1229,"session_id":"41f8b614-a609-4030-a340-e16fdadd2b75"}
2982024-12-11T23:43:53.600Z{"msg":"Transition from WaitQuorum to Active","v":0,"name":"crucible","level":30,"time":"2024-12-11T23:43:52.692702453Z","hostname":"w-01JEW1EECADXAJNR7ZZ07QNGFT","pid":1229,"client":"0","":"downstairs","session_id":"41f8b614-a609-4030-a340-e16fdadd2b75"}
2992024-12-11T23:43:53.600Z{"msg":"Transition from WaitQuorum to Active","v":0,"name":"crucible","level":30,"time":"2024-12-11T23:43:52.69272242Z","hostname":"w-01JEW1EECADXAJNR7ZZ07QNGFT","pid":1229,"client":"1","":"downstairs","session_id":"41f8b614-a609-4030-a340-e16fdadd2b75"}
3002024-12-11T23:43:53.600Z{"msg":"Transition from WaitQuorum to Active","v":0,"name":"crucible","level":30,"time":"2024-12-11T23:43:52.692752744Z","hostname":"w-01JEW1EECADXAJNR7ZZ07QNGFT","pid":1229,"client":"2","":"downstairs","session_id":"41f8b614-a609-4030-a340-e16fdadd2b75"}
3012024-12-11T23:43:53.600Z{"msg":"All required reconciliation work is completed","v":0,"name":"crucible","level":30,"time":"2024-12-11T23:43:52.692767972Z","hostname":"w-01JEW1EECADXAJNR7ZZ07QNGFT","pid":1229,"session_id":"41f8b614-a609-4030-a340-e16fdadd2b75"}
3022024-12-11T23:43:53.600Z{"msg":"Set Downstairs and Upstairs active after reconciliation","v":0,"name":"crucible","level":30Disk: sv:1 bs:4096 ts:204800 tb:50 max_io:50 or 204800
3032024-12-11T23:43:53.600Z,"time":"2024-12-11T23:43:52.692787958Z","hostname":"w-01JEW1EECADXAJNR7ZZ07QNGFT","pid":1229,"session_id":"41f8b614-a609-4030-a340-e16fdadd2b75"}
3042024-12-11T23:43:53.600Z{"msg":"d71ef062-11d4-4ff5-9203-0cceffc69f50 is now active with session: 41f8b614-a609-4030-a340-e16fdadd2b75","v":0,"name":"crucible","level":30,"time":"2024-12-11T23:43:52.692818423Z","hostname":"w-01JEW1EECADXAJNR7ZZ07QNGFT","pid":1229,"session_id":"41f8b614-a609-4030-a340-e16fdadd2b75"}
3052024-12-11T23:43:53.600Z{"msg":"Set Active after no reconciliation","v":0,"name":"crucible","level":30,"time":"2024-12-11T23:43:52.69283446Z","hostname":"w-01JEW1EECADXAJNR7ZZ07QNGFT","pid":1229,"session_id":"41f8b614-a609-4030-a340-e16fdadd2b75"}
3062024-12-11T23:43:53.600Z{"msg":"The guest has finished waiting for activation with:32","v":0,"name":"crucible","level":30,"time":"2024-12-11T23:43:52.692863595Z","hostname":"w-01JEW1EECADXAJNR7ZZ07QNGFT","pid":1229}
3072024-12-11T23:43:53.600ZLoading write count information from file "/var/tmp/test_up-build/verify_file"
3082024-12-11T23:43:53.600ZFill test
3092024-12-11T23:43:53.635ZRead and Verify all blocks (0..50 range:false)
3102024-12-11T23:43:53.674ZWrote out file "/var/tmp/test_up-build/verify_file"
3112024-12-11T23:43:53.674ZCLIENT: Tests done. All submitted work has been ACK'd
3122024-12-11T23:43:53.674Z----------------------------------------------------------------
3132024-12-11T23:43:53.674Z Crucible gen:32 GIO:true work queues: Upstairs:0 downstairs:1
3142024-12-11T23:43:53.677ZStates: Active Active Active
3152024-12-11T23:43:53.677ZJOBID ACK TYPE BKS/EXT DS:0 DS:1 DS:2 REPLAY
3162024-12-11T23:43:53.677Z 1002 Acked Read 50 Done Done Done false
3172024-12-11T23:43:53.677Z STATES DS:0 DS:1 DS:2 TOTAL
3182024-12-11T23:43:53.677Z Sent 0 0 0 0
3192024-12-11T23:43:53.677Z Done 1 1 1 3
3202024-12-11T23:43:53.677Z Skipped 0 0 0 0
3212024-12-11T23:43:53.677Z Error 0 0 0 0
3222024-12-11T23:43:53.677ZLast Flush: 1001 1001 1001
3232024-12-11T23:43:53.677ZDownstairs last five completed: 1001 1000
3242024-12-11T23:43:53.677ZUpstairs last five completed: 1002 1001 1000
3252024-12-11T23:43:53.677ZCLIENT: Up:0 ds:1 act:3
3262024-12-11T23:43:57.677Z----------------------------------------------------------------
3272024-12-11T23:43:57.677Z Crucible gen:32 GIO:true work queues: Upstairs:0 downstairs:0
3282024-12-11T23:43:57.677ZDownstairs last five completed: 1003 1002 1001 1000
3292024-12-11T23:43:57.677ZUpstairs last five completed: 1003 1002 1001 1000
3302024-12-11T23:43:57.677ZCLIENT: Up:0 ds:0 act:3
3312024-12-11T23:43:57.677ZCLIENT: All crucible jobs finished, exiting program
3322024-12-11T23:43:57.680Z{"msg":"Guest handle has been dropped","v":0,"name":"crucible","level":40,"time":"2024-12-11T23:43:56.772915588Z","hostname":"w-01JEW1EECADXAJNR7ZZ07QNGFT","pid":1229}
3332024-12-11T23:43:57.683ZRepair part 1 passed
3342024-12-11T23:43:57.687Z
3352024-12-11T23:43:57.687ZKill the current downstairs
3362024-12-11T23:43:57.855ZDownstairs 2 stopped
3372024-12-11T23:43:57.856Zmv /var/tmp/test_up-build/8830 /var/tmp/test_up-build/new
3382024-12-11T23:43:57.858ZNow put back the original so we have a mismatch
3392024-12-11T23:43:57.858Zmv /var/tmp/test_up-build/previous /var/tmp/test_up-build/8830
3402024-12-11T23:43:57.861ZRestart downstairs with old directory
3412024-12-11T23:43:57.920Z/var/tmp/bins/crucible-downstairs dump --no-color -d /var/tmp/test_up-build/8810 -d /var/tmp/test_up-build/8820 -d /var/tmp/test_up-build/8830
3422024-12-11T23:43:57.938ZEXT BLOCKS GEN0 GEN1 GEN2 FL0 FL1 FL2 D0 D1 D2 DIFF
3432024-12-11T23:43:57.940Z 0 000-009 32 32 31 1502 1502 1501 F F F <---
3442024-12-11T23:43:57.940Z 1 010-019 32 32 31 1502 1502 1501 F F F <---
3452024-12-11T23:43:57.940Z 2 020-029 32 32 31 1502 1502 1501 F F F <---
3462024-12-11T23:43:57.940Z 3 030-039 32 32 31 1502 1502 1501 F F F <---
3472024-12-11T23:43:57.940Z 4 040-049 32 32 31 1502 1502 1501 F F F <---
3482024-12-11T23:43:57.940ZMax gen: 32, Max flush: 1502
3492024-12-11T23:43:57.940ZError: Difference in extent metadata found!
3502024-12-11T23:43:57.943Zdump test found error as expected
3512024-12-11T23:43:57.943Z
3522024-12-11T23:43:57.943Z
3532024-12-11T23:43:57.943Z/var/tmp/bins/crutest verify --range -g 33 -q --key AQg69ATuOFkflT1lQvu2o0+Avqp7yDvZbvte6DgK0jc= --dsc 127.0.0.1:9998 --verify-out /var/tmp/test_up-build/verify_file --verify-in /var/tmp/test_up-build/verify_file
3542024-12-11T23:43:58.002Z{"msg":"Use this region info from dsc: RegionExtentInfo { block_size: 4096, blocks_per_extent: 10, extent_count: 5 }","v":0,"name":"crucible","level":30,"time":"2024-12-11T23:43:57.09710413Z","hostname":"w-01JEW1EECADXAJNR7ZZ07QNGFT","pid":1237,"task":"crutest"}
3552024-12-11T23:43:58.004Z{"msg":"dsc has 3 regions. This means 1 sub_volumes","v":0,"name":"crucible","level":30,"time":"2024-12-11T23:43:57.097619979Z","hostname":"w-01JEW1EECADXAJNR7ZZ07QNGFT","pid":1237,"task":"crutest"}
3562024-12-11T23:43:58.004Z{"msg":"SV 0 has targets: [127.0.0.1:8810, 127.0.0.1:8820, 127.0.0.1:8830]","v":0,"name":"crucible","level":30,"time":"2024-12-11T23:43:57.099340047Z","hostname":"w-01JEW1EECADXAJNR7ZZ07QNGFT","pid":1237,"task":"crutest"}
3572024-12-11T23:43:58.004Z{"msg":"Upstairs starts","v":0,"name":"crucible","level":30,"time":"2024-12-11T23:43:57.099568867Z","hostname":"w-01JEW1EECADXAJNR7ZZ07QNGFT","pid":1237}
3582024-12-11T23:43:58.004Z{"msg":"Crucible Version: BuildInfo {\n version: \"0.0.1\",\n git_sha: \"d81f7fe7d3a87a2a3c58f4f5d619f7f37b0a05d0\",\n git_commit_timestamp: \"2024-12-11T23:24:14.000000000Z\",\n git_branch: \"mkeeter/separate-notify-task\",\n rustc_semver: \"1.82.0\",\n rustc_channel: \"stable\",\n rustc_host_triple: \"x86_64-unknown-illumos\",\n rustc_commit_sha: \"f6e511eec7342f59a25f7c0534f1dbea00d01b14\",\n cargo_triple: \"x86_64-unknown-illumos\",\n debug: true,\n opt_level: 0,\n}","v":0,"name":"crucible","level":30,"time":"2024-12-11T23:43:57.09960759Z","hostname":"w-01JEW1EECADXAJNR7ZZ07QNGFT","pid":1237}
3592024-12-11T23:43:58.004Z{"msg":"Upstairs <-> Downstairs Message Version: 12","v":0,"name":"crucible","level":30,"time":"2024-12-11T23:43:57.099630286Z","hostname":"w-01JEW1EECADXAJNR7ZZ07QNGFT","pid":1237}
3602024-12-11T23:43:58.004Z{"msg":"Using region definition RegionDefinition { block_size: 4096, extent_size: Block { value: 10, shift: 12 }, extent_count: 5, uuid: 00000000-0000-0000-0000-000000000000, encrypted: true, database_read_version: 1, database_write_version: 1 }","v":0,"name":"crucible","level":30,"time":"2024-12-11T23:43:57.099645954Z","hostname":"w-01JEW1EECADXAJNR7ZZ07QNGFT","pid":1237}
3612024-12-11T23:43:58.008Z{"msg":"Crucible 29eb25b9-5b95-4919-8c9d-b5b737ba66b9 has session id: b6f65ebb-1abc-415a-a7c2-08666dd18f12","v":0,"name":"crucible","level":30,"time":"2024-12-11T23:43:57.100192707Z","hostname":"w-01JEW1EECADXAJNR7ZZ07QNGFT","pid":1237,"session_id":"b6f65ebb-1abc-415a-a7c2-08666dd18f12"}
3622024-12-11T23:43:58.008Z{"msg":"Upstairs opts: Upstairs UUID: 29eb25b9-5b95-4919-8c9d-b5b737ba66b9, Targets: [127.0.0.1:8810, 127.0.0.1:8820, 127.0.0.1:8830], lossy: false, flush_timeout: None, key populated: true, cert_pem populated: false, key_pem populated: false, root_cert_pem populated: false, Control: None, read_only: false","v":0,"name":"crucible","level":30,"time":"2024-12-11T23:43:57.100246688Z","hostname":"w-01JEW1EECADXAJNR7ZZ07QNGFT","pid":1237,"session_id":"b6f65ebb-1abc-415a-a7c2-08666dd18f12"}
3632024-12-11T23:43:58.008Z{"msg":"Crucible stats registered with UUID: 29eb25b9-5b95-4919-8c9d-b5b737ba66b9","v":0,"name":"crucible","level":30,"time":"2024-12-11T23:43:57.100283651Z","hostname":"w-01JEW1EECADXAJNR7ZZ07QNGFT","pid":1237,"session_id":"b6f65ebb-1abc-415a-a7c2-08666dd18f12"}
3642024-12-11T23:43:58.008Z{"msg":"could not find Downstairs address for Nexus","v":0,"name":"crucible","level":40,"time":"2024-12-11T23:43:57.100306987Z","hostname":"w-01JEW1EECADXAJNR7ZZ07QNGFT","pid":1237,"session_id":"b6f65ebb-1abc-415a-a7c2-08666dd18f12"}
3652024-12-11T23:43:58.008Z{"msg":"Downstairs in volume = 3","v":0,"name":"crucible","level":30,"time":"2024-12-11T23:43:57.101232025Z","hostname":"w-01JEW1EECADXAJNR7ZZ07QNGFT","pid":1237,"task":"crutest"}
3662024-12-11T23:43:58.008Z{"msg":"The guest has requested activation with gen:33","v":0,"name":"crucible","level":30,"time":"2024-12-11T23:43:57.101290055Z","hostname":"w-01JEW1EECADXAJNR7ZZ07QNGFT","pid":1237}
3672024-12-11T23:43:58.008Z{"msg":"29eb25b9-5b95-4919-8c9d-b5b737ba66b9 active request set","v":0,"name":"crucible","level":30,"time":"2024-12-11T23:43:57.10131604Z","hostname":"w-01JEW1EECADXAJNR7ZZ07QNGFT","pid":1237,"session_id":"b6f65ebb-1abc-415a-a7c2-08666dd18f12"}
3682024-12-11T23:43:58.008Z{"msg":"sending connect oneshot to client","v":0,"name":"crucible","level":30,"time":"2024-12-11T23:43:57.101345295Z","hostname":"w-01JEW1EECADXAJNR7ZZ07QNGFT","pid":1237,"client":"0","":"downstairs","session_id":"b6f65ebb-1abc-415a-a7c2-08666dd18f12"}
3692024-12-11T23:43:58.008Z{"msg":"client set_active_request while in New; waiting...","v":0,"name":"crucible","level":30,"time":"2024-12-11T23:43:57.101394787Z","hostname":"w-01JEW1EECADXAJNR7ZZ07QNGFT","pid":1237,"client":"0","":"downstairs","session_id":"b6f65ebb-1abc-415a-a7c2-08666dd18f12"}
3702024-12-11T23:43:58.008Z{"msg":"sending connect oneshot to client","v":0,"name":"crucible","level":30,"time":"2024-12-11T23:43:57.101437909Z","hostname":"w-01JEW1EECADXAJNR7ZZ07QNGFT","pid":1237,"client":"1","":"downstairs","session_id":"b6f65ebb-1abc-415a-a7c2-08666dd18f12"}
3712024-12-11T23:43:58.008Z{"msg":"client set_active_request while in New; waiting...","v":0,"name":"crucible","level":30,"time":"2024-12-11T23:43:57.101468903Z","hostname":"w-01JEW1EECADXAJNR7ZZ07QNGFT","pid":1237,"client":"1","":"downstairs","session_id":"b6f65ebb-1abc-415a-a7c2-08666dd18f12"}
3722024-12-11T23:43:58.008Z{"msg":"sending connect oneshot to client","v":0,"name":"crucible","level":30,"time":"2024-12-11T23:43:57.101513736Z","hostname":"w-01JEW1EECADXAJNR7ZZ07QNGFT","pid":1237,"client":"2","":"downstairs","session_id":"b6f65ebb-1abc-415a-a7c2-08666dd18f12"}
3732024-12-11T23:43:58.008Z{"msg":"client set_active_request while in New; waiting...","v":0,"name":"crucible","level":30,"time":"2024-12-11T23:43:57.10154354Z","hostname":"w-01JEW1EECADXAJNR7ZZ07QNGFT","pid":1237,"client":"2","":"downstairs","session_id":"b6f65ebb-1abc-415a-a7c2-08666dd18f12"}
3742024-12-11T23:43:58.008Z{"msg":"connecting to 127.0.0.1:8810","v":0,"name":"crucible","level":30,"time":"2024-12-11T23:43:57.101591012Z","hostname":"w-01JEW1EECADXAJNR7ZZ07QNGFT","pid":1237,"":"io task","client":"0","":"downstairs","session_id":"b6f65ebb-1abc-415a-a7c2-08666dd18f12"}
3752024-12-11T23:43:58.008Z{"msg":"connecting to 127.0.0.1:8830","v":0,"name":"crucible","level":30,"time":"2024-12-11T23:43:57.101632055Z","hostname":"w-01JEW1EECADXAJNR7ZZ07QNGFT","pid":1237,"":"io task","client":"2","":"downstairs","session_id":"b6f65ebb-1abc-415a-a7c2-08666dd18f12"}
3762024-12-11T23:43:58.008Z{"msg":"connecting to 127.0.0.1:8820","v":0,"name":"crucible","level":30,"time":"2024-12-11T23:43:57.101671638Z","hostname":"w-01JEW1EECADXAJNR7ZZ07QNGFT","pid":1237,"":"io task","client":"1","":"downstairs","session_id":"b6f65ebb-1abc-415a-a7c2-08666dd18f12"}
3772024-12-11T23:43:58.008Z{"msg":"ds_connection connected from Ok(127.0.0.1:46018)","v":0,"name":"crucible","level":30,"time":"2024-12-11T23:43:57.101696314Z","hostname":"w-01JEW1EECADXAJNR7ZZ07QNGFT","pid":1237,"":"io task","client":"0","":"downstairs","session_id":"b6f65ebb-1abc-415a-a7c2-08666dd18f12"}
3782024-12-11T23:43:58.008Z{"msg":"ds_connection connected from Ok(127.0.0.1:64763)","v":0,"name":"crucible","level":30,"time":"2024-12-11T23:43:57.101732077Z","hostname":"w-01JEW1EECADXAJNR7ZZ07QNGFT","pid":1237,"":"io task","client":"1","":"downstairs","session_id":"b6f65ebb-1abc-415a-a7c2-08666dd18f12"}
3792024-12-11T23:43:58.008Z{"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-12-11T23:43:57.101987922Z","hostname":"w-01JEW1EECADXAJNR7ZZ07QNGFT","pid":1237,"":"io task","client":"2","":"downstairs","session_id":"b6f65ebb-1abc-415a-a7c2-08666dd18f12"}
3802024-12-11T23:43:58.008Z{"msg":"client task is sending Done(ConnectionFailed(Os { code: 146, kind: ConnectionRefused, message: \"Connection refused\" }))","v":0,"name":"crucible","level":40,"time":"2024-12-11T23:43:57.102020457Z","hostname":"w-01JEW1EECADXAJNR7ZZ07QNGFT","pid":1237,"":"io task","client":"2","":"downstairs","session_id":"b6f65ebb-1abc-415a-a7c2-08666dd18f12"}
3812024-12-11T23:43:58.008Z{"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-12-11T23:43:57.102047132Z","hostname":"w-01JEW1EECADXAJNR7ZZ07QNGFT","pid":1237,"session_id":"b6f65ebb-1abc-415a-a7c2-08666dd18f12"}
3822024-12-11T23:43:58.008Z{"msg":"client task is exiting","v":0,"name":"crucible","level":30,"time":"2024-12-11T23:43:57.102100712Z","hostname":"w-01JEW1EECADXAJNR7ZZ07QNGFT","pid":1237,"":"io task","client":"2","":"downstairs","session_id":"b6f65ebb-1abc-415a-a7c2-08666dd18f12"}
3832024-12-11T23:43:58.008Z{"msg":"ds_transition from New to WaitActive","v":0,"name":"crucible","level":30,"time":"2024-12-11T23:43:57.102421136Z","hostname":"w-01JEW1EECADXAJNR7ZZ07QNGFT","pid":1237,"client":"0","":"downstairs","session_id":"b6f65ebb-1abc-415a-a7c2-08666dd18f12"}
3842024-12-11T23:43:58.008Z{"msg":"[0] Transition from New to WaitActive","v":0,"name":"crucible","level":30,"time":"2024-12-11T23:43:57.102471407Z","hostname":"w-01JEW1EECADXAJNR7ZZ07QNGFT","pid":1237,"client":"0","":"downstairs","session_id":"b6f65ebb-1abc-415a-a7c2-08666dd18f12"}
3852024-12-11T23:43:58.008Z{"msg":"ds_transition from New to WaitActive","v":0,"name":"crucible","level":30,"time":"2024-12-11T23:43:57.102510251Z","hostname":"w-01JEW1EECADXAJNR7ZZ07QNGFT","pid":1237,"client":"1","":"downstairs","session_id":"b6f65ebb-1abc-415a-a7c2-08666dd18f12"}
3862024-12-11T23:43:58.008Z{"msg":"[1] Transition from New to WaitActive","v":0,"name":"crucible","level":30,"time":"2024-12-11T23:43:57.102552313Z","hostname":"w-01JEW1EECADXAJNR7ZZ07QNGFT","pid":1237,"client":"1","":"downstairs","session_id":"b6f65ebb-1abc-415a-a7c2-08666dd18f12"}
3872024-12-11T23:43:58.008Z{"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-12-11T23:43:57.10302894Z","hostname":"w-01JEW1EECADXAJNR7ZZ07QNGFT","pid":1237,"client":"1","":"downstairs","session_id":"b6f65ebb-1abc-415a-a7c2-08666dd18f12"}
3882024-12-11T23:43:58.008Z{"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-12-11T23:43:57.103172095Z","hostname":"w-01JEW1EECADXAJNR7ZZ07QNGFT","pid":1237,"client":"0","":"downstairs","session_id":"b6f65ebb-1abc-415a-a7c2-08666dd18f12"}
3892024-12-11T23:43:58.012Z{"msg":"ds_transition from WaitActive to WaitQuorum","v":0,"name":"crucible","level":30,"time":"2024-12-11T23:43:57.103419071Z","hostname":"w-01JEW1EECADXAJNR7ZZ07QNGFT","pid":1237,"client":"1","":"downstairs","session_id":"b6f65ebb-1abc-415a-a7c2-08666dd18f12"}
3902024-12-11T23:43:58.012Z{"msg":"[1] Transition from WaitActive to WaitQuorum","v":0,"name":"crucible","level":30,"time":"2024-12-11T23:43:57.103454325Z","hostname":"w-01JEW1EECADXAJNR7ZZ07QNGFT","pid":1237,"client":"1","":"downstairs","session_id":"b6f65ebb-1abc-415a-a7c2-08666dd18f12"}
3912024-12-11T23:43:58.012Z{"msg":"Waiting for more clients to be ready","v":0,"name":"crucible","level":30,"time":"2024-12-11T23:43:57.103469652Z","hostname":"w-01JEW1EECADXAJNR7ZZ07QNGFT","pid":1237,"session_id":"b6f65ebb-1abc-415a-a7c2-08666dd18f12"}
3922024-12-11T23:43:58.012Z{"msg":"ds_transition from WaitActive to WaitQuorum","v":0,"name":"crucible","level":30,"time":"2024-12-11T23:43:57.103496218Z","hostname":"w-01JEW1EECADXAJNR7ZZ07QNGFT","pid":1237,"client":"0","":"downstairs","session_id":"b6f65ebb-1abc-415a-a7c2-08666dd18f12"}
3932024-12-11T23:43:58.012Z{"msg":"[0] Transition from WaitActive to WaitQuorum","v":0,"name":"crucible","level":30,"time":"2024-12-11T23:43:57.103514684Z","hostname":"w-01JEW1EECADXAJNR7ZZ07QNGFT","pid":1237,"client":"0","":"downstairs","session_id":"b6f65ebb-1abc-415a-a7c2-08666dd18f12"}
3942024-12-11T23:43:58.012Z{"msg":"Waiting for more clients to be ready","v":0,"name":"crucible","level":30,"time":"2024-12-11T23:43:57.10353958Z","hostname":"w-01JEW1EECADXAJNR7ZZ07QNGFT","pid":1237,"session_id":"b6f65ebb-1abc-415a-a7c2-08666dd18f12"}
3952024-12-11T23:44:08.010Z{"msg":"connecting to 127.0.0.1:8830","v":0,"name":"crucible","level":30,"time":"2024-12-11T23:44:07.103514184Z","hostname":"w-01JEW1EECADXAJNR7ZZ07QNGFT","pid":1237,"":"io task","client":"2","":"downstairs","session_id":"b6f65ebb-1abc-415a-a7c2-08666dd18f12"}
3962024-12-11T23:44:08.010Z{"msg":"ds_connection connected from Ok(127.0.0.1:50598)","v":0,"name":"crucible","level":30,"time":"2024-12-11T23:44:07.103622395Z","hostname":"w-01JEW1EECADXAJNR7ZZ07QNGFT","pid":1237,"":"io task","client":"2","":"downstairs","session_id":"b6f65ebb-1abc-415a-a7c2-08666dd18f12"}
3972024-12-11T23:44:08.014Z{"msg":"ds_transition from New to WaitActive","v":0,"name":"crucible","level":30,"time":"2024-12-11T23:44:07.104597114Z","hostname":"w-01JEW1EECADXAJNR7ZZ07QNGFT","pid":1237,"client":"2","":"downstairs","session_id":"b6f65ebb-1abc-415a-a7c2-08666dd18f12"}
3982024-12-11T23:44:08.014Z{"msg":"[2] Transition from New to WaitActive","v":0,"name":"crucible","level":30,"time":"2024-12-11T23:44:07.104630368Z","hostname":"w-01JEW1EECADXAJNR7ZZ07QNGFT","pid":1237,"client":"2","":"downstairs","session_id":"b6f65ebb-1abc-415a-a7c2-08666dd18f12"}
3992024-12-11T23:44:08.014Z{"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-12-11T23:44:07.105111634Z","hostname":"w-01JEW1EECADXAJNR7ZZ07QNGFT","pid":1237,"client":"2","":"downstairs","session_id":"b6f65ebb-1abc-415a-a7c2-08666dd18f12"}
4002024-12-11T23:44:08.014Z{"msg":"ds_transition from WaitActive to WaitQuorum","v":0,"name":"crucible","level":30,"time":"2024-12-11T23:44:07.105459083Z","hostname":"w-01JEW1EECADXAJNR7ZZ07QNGFT","pid":1237,"client":"2","":"downstairs","session_id":"b6f65ebb-1abc-415a-a7c2-08666dd18f12"}
4012024-12-11T23:44:08.014Z{"msg":"[2] Transition from WaitActive to WaitQuorum","v":0,"name":"crucible","level":30,"time":"2024-12-11T23:44:07.105491067Z","hostname":"w-01JEW1EECADXAJNR7ZZ07QNGFT","pid":1237,"client":"2","":"downstairs","session_id":"b6f65ebb-1abc-415a-a7c2-08666dd18f12"}
4022024-12-11T23:44:08.014Z{"msg":"[0]R flush_numbers: [1502, 1502, 1502, 1502, 1502]","v":0,"name":"crucible","level":30,"time":"2024-12-11T23:44:07.105508174Z","hostname":"w-01JEW1EECADXAJNR7ZZ07QNGFT","pid":1237,"":"downstairs","":"downstairs","session_id":"b6f65ebb-1abc-415a-a7c2-08666dd18f12"}
4032024-12-11T23:44:08.014Z{"msg":"[0]R generation: [32, 32, 32, 32, 32]","v":0,"name":"crucible","level":30,"time":"2024-12-11T23:44:07.105541418Z","hostname":"w-01JEW1EECADXAJNR7ZZ07QNGFT","pid":1237,"":"downstairs","":"downstairs","session_id":"b6f65ebb-1abc-415a-a7c2-08666dd18f12"}
4042024-12-11T23:44:08.014Z{"msg":"[0]R dirty: [false, false, false, false, false]","v":0,"name":"crucible","level":30,"time":"2024-12-11T23:44:07.105574243Z","hostname":"w-01JEW1EECADXAJNR7ZZ07QNGFT","pid":1237,"":"downstairs","":"downstairs","session_id":"b6f65ebb-1abc-415a-a7c2-08666dd18f12"}
4052024-12-11T23:44:08.014Z{"msg":"[1]R flush_numbers: [1502, 1502, 1502, 1502, 1502]","v":0,"name":"crucible","level":30,"time":"2024-12-11T23:44:07.105610366Z","hostname":"w-01JEW1EECADXAJNR7ZZ07QNGFT","pid":1237,"":"downstairs","":"downstairs","session_id":"b6f65ebb-1abc-415a-a7c2-08666dd18f12"}
4062024-12-11T23:44:08.015Z{"msg":"[1]R generation: [32, 32, 32, 32, 32]","v":0,"name":"crucible","level":30,"time":"2024-12-11T23:44:07.10564408Z","hostname":"w-01JEW1EECADXAJNR7ZZ07QNGFT","pid":1237,"":"downstairs","":"downstairs","session_id":"b6f65ebb-1abc-415a-a7c2-08666dd18f12"}
4072024-12-11T23:44:08.015Z{"msg":"[1]R dirty: [false, false, false, false, false]","v":0,"name":"crucible","level":30,"time":"2024-12-11T23:44:07.105678214Z","hostname":"w-01JEW1EECADXAJNR7ZZ07QNGFT","pid":1237,"":"downstairs","":"downstairs","session_id":"b6f65ebb-1abc-415a-a7c2-08666dd18f12"}
4082024-12-11T23:44:08.015Z{"msg":"[2]R flush_numbers: [1501, 1501, 1501, 1501, 1501]","v":0,"name":"crucible","level":30,"time":"2024-12-11T23:44:07.105712748Z","hostname":"w-01JEW1EECADXAJNR7ZZ07QNGFT","pid":1237,"":"downstairs","":"downstairs","session_id":"b6f65ebb-1abc-415a-a7c2-08666dd18f12"}
4092024-12-11T23:44:08.015Z{"msg":"[2]R generation: [31, 31, 31, 31, 31]","v":0,"name":"crucible","level":30,"time":"2024-12-11T23:44:07.105730505Z","hostname":"w-01JEW1EECADXAJNR7ZZ07QNGFT","pid":1237,"":"downstairs","":"downstairs","session_id":"b6f65ebb-1abc-415a-a7c2-08666dd18f12"}
4102024-12-11T23:44:08.015Z{"msg":"[2]R dirty: [false, false, false, false, false]","v":0,"name":"crucible","level":30,"time":"2024-12-11T23:44:07.105762969Z","hostname":"w-01JEW1EECADXAJNR7ZZ07QNGFT","pid":1237,"":"downstairs","":"downstairs","session_id":"b6f65ebb-1abc-415a-a7c2-08666dd18f12"}
4112024-12-11T23:44:08.015Z{"msg":"Max found gen is 33","v":0,"name":"crucible","level":30,"time":"2024-12-11T23:44:07.105796564Z","hostname":"w-01JEW1EECADXAJNR7ZZ07QNGFT","pid":1237,"":"downstairs","":"downstairs","session_id":"b6f65ebb-1abc-415a-a7c2-08666dd18f12"}
4122024-12-11T23:44:08.015Z{"msg":"Generation requested: 33 >= found:33","v":0,"name":"crucible","level":30,"time":"2024-12-11T23:44:07.105831547Z","hostname":"w-01JEW1EECADXAJNR7ZZ07QNGFT","pid":1237,"":"downstairs","":"downstairs","session_id":"b6f65ebb-1abc-415a-a7c2-08666dd18f12"}
4132024-12-11T23:44:08.015Z{"msg":"Next flush: 1503","v":0,"name":"crucible","level":30,"time":"2024-12-11T23:44:07.105863872Z","hostname":"w-01JEW1EECADXAJNR7ZZ07QNGFT","pid":1237,"":"downstairs","":"downstairs","session_id":"b6f65ebb-1abc-415a-a7c2-08666dd18f12"}
4142024-12-11T23:44:08.015Z{"msg":"Extent 0 has flush number mismatch","v":0,"name":"crucible","level":30,"time":"2024-12-11T23:44:07.105898326Z","hostname":"w-01JEW1EECADXAJNR7ZZ07QNGFT","pid":1237,"":"mend","":"downstairs","":"downstairs","session_id":"b6f65ebb-1abc-415a-a7c2-08666dd18f12"}
4152024-12-11T23:44:08.015Z{"msg":"First source client ID for extent 0","v":0,"name":"crucible","level":30,"time":"2024-12-11T23:44:07.105919952Z","hostname":"w-01JEW1EECADXAJNR7ZZ07QNGFT","pid":1237,"mrl":"flush_mismatch","":"mend","":"downstairs","":"downstairs","session_id":"b6f65ebb-1abc-415a-a7c2-08666dd18f12"}
4162024-12-11T23:44:08.015Z{"msg":"extent:0 gens: 32 32 31","v":0,"name":"crucible","level":30,"time":"2024-12-11T23:44:07.105952246Z","hostname":"w-01JEW1EECADXAJNR7ZZ07QNGFT","pid":1237,"mrl":"flush_mismatch","":"mend","":"downstairs","":"downstairs","session_id":"b6f65ebb-1abc-415a-a7c2-08666dd18f12"}
4172024-12-11T23:44:08.015Z{"msg":"extent:0 flush: 1502 1502 1501 scs: [ClientId(0), ClientId(1)]","v":0,"name":"crucible","level":30,"time":"2024-12-11T23:44:07.105970633Z","hostname":"w-01JEW1EECADXAJNR7ZZ07QNGFT","pid":1237,"mrl":"flush_mismatch","":"mend","":"downstairs","":"downstairs","session_id":"b6f65ebb-1abc-415a-a7c2-08666dd18f12"}
4182024-12-11T23:44:08.015Z{"msg":"max_flush now has: [ClientId(0), ClientId(1)]","v":0,"name":"crucible","level":30,"time":"2024-12-11T23:44:07.105992899Z","hostname":"w-01JEW1EECADXAJNR7ZZ07QNGFT","pid":1237,"mrl":"flush_mismatch","":"mend","":"downstairs","":"downstairs","session_id":"b6f65ebb-1abc-415a-a7c2-08666dd18f12"}
4192024-12-11T23:44:08.015Z{"msg":"extent:0 dirty: false false false","v":0,"name":"crucible","level":30,"time":"2024-12-11T23:44:07.106027623Z","hostname":"w-01JEW1EECADXAJNR7ZZ07QNGFT","pid":1237,"mrl":"flush_mismatch","":"mend","":"downstairs","":"downstairs","session_id":"b6f65ebb-1abc-415a-a7c2-08666dd18f12"}
4202024-12-11T23:44:08.015Z{"msg":"No maxes found, left with: [ClientId(0), ClientId(1)]","v":0,"name":"crucible","level":30,"time":"2024-12-11T23:44:07.10604549Z","hostname":"w-01JEW1EECADXAJNR7ZZ07QNGFT","pid":1237,"mrl":"flush_mismatch","":"mend","":"downstairs","":"downstairs","session_id":"b6f65ebb-1abc-415a-a7c2-08666dd18f12"}
4212024-12-11T23:44:08.015Z{"msg":"find dest for source 0 for extent at index 0","v":0,"name":"crucible","level":30,"time":"2024-12-11T23:44:07.106069366Z","hostname":"w-01JEW1EECADXAJNR7ZZ07QNGFT","pid":1237,"mrl":"flush_mismatch","":"mend","":"downstairs","":"downstairs","session_id":"b6f65ebb-1abc-415a-a7c2-08666dd18f12"}
4222024-12-11T23:44:08.015Z{"msg":"source 0, add dest 2 gen","v":0,"name":"crucible","level":30,"time":"2024-12-11T23:44:07.106086123Z","hostname":"w-01JEW1EECADXAJNR7ZZ07QNGFT","pid":1237,"mrl":"flush_mismatch","":"mend","":"downstairs","":"downstairs","session_id":"b6f65ebb-1abc-415a-a7c2-08666dd18f12"}
4232024-12-11T23:44:08.015Z{"msg":"Extent 1 has flush number mismatch","v":0,"name":"crucible","level":30,"time":"2024-12-11T23:44:07.106120217Z","hostname":"w-01JEW1EECADXAJNR7ZZ07QNGFT","pid":1237,"":"mend","":"downstairs","":"downstairs","session_id":"b6f65ebb-1abc-415a-a7c2-08666dd18f12"}
4242024-12-11T23:44:08.015Z{"msg":"First source client ID for extent 1","v":0,"name":"crucible","level":30,"time":"2024-12-11T23:44:07.106137114Z","hostname":"w-01JEW1EECADXAJNR7ZZ07QNGFT","pid":1237,"mrl":"flush_mismatch","":"mend","":"downstairs","":"downstairs","session_id":"b6f65ebb-1abc-415a-a7c2-08666dd18f12"}
4252024-12-11T23:44:08.015Z{"msg":"extent:1 gens: 32 32 31","v":0,"name":"crucible","level":30,"time":"2024-12-11T23:44:07.106162599Z","hostname":"w-01JEW1EECADXAJNR7ZZ07QNGFT","pid":1237,"mrl":"flush_mismatch","":"mend","":"downstairs","":"downstairs","session_id":"b6f65ebb-1abc-415a-a7c2-08666dd18f12"}
4262024-12-11T23:44:08.015Z{"msg":"extent:1 flush: 1502 1502 1501 scs: [ClientId(0), ClientId(1)]","v":0,"name":"crucible","level":30,"time":"2024-12-11T23:44:07.106179676Z","hostname":"w-01JEW1EECADXAJNR7ZZ07QNGFT","pid":1237,"mrl":"flush_mismatch","":"mend","":"downstairs","":"downstairs","session_id":"b6f65ebb-1abc-415a-a7c2-08666dd18f12"}
4272024-12-11T23:44:08.015Z{"msg":"max_flush now has: [ClientId(0), ClientId(1)]","v":0,"name":"crucible","level":30,"time":"2024-12-11T23:44:07.106202632Z","hostname":"w-01JEW1EECADXAJNR7ZZ07QNGFT","pid":1237,"mrl":"flush_mismatch","":"mend","":"downstairs","":"downstairs","session_id":"b6f65ebb-1abc-415a-a7c2-08666dd18f12"}
4282024-12-11T23:44:08.015Z{"msg":"extent:1 dirty: false false false","v":0,"name":"crucible","level":30,"time":"2024-12-11T23:44:07.106218819Z","hostname":"w-01JEW1EECADXAJNR7ZZ07QNGFT","pid":1237,"mrl":"flush_mismatch","":"mend","":"downstairs","":"downstairs","session_id":"b6f65ebb-1abc-415a-a7c2-08666dd18f12"}
4292024-12-11T23:44:08.015Z{"msg":"No maxes found, left with: [ClientId(0), ClientId(1)]","v":0,"name":"crucible","level":30,"time":"2024-12-11T23:44:07.106242015Z","hostname":"w-01JEW1EECADXAJNR7ZZ07QNGFT","pid":1237,"mrl":"flush_mismatch","":"mend","":"downstairs","":"downstairs","session_id":"b6f65ebb-1abc-415a-a7c2-08666dd18f12"}
4302024-12-11T23:44:08.015Z{"msg":"find dest for source 0 for extent at index 1","v":0,"name":"crucible","level":30,"time":"2024-12-11T23:44:07.106258083Z","hostname":"w-01JEW1EECADXAJNR7ZZ07QNGFT","pid":1237,"mrl":"flush_mismatch","":"mend","":"downstairs","":"downstairs","session_id":"b6f65ebb-1abc-415a-a7c2-08666dd18f12"}
4312024-12-11T23:44:08.015Z{"msg":"source 0, add dest 2 gen","v":0,"name":"crucible","level":30,"time":"2024-12-11T23:44:07.106279959Z","hostname":"w-01JEW1EECADXAJNR7ZZ07QNGFT","pid":1237,"mrl":"flush_mismatch","":"mend","":"downstairs","":"downstairs","session_id":"b6f65ebb-1abc-415a-a7c2-08666dd18f12"}
4322024-12-11T23:44:08.015Z{"msg":"Extent 2 has flush number mismatch","v":0,"name":"crucible","level":30,"time":"2024-12-11T23:44:07.106296786Z","hostname":"w-01JEW1EECADXAJNR7ZZ07QNGFT","pid":1237,"":"mend","":"downstairs","":"downstairs","session_id":"b6f65ebb-1abc-415a-a7c2-08666dd18f12"}
4332024-12-11T23:44:08.015Z{"msg":"First source client ID for extent 2","v":0,"name":"crucible","level":30,"time":"2024-12-11T23:44:07.106319442Z","hostname":"w-01JEW1EECADXAJNR7ZZ07QNGFT","pid":1237,"mrl":"flush_mismatch","":"mend","":"downstairs","":"downstairs","session_id":"b6f65ebb-1abc-415a-a7c2-08666dd18f12"}
4342024-12-11T23:44:08.015Z{"msg":"extent:2 gens: 32 32 31","v":0,"name":"crucible","level":30,"time":"2024-12-11T23:44:07.106335099Z","hostname":"w-01JEW1EECADXAJNR7ZZ07QNGFT","pid":1237,"mrl":"flush_mismatch","":"mend","":"downstairs","":"downstairs","session_id":"b6f65ebb-1abc-415a-a7c2-08666dd18f12"}
4352024-12-11T23:44:08.015Z{"msg":"extent:2 flush: 1502 1502 1501 scs: [ClientId(0), ClientId(1)]","v":0,"name":"crucible","level":30,"time":"2024-12-11T23:44:07.106358175Z","hostname":"w-01JEW1EECADXAJNR7ZZ07QNGFT","pid":1237,"mrl":"flush_mismatch","":"mend","":"downstairs","":"downstairs","session_id":"b6f65ebb-1abc-415a-a7c2-08666dd18f12"}
4362024-12-11T23:44:08.015Z{"msg":"max_flush now has: [ClientId(0), ClientId(1)]","v":0,"name":"crucible","level":30,"time":"2024-12-11T23:44:07.10638778Z","hostname":"w-01JEW1EECADXAJNR7ZZ07QNGFT","pid":1237,"mrl":"flush_mismatch","":"mend","":"downstairs","":"downstairs","session_id":"b6f65ebb-1abc-415a-a7c2-08666dd18f12"}
4372024-12-11T23:44:08.015Z{"msg":"extent:2 dirty: false false false","v":0,"name":"crucible","level":30,"time":"2024-12-11T23:44:07.106411136Z","hostname":"w-01JEW1EECADXAJNR7ZZ07QNGFT","pid":1237,"mrl":"flush_mismatch","":"mend","":"downstairs","":"downstairs","session_id":"b6f65ebb-1abc-415a-a7c2-08666dd18f12"}
4382024-12-11T23:44:08.020Z{"msg":"No maxes found, left with: [ClientId(0), ClientId(1)]","v":0,"name":"crucible","level":30,"time":"2024-12-11T23:44:07.106431832Z","hostname":"w-01JEW1EECADXAJNR7ZZ07QNGFT","pid":1237,"mrl":"flush_mismatch","":"mend","":"downstairs","":"downstairs","session_id":"b6f65ebb-1abc-415a-a7c2-08666dd18f12"}
4392024-12-11T23:44:08.020Z{"msg":"find dest for source 0 for extent at index 2","v":0,"name":"crucible","level":30,"time":"2024-12-11T23:44:07.106466136Z","hostname":"w-01JEW1EECADXAJNR7ZZ07QNGFT","pid":1237,"mrl":"flush_mismatch","":"mend","":"downstairs","":"downstairs","session_id":"b6f65ebb-1abc-415a-a7c2-08666dd18f12"}
4402024-12-11T23:44:08.020Z{"msg":"source 0, add dest 2 gen","v":0,"name":"crucible","level":30,"time":"2024-12-11T23:44:07.106484353Z","hostname":"w-01JEW1EECADXAJNR7ZZ07QNGFT","pid":1237,"mrl":"flush_mismatch","":"mend","":"downstairs","":"downstairs","session_id":"b6f65ebb-1abc-415a-a7c2-08666dd18f12"}
4412024-12-11T23:44:08.020Z{"msg":"Extent 3 has flush number mismatch","v":0,"name":"crucible","level":30,"time":"2024-12-11T23:44:07.106518617Z","hostname":"w-01JEW1EECADXAJNR7ZZ07QNGFT","pid":1237,"":"mend","":"downstairs","":"downstairs","session_id":"b6f65ebb-1abc-415a-a7c2-08666dd18f12"}
4422024-12-11T23:44:08.020Z{"msg":"First source client ID for extent 3","v":0,"name":"crucible","level":30,"time":"2024-12-11T23:44:07.106539003Z","hostname":"w-01JEW1EECADXAJNR7ZZ07QNGFT","pid":1237,"mrl":"flush_mismatch","":"mend","":"downstairs","":"downstairs","session_id":"b6f65ebb-1abc-415a-a7c2-08666dd18f12"}
4432024-12-11T23:44:08.020Z{"msg":"extent:3 gens: 32 32 31","v":0,"name":"crucible","level":30,"time":"2024-12-11T23:44:07.106571608Z","hostname":"w-01JEW1EECADXAJNR7ZZ07QNGFT","pid":1237,"mrl":"flush_mismatch","":"mend","":"downstairs","":"downstairs","session_id":"b6f65ebb-1abc-415a-a7c2-08666dd18f12"}
4442024-12-11T23:44:08.020Z{"msg":"extent:3 flush: 1502 1502 1501 scs: [ClientId(0), ClientId(1)]","v":0,"name":"crucible","level":30,"time":"2024-12-11T23:44:07.106589434Z","hostname":"w-01JEW1EECADXAJNR7ZZ07QNGFT","pid":1237,"mrl":"flush_mismatch","":"mend","":"downstairs","":"downstairs","session_id":"b6f65ebb-1abc-415a-a7c2-08666dd18f12"}
4452024-12-11T23:44:08.020Z{"msg":"max_flush now has: [ClientId(0), ClientId(1)]","v":0,"name":"crucible","level":30,"time":"2024-12-11T23:44:07.106624048Z","hostname":"w-01JEW1EECADXAJNR7ZZ07QNGFT","pid":1237,"mrl":"flush_mismatch","":"mend","":"downstairs","":"downstairs","session_id":"b6f65ebb-1abc-415a-a7c2-08666dd18f12"}
4462024-12-11T23:44:08.020Z{"msg":"extent:3 dirty: false false false","v":0,"name":"crucible","level":30,"time":"2024-12-11T23:44:07.106646104Z","hostname":"w-01JEW1EECADXAJNR7ZZ07QNGFT","pid":1237,"mrl":"flush_mismatch","":"mend","":"downstairs","":"downstairs","session_id":"b6f65ebb-1abc-415a-a7c2-08666dd18f12"}
4472024-12-11T23:44:08.020Z{"msg":"No maxes found, left with: [ClientId(0), ClientId(1)]","v":0,"name":"crucible","level":30,"time":"2024-12-11T23:44:07.10667319Z","hostname":"w-01JEW1EECADXAJNR7ZZ07QNGFT","pid":1237,"mrl":"flush_mismatch","":"mend","":"downstairs","":"downstairs","session_id":"b6f65ebb-1abc-415a-a7c2-08666dd18f12"}
4482024-12-11T23:44:08.020Z{"msg":"find dest for source 0 for extent at index 3","v":0,"name":"crucible","level":30,"time":"2024-12-11T23:44:07.106690137Z","hostname":"w-01JEW1EECADXAJNR7ZZ07QNGFT","pid":1237,"mrl":"flush_mismatch","":"mend","":"downstairs","":"downstairs","session_id":"b6f65ebb-1abc-415a-a7c2-08666dd18f12"}
4492024-12-11T23:44:08.020Z{"msg":"source 0, add dest 2 gen","v":0,"name":"crucible","level":30,"time":"2024-12-11T23:44:07.106724501Z","hostname":"w-01JEW1EECADXAJNR7ZZ07QNGFT","pid":1237,"mrl":"flush_mismatch","":"mend","":"downstairs","":"downstairs","session_id":"b6f65ebb-1abc-415a-a7c2-08666dd18f12"}
4502024-12-11T23:44:08.020Z{"msg":"Extent 4 has flush number mismatch","v":0,"name":"crucible","level":30,"time":"2024-12-11T23:44:07.106754395Z","hostname":"w-01JEW1EECADXAJNR7ZZ07QNGFT","pid":1237,"":"mend","":"downstairs","":"downstairs","session_id":"b6f65ebb-1abc-415a-a7c2-08666dd18f12"}
4512024-12-11T23:44:08.020Z{"msg":"First source client ID for extent 4","v":0,"name":"crucible","level":30,"time":"2024-12-11T23:44:07.106793989Z","hostname":"w-01JEW1EECADXAJNR7ZZ07QNGFT","pid":1237,"mrl":"flush_mismatch","":"mend","":"downstairs","":"downstairs","session_id":"b6f65ebb-1abc-415a-a7c2-08666dd18f12"}
4522024-12-11T23:44:08.020Z{"msg":"extent:4 gens: 32 32 31","v":0,"name":"crucible","level":30,"time":"2024-12-11T23:44:07.106825803Z","hostname":"w-01JEW1EECADXAJNR7ZZ07QNGFT","pid":1237,"mrl":"flush_mismatch","":"mend","":"downstairs","":"downstairs","session_id":"b6f65ebb-1abc-415a-a7c2-08666dd18f12"}
4532024-12-11T23:44:08.020Z{"msg":"extent:4 flush: 1502 1502 1501 scs: [ClientId(0), ClientId(1)]","v":0,"name":"crucible","level":30,"time":"2024-12-11T23:44:07.106858387Z","hostname":"w-01JEW1EECADXAJNR7ZZ07QNGFT","pid":1237,"mrl":"flush_mismatch","":"mend","":"downstairs","":"downstairs","session_id":"b6f65ebb-1abc-415a-a7c2-08666dd18f12"}
4542024-12-11T23:44:08.020Z{"msg":"max_flush now has: [ClientId(0), ClientId(1)]","v":0,"name":"crucible","level":30,"time":"2024-12-11T23:44:07.106881803Z","hostname":"w-01JEW1EECADXAJNR7ZZ07QNGFT","pid":1237,"mrl":"flush_mismatch","":"mend","":"downstairs","":"downstairs","session_id":"b6f65ebb-1abc-415a-a7c2-08666dd18f12"}
4552024-12-11T23:44:08.020Z{"msg":"extent:4 dirty: false false false","v":0,"name":"crucible","level":30,"time":"2024-12-11T23:44:07.106907838Z","hostname":"w-01JEW1EECADXAJNR7ZZ07QNGFT","pid":1237,"mrl":"flush_mismatch","":"mend","":"downstairs","":"downstairs","session_id":"b6f65ebb-1abc-415a-a7c2-08666dd18f12"}
4562024-12-11T23:44:08.020Z{"msg":"No maxes found, left with: [ClientId(0), ClientId(1)]","v":0,"name":"crucible","level":30,"time":"2024-12-11T23:44:07.106929335Z","hostname":"w-01JEW1EECADXAJNR7ZZ07QNGFT","pid":1237,"mrl":"flush_mismatch","":"mend","":"downstairs","":"downstairs","session_id":"b6f65ebb-1abc-415a-a7c2-08666dd18f12"}
4572024-12-11T23:44:08.020Z{"msg":"find dest for source 0 for extent at index 4","v":0,"name":"crucible","level":30,"time":"2024-12-11T23:44:07.106966508Z","hostname":"w-01JEW1EECADXAJNR7ZZ07QNGFT","pid":1237,"mrl":"flush_mismatch","":"mend","":"downstairs","":"downstairs","session_id":"b6f65ebb-1abc-415a-a7c2-08666dd18f12"}
4582024-12-11T23:44:08.020Z{"msg":"source 0, add dest 2 gen","v":0,"name":"crucible","level":30,"time":"2024-12-11T23:44:07.10701456Z","hostname":"w-01JEW1EECADXAJNR7ZZ07QNGFT","pid":1237,"mrl":"flush_mismatch","":"mend","":"downstairs","":"downstairs","session_id":"b6f65ebb-1abc-415a-a7c2-08666dd18f12"}
4592024-12-11T23:44:08.020Z{"msg":"Transition from WaitQuorum to Reconcile","v":0,"name":"crucible","level":30,"time":"2024-12-11T23:44:07.107063281Z","hostname":"w-01JEW1EECADXAJNR7ZZ07QNGFT","pid":1237,"client":"0","":"downstairs","session_id":"b6f65ebb-1abc-415a-a7c2-08666dd18f12"}
4602024-12-11T23:44:08.020Z{"msg":"Transition from WaitQuorum to Reconcile","v":0,"name":"crucible","level":30,"time":"2024-12-11T23:44:07.107109673Z","hostname":"w-01JEW1EECADXAJNR7ZZ07QNGFT","pid":1237,"client":"1","":"downstairs","session_id":"b6f65ebb-1abc-415a-a7c2-08666dd18f12"}
4612024-12-11T23:44:08.020Z{"msg":"Transition from WaitQuorum to Reconcile","v":0,"name":"crucible","level":30,"time":"2024-12-11T23:44:07.107151676Z","hostname":"w-01JEW1EECADXAJNR7ZZ07QNGFT","pid":1237,"client":"2","":"downstairs","session_id":"b6f65ebb-1abc-415a-a7c2-08666dd18f12"}
4622024-12-11T23:44:08.020Z{"msg":"Full repair list: {ExtentId(3): ExtentFix { source: ClientId(0), dest: [ClientId(2)] }, ExtentId(4): ExtentFix { source: ClientId(0), dest: [ClientId(2)] }, ExtentId(1): ExtentFix { source: ClientId(0), dest: [ClientId(2)] }, ExtentId(2): ExtentFix { source: ClientId(0), dest: [ClientId(2)] }, ExtentId(0): ExtentFix { source: ClientId(0), dest: [ClientId(2)] }}","v":0,"name":"crucible","level":30,"time":"2024-12-11T23:44:07.10718658Z","hostname":"w-01JEW1EECADXAJNR7ZZ07QNGFT","pid":1237,"":"downstairs","":"downstairs","session_id":"b6f65ebb-1abc-415a-a7c2-08666dd18f12"}
4632024-12-11T23:44:08.020Z{"msg":"Task list: [ReconcileIO { id: ReconciliationId(0), op: ExtentFlush { repair_id: ReconciliationId(0), extent_id: ExtentId(3), client_id: ClientId(0), flush_number: 1503, gen_number: 33 }, state: ClientData([New, New, New]) }, ReconcileIO { id: ReconciliationId(1), op: ExtentClose { repair_id: ReconciliationId(1), extent_id: ExtentId(3) }, state: ClientData([New, New, New]) }, ReconcileIO { id: ReconciliationId(2), op: ExtentRepair { repair_id: ReconciliationId(2), extent_id: ExtentId(3), source_client_id: ClientId(0), source_repair_address: 0.0.0.0:12810, dest_clients: [ClientId(2)] }, state: ClientData([New, New, New]) }, ReconcileIO { id: ReconciliationId(3), op: ExtentReopen { repair_id: ReconciliationId(3), extent_id: ExtentId(3) }, 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: 1503, 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(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(1), client_id: ClientId(0), flush_number: 1503, gen_number: 33 }, state: ClientData([New, New, New]) }, ReconcileIO { id: ReconciliationId(9), op: ExtentClose { repair_id: ReconciliationId(9), extent_id: ExtentId(1) }, state: ClientData([New, New, New]) }, ReconcileIO { id: ReconciliationId(10), op: ExtentRepair { repair_id: ReconciliationId(10), extent_id: ExtentId(1), source_client_id: ClientId(0), source_repair_address: 0.0.0.0:12810, dest_clients: [ClientId(2)] }, state: ClientData([New, New, New]) }, ReconcileIO { id: ReconciliationId(11), op: ExtentReopen { repair_id: ReconciliationId(11), extent_id: ExtentId(1) }, state: ClientData([New, New, New]) }, ReconcileIO { id: ReconciliationId(12), op: ExtentFlush { repair_id: ReconciliationId(12), extent_id: ExtentId(2), client_id: ClientId(0), flush_number: 1503, gen_number: 33 }, state: ClientData([New, New, New]) }, ReconcileIO { id: ReconciliationId(13), op: ExtentClose { repair_id: ReconciliationId(13), extent_id: ExtentId(2) }, state: ClientData([New, New, New]) }, ReconcileIO { id: ReconciliationId(14), op: ExtentRepair { repair_id: ReconciliationId(14), extent_id: ExtentId(2), source_client_id: ClientId(0), source_repair_address: 0.0.0.0:12810, dest_clients: [ClientId(2)] }, state: ClientData([New, New, New]) }, ReconcileIO { id: ReconciliationId(15), op: ExtentReopen { repair_id: ReconciliationId(15), extent_id: ExtentId(2) }, state: ClientData([New, New, New]) }, ReconcileIO { id: ReconciliationId(16), op: ExtentFlush { repair_id: ReconciliationId(16), extent_id: ExtentId(0), client_id: ClientId(0), flush_number: 1503, gen_number: 33 }, state: ClientData([New, New, New]) }, ReconcileIO { id: ReconciliationId(17), op: ExtentClose { repair_id: ReconciliationId(17), extent_id: ExtentId(0) }, state: ClientData([New, New, New]) }, ReconcileIO { id: ReconciliationId(18), op: ExtentRepair { repair_id: ReconciliationId(18), extent_id: ExtentId(0), source_client_id: ClientId(0), source_repair_address: 0.0.0.0:12810, dest_clients: [ClientId(2)] }, state: ClientData([New, New, New]) }, ReconcileIO { id: ReconciliationId(19), op: ExtentReopen { repair_id: ReconciliationId(19), extent_id: ExtentId(0) }, state: ClientData([New, New, New]) }]","v":0,"name":"crucible","level":30,"time":"2024-12-11T23:44:07.107270295Z","hostname":"w-01JEW1EECADXAJNR7ZZ07QNGFT","pid":1237,"":"downstairs","":"downstairs","session_id":"b6f65ebb-1abc-415a-a7c2-08666dd18f12"}
4642024-12-11T23:44:08.020Z{"msg":"starting reconciliation 6b2a3d1d-52c8-42d2-a956-2503e655360e: found 20 extents that need repair","v":0,"name":"crucible","level":30,"time":"2024-12-11T23:44:07.107289741Z","hostname":"w-01JEW1EECADXAJNR7ZZ07QNGFT","pid":1237,"":"downstairs","":"downstairs","session_id":"b6f65ebb-1abc-415a-a7c2-08666dd18f12"}
4652024-12-11T23:44:08.021Z{"msg":"sending reconcile request ReconciliationId(2)","v":0,"name":"crucible","level":30,"time":"2024-12-11T23:44:07.107303579Z","hostname":"w-01JEW1EECADXAJNR7ZZ07QNGFT","pid":1237,"client":"2","":"downstairs","session_id":"b6f65ebb-1abc-415a-a7c2-08666dd18f12"}
4662024-12-11T23:44:08.025Z{"msg":"sending reconcile request ReconciliationId(6)","v":0,"name":"crucible","level":30,"time":"2024-12-11T23:44:07.11914736Z","hostname":"w-01JEW1EECADXAJNR7ZZ07QNGFT","pid":1237,"client":"2","":"downstairs","session_id":"b6f65ebb-1abc-415a-a7c2-08666dd18f12"}
4672024-12-11T23:44:08.029Z{"msg":"sending reconcile request ReconciliationId(10)","v":0,"name":"crucible","level":30,"time":"2024-12-11T23:44:07.12285138Z","hostname":"w-01JEW1EECADXAJNR7ZZ07QNGFT","pid":1237,"client":"2","":"downstairs","session_id":"b6f65ebb-1abc-415a-a7c2-08666dd18f12"}
4682024-12-11T23:44:08.034Z{"msg":"sending reconcile request ReconciliationId(14)","v":0,"name":"crucible","level":30,"time":"2024-12-11T23:44:07.126708463Z","hostname":"w-01JEW1EECADXAJNR7ZZ07QNGFT","pid":1237,"client":"2","":"downstairs","session_id":"b6f65ebb-1abc-415a-a7c2-08666dd18f12"}
4692024-12-11T23:44:08.037Z{"msg":"sending reconcile request ReconciliationId(18)","v":0,"name":"crucible","level":30,"time":"2024-12-11T23:44:07.130375559Z","hostname":"w-01JEW1EECADXAJNR7ZZ07QNGFT","pid":1237,"client":"2","":"downstairs","session_id":"b6f65ebb-1abc-415a-a7c2-08666dd18f12"}
4702024-12-11T23:44:08.040Z{"msg":"done with reconciliation","v":0,"name":"crucible","level":30,"time":"2024-12-11T23:44:07.133391469Z","hostname":"w-01JEW1EECADXAJNR7ZZ07QNGFT","pid":1237,"":"downstairs","":"downstairs","session_id":"b6f65ebb-1abc-415a-a7c2-08666dd18f12"}
4712024-12-11T23:44:08.040Z{"msg":"Transition from Reconcile to Active","v":0,"name":"crucible","level":30,"time":"2024-12-11T23:44:07.133430722Z","hostname":"w-01JEW1EECADXAJNR7ZZ07QNGFT","pid":1237,"client":"0","":"downstairs","session_id":"b6f65ebb-1abc-415a-a7c2-08666dd18f12"}
4722024-12-11T23:44:08.040Z{"msg":"Transition from Reconcile to Active","v":0,"name":"crucible","level":30,"time":"2024-12-11T23:44:07.13344807Z","hostname":"w-01JEW1EECADXAJNR7ZZ07QNGFT","pid":1237,"client":"1","":"downstairs","session_id":"b6f65ebb-1abc-415a-a7c2-08666dd18f12"}
4732024-12-11T23:44:08.040Z{"msg":"Transition from Reconcile to Active","v":0,"name":"crucible","level":30,"time":"2024-12-11T23:44:07.133470276Z","hostname":"w-01JEW1EECADXAJNR7ZZ07QNGFT","pid":1237,"client":"2","":"downstairs","session_id":"b6f65ebb-1abc-415a-a7c2-08666dd18f12"}
4742024-12-11T23:44:08.040Z{"msg":"All required reconciliation work is completed","v":0,"name":"crucible","level":30,"time":"2024-12-11T23:44:07.133507579Z","hostname":"w-01JEW1EECADXAJNR7ZZ07QNGFT","pid":1237,"session_id":"b6f65ebb-1abc-415a-a7c2-08666dd18f12"}
4752024-12-11T23:44:08.040Z{"msg":"Set Downstairs and Upstairs active after reconciliation"Wait for a query_work_queue command to finish before sending IO
4762024-12-11T23:44:08.040Z,"v":0,"name":"crucible","level":30,"time":"2024-12-11T23:44:07.133538224Z","hostname":"w-01JEW1EECADXAJNR7ZZ07QNGFT","pid":1237,"session_id":"b6f65ebb-1abc-415a-a7c2-08666dd18f12"}
4772024-12-11T23:44:08.040Z{"msg":"29eb25b9-5b95-4919-8c9d-b5b737ba66b9 is now active with session: b6f65ebb-1abc-415a-a7c2-08666dd18f12","v":0,"name":"crucible","level":30,"time":"2024-12-11T23:44:07.133553701Z","hostname":"w-01JEW1EECADXAJNR7ZZ07QNGFT","pid":1237,"session_id":"b6f65ebb-1abc-415a-a7c2-08666dd18f12"}
4782024-12-11T23:44:08.040Z{"msg":"The guest has finished waiting for activation with:33","v":0,"name":"crucible","level":30,"time":"2024-12-11T23:44:07.133575737Z","hostname":"w-01JEW1EECADXAJNR7ZZ07QNGFT","pid":1237}
4792024-12-11T23:44:08.043ZDisk: sv:1 bs:4096 ts:204800 tb:50 max_io:50 or 204800
4802024-12-11T23:44:08.043ZLoading write count information from file "/var/tmp/test_up-build/verify_file"
4812024-12-11T23:44:08.043ZRead and Verify all blocks (0..50 range:true)
4822024-12-11T23:44:08.080ZWrote out file "/var/tmp/test_up-build/verify_file"
4832024-12-11T23:44:08.080ZVerify test completed
4842024-12-11T23:44:08.083ZWrote out file "/var/tmp/test_up-build/verify_file"
4852024-12-11T23:44:08.083ZCLIENT: Tests done. All submitted work has been ACK'd
4862024-12-11T23:44:08.083Z----------------------------------------------------------------
4872024-12-11T23:44:08.083Z Crucible gen:33 GIO:true work queues: Upstairs:0 downstairs:1
4882024-12-11T23:44:08.083ZStates: Active Active Active
4892024-12-11T23:44:08.083ZJOBID ACK TYPE BKS/EXT DS:0 DS:1 DS:2 REPLAY
4902024-12-11T23:44:08.083Z 1000 Acked Read 50 Done Done Done false
4912024-12-11T23:44:08.083Z STATES DS:0 DS:1 DS:2 TOTAL
4922024-12-11T23:44:08.083Z Sent 0 0 0 0
4932024-12-11T23:44:08.083Z Done 1 1 1 3
4942024-12-11T23:44:08.083Z Skipped 0 0 0 0
4952024-12-11T23:44:08.083Z Error 0 0 0 0
4962024-12-11T23:44:08.083ZLast Flush: 0 0 0
4972024-12-11T23:44:08.083ZDownstairs last five completed:
4982024-12-11T23:44:08.083ZUpstairs last five completed: 1000
4992024-12-11T23:44:08.083ZCLIENT: Up:0 ds:1 act:3
5002024-12-11T23:44:12.083Z----------------------------------------------------------------
5012024-12-11T23:44:12.083Z Crucible gen:33 GIO:true work queues: Upstairs:0 downstairs:0
5022024-12-11T23:44:12.083ZDownstairs last five completed: 1001 1000
5032024-12-11T23:44:12.083ZUpstairs last five completed: 1001 1000
5042024-12-11T23:44:12.083ZCLIENT: Up:0 ds:0 act:3
5052024-12-11T23:44:12.083ZCLIENT: All crucible jobs finished, exiting program
5062024-12-11T23:44:12.087Z{"msg":"Guest handle has been dropped","v":0,"name":"crucible","level":40,"time":"2024-12-11T23:44:11.176008395Z","hostname":"w-01JEW1EECADXAJNR7ZZ07QNGFT","pid":1237}
5072024-12-11T23:44:12.089ZRepair part 2 passed
5082024-12-11T23:44:12.092Z/var/tmp/bins/crucible-downstairs dump --no-color -d /var/tmp/test_up-build/8810 -d /var/tmp/test_up-build/8820 -d /var/tmp/test_up-build/8830
5092024-12-11T23:44:12.106ZEXT BLOCKS GEN0 GEN1 GEN2 FL0 FL1 FL2 D0 D1 D2 DIFF
5102024-12-11T23:44:12.106Z 0 000-009 32 32 32 1502 1502 1502 F F F
5112024-12-11T23:44:12.109Z 1 010-019 32 32 32 1502 1502 1502 F F F
5122024-12-11T23:44:12.109Z 2 020-029 32 32 32 1502 1502 1502 F F F
5132024-12-11T23:44:12.109Z 3 030-039 32 32 32 1502 1502 1502 F F F
5142024-12-11T23:44:12.109Z 4 040-049 32 32 32 1502 1502 1502 F F F
5152024-12-11T23:44:12.109ZMax gen: 32, Max flush: 1502
5162024-12-11T23:44:12.112Zdump test passed
5172024-12-11T23:44:12.112Z/var/tmp/bins/crucible-downstairs dump --no-color -d /var/tmp/test_up-build/8810 -d /var/tmp/test_up-build/8820 -d /var/tmp/test_up-build/8830 -e 1
5182024-12-11T23:44:12.126Z Extent 1
5192024-12-11T23:44:12.126ZGEN 32 32 32
5202024-12-11T23:44:12.126ZFLUSH_ID 1502 1502 1502
5212024-12-11T23:44:12.126ZDIRTY
5222024-12-11T23:44:12.126Z
5232024-12-11T23:44:12.126ZBLOCK D0 D1 D2 C0 C1 C2 DIFF
5242024-12-11T23:44:12.128Z010 A A A A A A
5252024-12-11T23:44:12.131Z011 A A A A A A
5262024-12-11T23:44:12.131Z012 A A A A A A
5272024-12-11T23:44:12.134Z013 A A A A A A
5282024-12-11T23:44:12.134Z014 A A A A A A
5292024-12-11T23:44:12.136Z015 A A A A A A
5302024-12-11T23:44:12.136Z016 A A A A A A
5312024-12-11T23:44:12.136Z017 A A A A A A
5322024-12-11T23:44:12.139Z018 A A A A A A
5332024-12-11T23:44:12.139Z019 A A A A A A
5342024-12-11T23:44:12.143Zdump extent test passed
5352024-12-11T23:44:12.146Z/var/tmp/bins/crucible-downstairs dump --no-color -d /var/tmp/test_up-build/8810 -d /var/tmp/test_up-build/8820 -d /var/tmp/test_up-build/8830 -b 20
5362024-12-11T23:44:12.160ZExtent 2 Block in extent 0 Actual block 20
5372024-12-11T23:44:12.160Z
5382024-12-11T23:44:12.163Z DATA SHA256 VER
5392024-12-11T23:44:12.163Z------ ---------------------------------------------------------------- ---
5402024-12-11T23:44:12.163Z 0 0a14f0ae5d10b3fdab60e20b5b44cf51a3868f85873cac09e3407c30d0fa1c3b A
5412024-12-11T23:44:12.163Z 1 0a14f0ae5d10b3fdab60e20b5b44cf51a3868f85873cac09e3407c30d0fa1c3b A
5422024-12-11T23:44:12.165Z 2 0a14f0ae5d10b3fdab60e20b5b44cf51a3868f85873cac09e3407c30d0fa1c3b A
5432024-12-11T23:44:12.165Z
5442024-12-11T23:44:12.166ZNONCES 0 1 2 DIFF
5452024-12-11T23:44:12.166Z------ ------------------------ ------------------------ ------------------------ -----
5462024-12-11T23:44:12.166Z 0 a2579cae42a1db896c02c452 a2579cae42a1db896c02c452 a2579cae42a1db896c02c452
5472024-12-11T23:44:12.166Z
5482024-12-11T23:44:12.166Z TAGS 0 1 2 DIFF
5492024-12-11T23:44:12.166Z------ -------------------------------- -------------------------------- -------------------------------- -----
5502024-12-11T23:44:12.166Z 0 d52d8edb211f8885db4d63faa09fc81d d52d8edb211f8885db4d63faa09fc81d d52d8edb211f8885db4d63faa09fc81d
5512024-12-11T23:44:12.166Z
5522024-12-11T23:44:12.166ZHASHES 0 1 2 DIFF
5532024-12-11T23:44:12.166Z------ ---------------- ---------------- ---------------- -----
5542024-12-11T23:44:12.166Z
5552024-12-11T23:44:12.169Zdump block test passed
5562024-12-11T23:44:12.169ZInitial upstairs tests have completed, stopping all downstairs
5572024-12-11T23:44:17.231ZCreating 4 larger downstairs regions
5582024-12-11T23:44:17.342ZStarting 4 downstairs
5592024-12-11T23:44:22.350Zdsc restarted at PID: 1250
5602024-12-11T23:44:22.579ZNow do the replace-reconcile test
5612024-12-11T23:44:22.638ZUsing 8840 for the replacement port
5622024-12-11T23:47:48.427ZCompleted test: replace-reconcile
5632024-12-11T23:47:48.430ZNow do the replace-before-active test
5642024-12-11T23:50:54.889ZCompleted test: replace-before-active
5652024-12-11T23:50:54.891ZAll tests have completed, stopping all downstairs
5662024-12-11T23:50:54.947Z
5672024-12-11T23:50:54.947ZAll Tests have passed
5682024-12-11T23:50:54.949Z10:25 Test duration
5692024-12-11T23:50:54.949Z
5702024-12-11T23:50:54.949Zreal 10:25.218800752
5712024-12-11T23:50:54.949Zuser 6:25.156737620
5722024-12-11T23:50:54.949Zsys 12.334061349
5732024-12-11T23:50:54.949Ztrap 0.210566991
5742024-12-11T23:50:54.949Ztflt 0.010261867
5752024-12-11T23:50:54.950Zdflt 0.070283188
5762024-12-11T23:50:54.950Zkflt 0.001157024
5772024-12-11T23:50:54.950Zlock 8:38:23.865415015
5782024-12-11T23:50:54.950Zslp 34:59.560871882
5792024-12-11T23:50:54.950Zlat 23.384471986
5802024-12-11T23:50:54.950Zstop 0.126966107
5812024-12-11T23:50:54.950Z+ echo 'test-up-encrypted ends'
5822024-12-11T23:50:54.950Ztest-up-encrypted ends
5832024-12-11T23:50:59.952Zprocess exited: duration 633401 ms, exit code 0
5842024-12-11T23:50:59.953Zexec warning: : stdio descriptors remain open after task exit; waiting 60 seconds for them to close
5852024-12-11T23:51:59.991Zexec warning: : stdout descriptor may be held open by a background process; giving up!
5862024-12-11T23:51:59.991Zexec warning: : stderr descriptor may be held open by a background process; giving up!
 
5872024-12-11T23:52:00.001Zfound 14 output files
5882024-12-11T23:52:00.001Zuploading: /tmp/test_up-build/dsc-out.txt (43744 bytes)
5892024-12-11T23:52:01.014Zuploaded: /tmp/test_up-build/dsc-out.txt
5902024-12-11T23:52:01.023Zuploading: /tmp/test_up-build/test_up_out.txt (9846804 bytes)
5912024-12-11T23:52:02.141Zuploaded: /tmp/test_up-build/test_up_out.txt
5922024-12-11T23:52:02.143Zuploading: /tmp/test_up-build/dsc/downstairs-8810.txt (2505 bytes)
5932024-12-11T23:52:03.149Zuploaded: /tmp/test_up-build/dsc/downstairs-8810.txt
5942024-12-11T23:52:03.152Zuploading: /tmp/test_up-build/dsc/downstairs-8820.txt (144654 bytes)
5952024-12-11T23:52:04.162Zuploaded: /tmp/test_up-build/dsc/downstairs-8820.txt
5962024-12-11T23:52:04.165Zuploading: /tmp/test_up-build/dsc/downstairs-8830.txt (251110 bytes)
5972024-12-11T23:52:05.177Zuploaded: /tmp/test_up-build/dsc/downstairs-8830.txt
5982024-12-11T23:52:05.179Zuploading: /tmp/test_up-build/dsc/downstairs-8840.txt (139431 bytes)
5992024-12-11T23:52:06.189Zuploaded: /tmp/test_up-build/dsc/downstairs-8840.txt
6002024-12-11T23:52:06.192Zuploading: /tmp/debug/df.txt (1270 bytes)
6012024-12-11T23:52:07.199Zuploaded: /tmp/debug/df.txt
6022024-12-11T23:52:07.202Zuploading: /tmp/debug/dtrace.txt (562106 bytes)
6032024-12-11T23:52:08.217Zuploaded: /tmp/debug/dtrace.txt
6042024-12-11T23:52:08.217Zuploading: /tmp/debug/iostat.txt (208038 bytes)
6052024-12-11T23:52:08.226Zupload warning: file "/tmp/debug/iostat.txt" changed size mid upload: 208038 -> 210446
6062024-12-11T23:52:09.232Zuploaded: /tmp/debug/iostat.txt
6072024-12-11T23:52:09.234Zuploading: /tmp/debug/mpstat.txt (504435 bytes)
6082024-12-11T23:52:09.244Zupload warning: file "/tmp/debug/mpstat.txt" changed size mid upload: 504435 -> 511005
6092024-12-11T23:52:10.251Zuploaded: /tmp/debug/mpstat.txt
6102024-12-11T23:52:10.254Zuploading: /tmp/debug/paging.txt (91216 bytes)
6112024-12-11T23:52:10.259Zupload warning: file "/tmp/debug/paging.txt" changed size mid upload: 91216 -> 92534
6122024-12-11T23:52:11.265Zuploaded: /tmp/debug/paging.txt
6132024-12-11T23:52:11.268Zuploading: /tmp/debug/prstat.txt (965570 bytes)
6142024-12-11T23:52:11.283Zupload warning: file "/tmp/debug/prstat.txt" changed size mid upload: 965570 -> 981086
6152024-12-11T23:52:12.289Zuploaded: /tmp/debug/prstat.txt
6162024-12-11T23:52:12.291Zuploading: /tmp/debug/psrinfo.txt (1528 bytes)
6172024-12-11T23:52:13.297Zuploaded: /tmp/debug/psrinfo.txt
6182024-12-11T23:52:13.297Zuploading: /tmp/debug/upstairs-info.txt (99864 bytes)
6192024-12-11T23:52:14.309Zuploaded: /tmp/debug/upstairs-info.txt