01JPN21HNASV4ZFC094G60264J: test-up-2region-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: 01JPN21Z1MNF3QF0B4XRWHY16B

Tags:

Artefacts:

Output:

SEQ GLOBAL TIME DETAILS
12025-03-18T16:40:43.377Zjob dependencies complete; ready to run (waiting for 0 s)
22025-03-18T16:41:37.634Zjob assigned to worker 01JPN225S828YGR17Y0NASFSKX [factory aws, i-0a78345b073566dd2] (queued for 54 s)
32025-03-18T16:41:46.019Zdownloading input: /input/build/work/bins/crucible-downstairs.gz
42025-03-18T16:41:47.631Zdownloaded input: /input/build/work/bins/crucible-downstairs.gz
52025-03-18T16:41:47.632Zdownloading input: /input/build/work/bins/crucible-hammer.gz
62025-03-18T16:41:49.469Zdownloaded input: /input/build/work/bins/crucible-hammer.gz
72025-03-18T16:41:49.469Zdownloading input: /input/build/work/bins/crutest.gz
82025-03-18T16:41:50.901Zdownloaded input: /input/build/work/bins/crutest.gz
92025-03-18T16:41:50.901Zdownloading input: /input/build/work/bins/dsc.gz
102025-03-18T16:41:52.017Zdownloaded input: /input/build/work/bins/dsc.gz
112025-03-18T16:41:52.021Zdownloading input: /input/build/work/scripts/perf-downstairs-tick.d
122025-03-18T16:41:52.050Zdownloaded input: /input/build/work/scripts/perf-downstairs-tick.d
132025-03-18T16:41:52.050Zdownloading input: /input/build/work/scripts/test_ds.sh
142025-03-18T16:41:52.096Zdownloaded input: /input/build/work/scripts/test_ds.sh
152025-03-18T16:41:52.096Zdownloading input: /input/build/work/scripts/test_live_repair.sh
162025-03-18T16:41:52.155Zdownloaded input: /input/build/work/scripts/test_live_repair.sh
172025-03-18T16:41:52.155Zdownloading input: /input/build/work/scripts/test_repair.sh
182025-03-18T16:41:52.248Zdownloaded input: /input/build/work/scripts/test_repair.sh
192025-03-18T16:41:52.248Zdownloading input: /input/build/work/scripts/test_replay.sh
202025-03-18T16:41:52.289Zdownloaded input: /input/build/work/scripts/test_replay.sh
212025-03-18T16:41:52.289Zdownloading input: /input/build/work/scripts/test_up.sh
222025-03-18T16:41:52.306Zdownloaded input: /input/build/work/scripts/test_up.sh
232025-03-18T16:41:52.306Zdownloading input: /input/build/work/scripts/upstairs_info.d
242025-03-18T16:41:52.334Zdownloaded input: /input/build/work/scripts/upstairs_info.d
252025-03-18T16:41:52.337Zdownloading input: /input/build/tmp/cargo-test-out.log
262025-03-18T16:41:53.316Zdownloaded input: /input/build/tmp/cargo-test-out.log
 
272025-03-18T16:41:53.316Zstarting task 0: "setup"
282025-03-18T16:41:53.320Z++ uname -s
292025-03-18T16:41:53.323Z+ kern=SunOS
302025-03-18T16:41:53.323Z+ build_user=build
312025-03-18T16:41:53.324Z+ build_uid=12345
322025-03-18T16:41:53.324Z+ work_dir=/work
332025-03-18T16:41:53.324Z+ input_dir=/input
342025-03-18T16:41:53.324Z+ [[ 0 == 12345 ]]
352025-03-18T16:41:53.324Z+ case "$kern" in
362025-03-18T16:41:53.324Z+ groupadd -g 12345 build
372025-03-18T16:41:53.327Z+ useradd -u 12345 -g build -d /home/build -s /bin/bash -c build -P 'Primary Administrator' build
382025-03-18T16:41:55.333Z+ zfs create -o mountpoint=/work rpool/work
392025-03-18T16:41:55.650Z++ awk '$2 == "/home" { print $3 }' /etc/mnttab
402025-03-18T16:41:55.653Z+ home_fs=zfs
412025-03-18T16:41:55.653Z+ [[ zfs == autofs ]]
422025-03-18T16:41:55.653Z+ mkdir -p /home/build
432025-03-18T16:41:55.657Z+ chown build:build /home/build /work
442025-03-18T16:41:57.657Z+ chmod 0700 /home/build /work
452025-03-18T16:41:57.661Zprocess exited: duration 4346 ms, exit code 0
 
462025-03-18T16:41:57.670Zstarting task 1: "authentication"
472025-03-18T16:41:57.686Zprocess exited: duration 18 ms, exit code 0
 
482025-03-18T16:41:57.694Zstarting task 2: "build"
492025-03-18T16:41:57.698Z+ banner cores
502025-03-18T16:41:57.702Z
512025-03-18T16:41:57.702Z #### #### ##### ###### ####
522025-03-18T16:41:57.702Z # # # # # # # #
532025-03-18T16:41:57.702Z # # # # # ##### ####
542025-03-18T16:41:57.702Z # # # ##### # #
552025-03-18T16:41:57.702Z # # # # # # # # #
562025-03-18T16:41:57.702Z #### #### # # ###### ####
572025-03-18T16:41:57.702Z
582025-03-18T16:41:57.702Z+ pfexec coreadm -i /tmp/core.%f.%p -g /tmp/core.%f.%p -e global -e log -e proc-setid -e global-setid
592025-03-18T16:41:57.710Z+ banner unpack
602025-03-18T16:41:57.715Z
612025-03-18T16:41:57.715Z # # # # ##### ## #### # #
622025-03-18T16:41:57.715Z # # ## # # # # # # # # #
632025-03-18T16:41:57.715Z # # # # # # # # # # ####
642025-03-18T16:41:57.715Z # # # # # ##### ###### # # #
652025-03-18T16:41:57.715Z # # # ## # # # # # # #
662025-03-18T16:41:57.715Z #### # # # # # #### # #
672025-03-18T16:41:57.715Z
682025-03-18T16:41:57.715Z+ mkdir -p /var/tmp/bins
692025-03-18T16:41:57.719Z+ for t in "$input/bins/"*.gz
702025-03-18T16:41:57.719Z++ basename /input/build/work/bins/crucible-downstairs.gz
712025-03-18T16:41:57.719Z+ b=crucible-downstairs.gz
722025-03-18T16:41:57.719Z+ b=crucible-downstairs
732025-03-18T16:41:57.719Z+ gunzip
742025-03-18T16:42:00.182Z+ chmod +x /var/tmp/bins/crucible-downstairs
752025-03-18T16:42:00.185Z+ for t in "$input/bins/"*.gz
762025-03-18T16:42:00.186Z++ basename /input/build/work/bins/crucible-hammer.gz
772025-03-18T16:42:00.189Z+ b=crucible-hammer.gz
782025-03-18T16:42:00.189Z+ b=crucible-hammer
792025-03-18T16:42:00.189Z+ gunzip
802025-03-18T16:42:02.377Z+ chmod +x /var/tmp/bins/crucible-hammer
812025-03-18T16:42:02.381Z+ for t in "$input/bins/"*.gz
822025-03-18T16:42:02.381Z++ basename /input/build/work/bins/crutest.gz
832025-03-18T16:42:02.384Z+ b=crutest.gz
842025-03-18T16:42:02.384Z+ b=crutest
852025-03-18T16:42:02.384Z+ gunzip
862025-03-18T16:42:04.818Z+ chmod +x /var/tmp/bins/crutest
872025-03-18T16:42:04.821Z+ for t in "$input/bins/"*.gz
882025-03-18T16:42:04.821Z++ basename /input/build/work/bins/dsc.gz
892025-03-18T16:42:04.821Z+ b=dsc.gz
902025-03-18T16:42:04.821Z+ b=dsc
912025-03-18T16:42:04.821Z+ gunzip
922025-03-18T16:42:06.152Z+ chmod +x /var/tmp/bins/dsc
932025-03-18T16:42:06.156Z+ export BINDIR=/var/tmp/bins
942025-03-18T16:42:06.156Z+ BINDIR=/var/tmp/bins
952025-03-18T16:42:06.156Z+ jobpid=1145
962025-03-18T16:42:06.156Z+ echo 'Setup debug logging'
972025-03-18T16:42:06.159ZSetup debug logging
982025-03-18T16:42:06.159Z+ mkdir /tmp/debug
992025-03-18T16:42:06.159Z+ sleep 3600
1002025-03-18T16:42:06.159Z+ psrinfo -v
1012025-03-18T16:42:06.162Z+ df -h
1022025-03-18T16:42:06.168Z+ prstat -d d -mLc 1
1032025-03-18T16:42:06.172Z+ iostat -T d -xn 1
1042025-03-18T16:42:06.172Z+ mpstat -T d 1
1052025-03-18T16:42:06.172Z+ vmstat -T d -p 1
1062025-03-18T16:42:06.172Z+ pfexec dtrace -Z -s /input/build/work/scripts/perf-downstairs-tick.d
1072025-03-18T16:42:06.175Z+ banner test_up_2r_encrypted
1082025-03-18T16:42:06.175Z+ pfexec dtrace -Z -s /input/build/work/scripts/upstairs_info.d
1092025-03-18T16:42:06.175Z #####
1102025-03-18T16:42:06.175Z ##### ###### #### ##### # # ##### # # #####
1112025-03-18T16:42:06.175Z # # # # # # # # # # #
1122025-03-18T16:42:06.175Z # ##### #### # # # # # ##### # #
1132025-03-18T16:42:06.175Z # # # # # # ##### # #####
1142025-03-18T16:42:06.175Z # # # # # # # # # # #
1152025-03-18T16:42:06.175Z # ###### #### # ####### #### # ####### ####### # #
1162025-03-18T16:42:06.175Z
1172025-03-18T16:42:06.175Z+ ptime -m bash /input/build/work/scripts/test_up.sh -r 2 -N encrypted
1182025-03-18T16:42:06.185Z/input/build/work
1192025-03-18T16:42:06.197ZUsing 2 region sets
1202025-03-18T16:42:06.197ZTurn off color for downstairs dump
1212025-03-18T16:42:06.212ZUpstairs using key: B3P3gZ9tJ5vWD72EjbZTFM1kuPb0n3pWl29LAKfzNeo=
1222025-03-18T16:42:06.216Zdsc output goes to /tmp/test_up-build/dsc-out.txt
1232025-03-18T16:42:06.216ZCreating 6 downstairs regions
1242025-03-18T16:42:06.571ZStarting 6 downstairs
1252025-03-18T16:42:06.574Zdsc started at PID: 1193
1262025-03-18T16:42:11.899ZDisable automatic restart on all downstairs
1272025-03-18T16:42:11.950Z
1282025-03-18T16:42:11.950ZBegin tests, output goes to /tmp/test_up-build/test_up_out.txt
1292025-03-18T16:42:11.954ZRunning test: span
1302025-03-18T16:42:16.128ZCompleted test: span
1312025-03-18T16:42:21.134ZRunning test: big
1322025-03-18T16:42:25.732ZCompleted test: big
1332025-03-18T16:42:30.737ZRunning test: dep
1342025-03-18T16:43:04.390ZCompleted test: dep
1352025-03-18T16:43:09.397ZRunning test: balloon
1362025-03-18T16:47:25.361ZCompleted test: balloon
1372025-03-18T16:47:30.369ZRunning test: deactivate
1382025-03-18T16:48:25.043ZCompleted test: deactivate
1392025-03-18T16:48:30.051ZRunning hammer
1402025-03-18T16:48:47.682ZRun repair tests
1412025-03-18T16:48:47.685Z/var/tmp/bins/crutest fill -g 31 -q --key B3P3gZ9tJ5vWD72EjbZTFM1kuPb0n3pWl29LAKfzNeo= --dsc 127.0.0.1:9998 --verify-out /var/tmp/test_up-build/verify_file
1422025-03-18T16:48:47.743Z{"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":"2025-03-18T16:48:47.53220817Z","hostname":"w-01JPN225S828YGR17Y0NASFSKX","pid":1236,"task":"crutest"}
1432025-03-18T16:48:47.747Z{"msg":"dsc has 6 regions. This means 2 sub_volumes","v":0,"name":"crucible","level":30,"time":"2025-03-18T16:48:47.53274661Z","hostname":"w-01JPN225S828YGR17Y0NASFSKX","pid":1236,"task":"crutest"}
1442025-03-18T16:48:47.747Z{"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":"2025-03-18T16:48:47.534493143Z","hostname":"w-01JPN225S828YGR17Y0NASFSKX","pid":1236,"task":"crutest"}
1452025-03-18T16:48:47.747Z{"msg":"Upstairs starts","v":0,"name":"crucible","level":30,"time":"2025-03-18T16:48:47.534733717Z","hostname":"w-01JPN225S828YGR17Y0NASFSKX","pid":1236}
1462025-03-18T16:48:47.747Z{"msg":"Crucible Version: BuildInfo {\n version: \"0.0.1\",\n git_sha: \"e56b83235918dca6f00b1bca17876ae8794868bc\",\n git_commit_timestamp: \"2025-03-18T04:42:45.000000000Z\",\n git_branch: \"renovate/chrono-0.x-lockfile\",\n rustc_semver: \"1.84.0\",\n rustc_channel: \"stable\",\n rustc_host_triple: \"x86_64-unknown-illumos\",\n rustc_commit_sha: \"9fc6b43126469e3858e2fe86cafb4f0fd5068869\",\n cargo_triple: \"x86_64-unknown-illumos\",\n debug: true,\n opt_level: 0,\n}","v":0,"name":"crucible","level":30,"time":"2025-03-18T16:48:47.53478082Z","hostname":"w-01JPN225S828YGR17Y0NASFSKX","pid":1236}
1472025-03-18T16:48:47.747Z{"msg":"Upstairs <-> Downstairs Message Version: 13","v":0,"name":"crucible","level":30,"time":"2025-03-18T16:48:47.534804297Z","hostname":"w-01JPN225S828YGR17Y0NASFSKX","pid":1236}
1482025-03-18T16:48:47.747Z{"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":"2025-03-18T16:48:47.534819914Z","hostname":"w-01JPN225S828YGR17Y0NASFSKX","pid":1236}
1492025-03-18T16:48:47.747Z{"msg":"Crucible d866bfa1-7609-43f8-85d1-205bc133f7bd has session id: b3893b18-3ca5-4923-87ae-161c6ed9acbd","v":0,"name":"crucible","level":30,"time":"2025-03-18T16:48:47.535280186Z","hostname":"w-01JPN225S828YGR17Y0NASFSKX","pid":1236,"session_id":"b3893b18-3ca5-4923-87ae-161c6ed9acbd"}
1502025-03-18T16:48:47.747Z{"msg":"Upstairs opts: Upstairs UUID: d866bfa1-7609-43f8-85d1-205bc133f7bd, 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":"2025-03-18T16:48:47.5353259Z","hostname":"w-01JPN225S828YGR17Y0NASFSKX","pid":1236,"session_id":"b3893b18-3ca5-4923-87ae-161c6ed9acbd"}
1512025-03-18T16:48:47.747Z{"msg":"Crucible stats registered with UUID: d866bfa1-7609-43f8-85d1-205bc133f7bd","v":0,"name":"crucible","level":30,"time":"2025-03-18T16:48:47.535360115Z","hostname":"w-01JPN225S828YGR17Y0NASFSKX","pid":1236,"session_id":"b3893b18-3ca5-4923-87ae-161c6ed9acbd"}
1522025-03-18T16:48:47.747Z{"msg":"could not find Downstairs address for Nexus","v":0,"name":"crucible","level":40,"time":"2025-03-18T16:48:47.535383181Z","hostname":"w-01JPN225S828YGR17Y0NASFSKX","pid":1236,"session_id":"b3893b18-3ca5-4923-87ae-161c6ed9acbd"}
1532025-03-18T16:48:47.751Z{"msg":"SV 1 has targets: [127.0.0.1:8840, 127.0.0.1:8850, 127.0.0.1:8860]","v":0,"name":"crucible","level":30,"time":"2025-03-18T16:48:47.537365279Z","hostname":"w-01JPN225S828YGR17Y0NASFSKX","pid":1236,"task":"crutest"}
1542025-03-18T16:48:47.751Z{"msg":"Upstairs starts","v":0,"name":"crucible","level":30,"time":"2025-03-18T16:48:47.537442757Z","hostname":"w-01JPN225S828YGR17Y0NASFSKX","pid":1236}
1552025-03-18T16:48:47.751Z{"msg":"Crucible Version: BuildInfo {\n version: \"0.0.1\",\n git_sha: \"e56b83235918dca6f00b1bca17876ae8794868bc\",\n git_commit_timestamp: \"2025-03-18T04:42:45.000000000Z\",\n git_branch: \"renovate/chrono-0.x-lockfile\",\n rustc_semver: \"1.84.0\",\n rustc_channel: \"stable\",\n rustc_host_triple: \"x86_64-unknown-illumos\",\n rustc_commit_sha: \"9fc6b43126469e3858e2fe86cafb4f0fd5068869\",\n cargo_triple: \"x86_64-unknown-illumos\",\n debug: true,\n opt_level: 0,\n}","v":0,"name":"crucible","level":30,"time":"2025-03-18T16:48:47.537480362Z","hostname":"w-01JPN225S828YGR17Y0NASFSKX","pid":1236}
1562025-03-18T16:48:47.751Z{"msg":"Upstairs <-> Downstairs Message Version: 13","v":0,"name":"crucible","level":30,"time":"2025-03-18T16:48:47.537555751Z","hostname":"w-01JPN225S828YGR17Y0NASFSKX","pid":1236}
1572025-03-18T16:48:47.751Z{"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":"2025-03-18T16:48:47.537601484Z","hostname":"w-01JPN225S828YGR17Y0NASFSKX","pid":1236}
1582025-03-18T16:48:47.751Z{"msg":"Crucible d866bfa1-7609-43f8-85d1-205bc133f7bd has session id: 419b0db9-aede-46e0-9984-ed6137830fe5","v":0,"name":"crucible","level":30,"time":"2025-03-18T16:48:47.537903759Z","hostname":"w-01JPN225S828YGR17Y0NASFSKX","pid":1236,"session_id":"419b0db9-aede-46e0-9984-ed6137830fe5"}
1592025-03-18T16:48:47.751Z{"msg":"Upstairs opts: Upstairs UUID: d866bfa1-7609-43f8-85d1-205bc133f7bd, Targets: [127.0.0.1:8840, 127.0.0.1:8850, 127.0.0.1:8860], 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":"2025-03-18T16:48:47.537974769Z","hostname":"w-01JPN225S828YGR17Y0NASFSKX","pid":1236,"session_id":"419b0db9-aede-46e0-9984-ed6137830fe5"}
1602025-03-18T16:48:47.751Z{"msg":"Crucible stats registered with UUID: d866bfa1-7609-43f8-85d1-205bc133f7bd","v":0,"name":"crucible","level":30,"time":"2025-03-18T16:48:47.538015573Z","hostname":"w-01JPN225S828YGR17Y0NASFSKX","pid":1236,"session_id":"419b0db9-aede-46e0-9984-ed6137830fe5"}
1612025-03-18T16:48:47.751Z{"msg":"could not find Downstairs address for Nexus","v":0,"name":"crucible","level":40,"time":"2025-03-18T16:48:47.538039679Z","hostname":"w-01JPN225S828YGR17Y0NASFSKX","pid":1236,"session_id":"419b0db9-aede-46e0-9984-ed6137830fe5"}
1622025-03-18T16:48:47.751Z{"msg":"Downstairs in volume = 6","v":0,"name":"crucible","level":30,"time":"2025-03-18T16:48:47.538674016Z","hostname":"w-01JPN225S828YGR17Y0NASFSKX","pid":1236,"task":"crutest"}
1632025-03-18T16:48:47.751Z{"msg":"The guest has requested activation with gen:31","v":0,"name":"crucible","level":30,"time":"2025-03-18T16:48:47.538696902Z","hostname":"w-01JPN225S828YGR17Y0NASFSKX","pid":1236}
1642025-03-18T16:48:47.751Z{"msg":"d866bfa1-7609-43f8-85d1-205bc133f7bd active request set","v":0,"name":"crucible","level":30,"time":"2025-03-18T16:48:47.538752704Z","hostname":"w-01JPN225S828YGR17Y0NASFSKX","pid":1236,"session_id":"b3893b18-3ca5-4923-87ae-161c6ed9acbd"}
1652025-03-18T16:48:47.751Z{"msg":"sending connect oneshot to client","v":0,"name":"crucible","level":30,"time":"2025-03-18T16:48:47.53878126Z","hostname":"w-01JPN225S828YGR17Y0NASFSKX","pid":1236,"client":"0","":"downstairs","session_id":"b3893b18-3ca5-4923-87ae-161c6ed9acbd"}
1662025-03-18T16:48:47.751Z{"msg":"client set_active_request while in Connecting { state: Start { auto_promote: true }, mode: New }; waiting...","v":0,"name":"crucible","level":30,"time":"2025-03-18T16:48:47.538828153Z","hostname":"w-01JPN225S828YGR17Y0NASFSKX","pid":1236,"client":"0","":"downstairs","session_id":"b3893b18-3ca5-4923-87ae-161c6ed9acbd"}
1672025-03-18T16:48:47.751Z{"msg":"sending connect oneshot to client","v":0,"name":"crucible","level":30,"time":"2025-03-18T16:48:47.53885021Z","hostname":"w-01JPN225S828YGR17Y0NASFSKX","pid":1236,"client":"1","":"downstairs","session_id":"b3893b18-3ca5-4923-87ae-161c6ed9acbd"}
1682025-03-18T16:48:47.751Z{"msg":"client set_active_request while in Connecting { state: Start { auto_promote: true }, mode: New }; waiting...","v":0,"name":"crucible","level":30,"time":"2025-03-18T16:48:47.538875266Z","hostname":"w-01JPN225S828YGR17Y0NASFSKX","pid":1236,"client":"1","":"downstairs","session_id":"b3893b18-3ca5-4923-87ae-161c6ed9acbd"}
1692025-03-18T16:48:47.751Z{"msg":"sending connect oneshot to client","v":0,"name":"crucible","level":30,"time":"2025-03-18T16:48:47.53891797Z","hostname":"w-01JPN225S828YGR17Y0NASFSKX","pid":1236,"client":"2","":"downstairs","session_id":"b3893b18-3ca5-4923-87ae-161c6ed9acbd"}
1702025-03-18T16:48:47.751Z{"msg":"client set_active_request while in Connecting { state: Start { auto_promote: true }, mode: New }; waiting...","v":0,"name":"crucible","level":30,"time":"2025-03-18T16:48:47.538945626Z","hostname":"w-01JPN225S828YGR17Y0NASFSKX","pid":1236,"client":"2","":"downstairs","session_id":"b3893b18-3ca5-4923-87ae-161c6ed9acbd"}
1712025-03-18T16:48:47.751Z{"msg":"connecting to 127.0.0.1:8830","v":0,"name":"crucible","level":30,"time":"2025-03-18T16:48:47.538978711Z","hostname":"w-01JPN225S828YGR17Y0NASFSKX","pid":1236,"":"io task","client":"2","":"downstairs","session_id":"b3893b18-3ca5-4923-87ae-161c6ed9acbd"}
1722025-03-18T16:48:47.751Z{"msg":"connecting to 127.0.0.1:8810","v":0,"name":"crucible","level":30,"time":"2025-03-18T16:48:47.539038882Z","hostname":"w-01JPN225S828YGR17Y0NASFSKX","pid":1236,"":"io task","client":"0","":"downstairs","session_id":"b3893b18-3ca5-4923-87ae-161c6ed9acbd"}
1732025-03-18T16:48:47.751Z{"msg":"connecting to 127.0.0.1:8820","v":0,"name":"crucible","level":30,"time":"2025-03-18T16:48:47.539074027Z","hostname":"w-01JPN225S828YGR17Y0NASFSKX","pid":1236,"":"io task","client":"1","":"downstairs","session_id":"b3893b18-3ca5-4923-87ae-161c6ed9acbd"}
1742025-03-18T16:48:47.751Z{"msg":"ds_connection connected from Ok(127.0.0.1:34227)","v":0,"name":"crucible","level":30,"time":"2025-03-18T16:48:47.539099643Z","hostname":"w-01JPN225S828YGR17Y0NASFSKX","pid":1236,"":"io task","client":"2","":"downstairs","session_id":"b3893b18-3ca5-4923-87ae-161c6ed9acbd"}
1752025-03-18T16:48:47.751Z{"msg":"ds_connection connected from Ok(127.0.0.1:54465)","v":0,"name":"crucible","level":30,"time":"2025-03-18T16:48:47.539134248Z","hostname":"w-01JPN225S828YGR17Y0NASFSKX","pid":1236,"":"io task","client":"0","":"downstairs","session_id":"b3893b18-3ca5-4923-87ae-161c6ed9acbd"}
1762025-03-18T16:48:47.751Z{"msg":"ds_connection connected from Ok(127.0.0.1:32996)","v":0,"name":"crucible","level":30,"time":"2025-03-18T16:48:47.539284516Z","hostname":"w-01JPN225S828YGR17Y0NASFSKX","pid":1236,"":"io task","client":"1","":"downstairs","session_id":"b3893b18-3ca5-4923-87ae-161c6ed9acbd"}
1772025-03-18T16:48:47.751Z{"msg":"version negotiation from state Connecting { state: WaitForPromote, mode: New }","v":0,"name":"crucible","level":30,"time":"2025-03-18T16:48:47.539742018Z","hostname":"w-01JPN225S828YGR17Y0NASFSKX","pid":1236,"client":"2","":"downstairs","session_id":"b3893b18-3ca5-4923-87ae-161c6ed9acbd"}
1782025-03-18T16:48:47.757Z{"msg":"version negotiation from state Connecting { state: WaitForPromote, mode: New }","v":0,"name":"crucible","level":30,"time":"2025-03-18T16:48:47.539884507Z","hostname":"w-01JPN225S828YGR17Y0NASFSKX","pid":1236,"client":"1","":"downstairs","session_id":"b3893b18-3ca5-4923-87ae-161c6ed9acbd"}
1792025-03-18T16:48:47.757Z{"msg":"version negotiation from state Connecting { state: WaitForPromote, mode: New }","v":0,"name":"crucible","level":30,"time":"2025-03-18T16:48:47.539970444Z","hostname":"w-01JPN225S828YGR17Y0NASFSKX","pid":1236,"client":"0","":"downstairs","session_id":"b3893b18-3ca5-4923-87ae-161c6ed9acbd"}
1802025-03-18T16:48:47.757Z{"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":"2025-03-18T16:48:47.54040637Z","hostname":"w-01JPN225S828YGR17Y0NASFSKX","pid":1236,"client":"2","":"downstairs","session_id":"b3893b18-3ca5-4923-87ae-161c6ed9acbd"}
1812025-03-18T16:48:47.757Z{"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":"2025-03-18T16:48:47.540443535Z","hostname":"w-01JPN225S828YGR17Y0NASFSKX","pid":1236,"client":"1","":"downstairs","session_id":"b3893b18-3ca5-4923-87ae-161c6ed9acbd"}
1822025-03-18T16:48:47.757Z{"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":"2025-03-18T16:48:47.540504226Z","hostname":"w-01JPN225S828YGR17Y0NASFSKX","pid":1236,"client":"0","":"downstairs","session_id":"b3893b18-3ca5-4923-87ae-161c6ed9acbd"}
1832025-03-18T16:48:47.757Z{"msg":"Waiting for more clients to be ready","v":0,"name":"crucible","level":30,"time":"2025-03-18T16:48:47.540866152Z","hostname":"w-01JPN225S828YGR17Y0NASFSKX","pid":1236,"session_id":"b3893b18-3ca5-4923-87ae-161c6ed9acbd"}
1842025-03-18T16:48:47.757Z{"msg":"Waiting for more clients to be ready","v":0,"name":"crucible","level":30,"time":"2025-03-18T16:48:47.540899467Z","hostname":"w-01JPN225S828YGR17Y0NASFSKX","pid":1236,"session_id":"b3893b18-3ca5-4923-87ae-161c6ed9acbd"}
1852025-03-18T16:48:47.757Z{"msg":"[0]R flush_numbers: [3995, 3995, 3995, 3995, 3995]","v":0,"name":"crucible","level":30,"time":"2025-03-18T16:48:47.540914635Z","hostname":"w-01JPN225S828YGR17Y0NASFSKX","pid":1236,"":"downstairs","":"downstairs","session_id":"b3893b18-3ca5-4923-87ae-161c6ed9acbd"}
1862025-03-18T16:48:47.757Z{"msg":"[0]R generation: [25, 25, 25, 25, 25]","v":0,"name":"crucible","level":30,"time":"2025-03-18T16:48:47.540933122Z","hostname":"w-01JPN225S828YGR17Y0NASFSKX","pid":1236,"":"downstairs","":"downstairs","session_id":"b3893b18-3ca5-4923-87ae-161c6ed9acbd"}
1872025-03-18T16:48:47.757Z{"msg":"[0]R dirty: [false, false, false, false, false]","v":0,"name":"crucible","level":30,"time":"2025-03-18T16:48:47.540964348Z","hostname":"w-01JPN225S828YGR17Y0NASFSKX","pid":1236,"":"downstairs","":"downstairs","session_id":"b3893b18-3ca5-4923-87ae-161c6ed9acbd"}
1882025-03-18T16:48:47.757Z{"msg":"[1]R flush_numbers: [3995, 3995, 3995, 3995, 3995]","v":0,"name":"crucible","level":30,"time":"2025-03-18T16:48:47.540979355Z","hostname":"w-01JPN225S828YGR17Y0NASFSKX","pid":1236,"":"downstairs","":"downstairs","session_id":"b3893b18-3ca5-4923-87ae-161c6ed9acbd"}
1892025-03-18T16:48:47.757Z{"msg":"[1]R generation: [25, 25, 25, 25, 25]","v":0,"name":"crucible","level":30,"time":"2025-03-18T16:48:47.541008711Z","hostname":"w-01JPN225S828YGR17Y0NASFSKX","pid":1236,"":"downstairs","":"downstairs","session_id":"b3893b18-3ca5-4923-87ae-161c6ed9acbd"}
1902025-03-18T16:48:47.757Z{"msg":"[1]R dirty: [false, false, false, false, false]","v":0,"name":"crucible","level":30,"time":"2025-03-18T16:48:47.541039077Z","hostname":"w-01JPN225S828YGR17Y0NASFSKX","pid":1236,"":"downstairs","":"downstairs","session_id":"b3893b18-3ca5-4923-87ae-161c6ed9acbd"}
1912025-03-18T16:48:47.757Z{"msg":"[2]R flush_numbers: [3995, 3995, 3995, 3995, 3995]","v":0,"name":"crucible","level":30,"time":"2025-03-18T16:48:47.541054575Z","hostname":"w-01JPN225S828YGR17Y0NASFSKX","pid":1236,"":"downstairs","":"downstairs","session_id":"b3893b18-3ca5-4923-87ae-161c6ed9acbd"}
1922025-03-18T16:48:47.757Z{"msg":"[2]R generation: [25, 25, 25, 25, 25]","v":0,"name":"crucible","level":30,"time":"2025-03-18T16:48:47.54108542Z","hostname":"w-01JPN225S828YGR17Y0NASFSKX","pid":1236,"":"downstairs","":"downstairs","session_id":"b3893b18-3ca5-4923-87ae-161c6ed9acbd"}
1932025-03-18T16:48:47.757Z{"msg":"[2]R dirty: [false, false, false, false, false]","v":0,"name":"crucible","level":30,"time":"2025-03-18T16:48:47.541101528Z","hostname":"w-01JPN225S828YGR17Y0NASFSKX","pid":1236,"":"downstairs","":"downstairs","session_id":"b3893b18-3ca5-4923-87ae-161c6ed9acbd"}
1942025-03-18T16:48:47.757Z{"msg":"Max found gen is 26","v":0,"name":"crucible","level":30,"time":"2025-03-18T16:48:47.541139342Z","hostname":"w-01JPN225S828YGR17Y0NASFSKX","pid":1236,"":"downstairs","":"downstairs","session_id":"b3893b18-3ca5-4923-87ae-161c6ed9acbd"}
1952025-03-18T16:48:47.757Z{"msg":"Generation requested: 31 >= found:26","v":0,"name":"crucible","level":30,"time":"2025-03-18T16:48:47.541163988Z","hostname":"w-01JPN225S828YGR17Y0NASFSKX","pid":1236,"":"downstairs","":"downstairs","session_id":"b3893b18-3ca5-4923-87ae-161c6ed9acbd"}
1962025-03-18T16:48:47.757Z{"msg":"Next flush: 3996","v":0,"name":"crucible","level":30,"time":"2025-03-18T16:48:47.541192934Z","hostname":"w-01JPN225S828YGR17Y0NASFSKX","pid":1236,"":"downstairs","":"downstairs","session_id":"b3893b18-3ca5-4923-87ae-161c6ed9acbd"}
1972025-03-18T16:48:47.757Z{"msg":"All extents match","v":0,"name":"crucible","level":30,"time":"2025-03-18T16:48:47.54121866Z","hostname":"w-01JPN225S828YGR17Y0NASFSKX","pid":1236,"":"downstairs","":"downstairs","session_id":"b3893b18-3ca5-4923-87ae-161c6ed9acbd"}
1982025-03-18T16:48:47.757Z{"msg":"No downstairs reconciliation required","v":0,"name":"crucible","level":30,"time":"2025-03-18T16:48:47.541233138Z","hostname":"w-01JPN225S828YGR17Y0NASFSKX","pid":1236,"session_id":"b3893b18-3ca5-4923-87ae-161c6ed9acbd"}
1992025-03-18T16:48:47.757Z{"msg":"Transition from WaitQuorum to Active","v":0,"name":"crucible","level":30,"time":"2025-03-18T16:48:47.541247556Z","hostname":"w-01JPN225S828YGR17Y0NASFSKX","pid":1236,"client":"0","":"downstairs","session_id":"b3893b18-3ca5-4923-87ae-161c6ed9acbd"}
2002025-03-18T16:48:47.757Z{"msg":"Transition from WaitQuorum to Active","v":0,"name":"crucible","level":30,"time":"2025-03-18T16:48:47.541270433Z","hostname":"w-01JPN225S828YGR17Y0NASFSKX","pid":1236,"client":"1","":"downstairs","session_id":"b3893b18-3ca5-4923-87ae-161c6ed9acbd"}
2012025-03-18T16:48:47.757Z{"msg":"Transition from WaitQuorum to Active","v":0,"name":"crucible","level":30,"time":"2025-03-18T16:48:47.541306037Z","hostname":"w-01JPN225S828YGR17Y0NASFSKX","pid":1236,"client":"2","":"downstairs","session_id":"b3893b18-3ca5-4923-87ae-161c6ed9acbd"}
2022025-03-18T16:48:47.757Z{"msg":"All required reconciliation work is completed","v":0,"name":"crucible","level":30,"time":"2025-03-18T16:48:47.541332343Z","hostname":"w-01JPN225S828YGR17Y0NASFSKX","pid":1236,"session_id":"b3893b18-3ca5-4923-87ae-161c6ed9acbd"}
2032025-03-18T16:48:47.757Z{"msg":"Set Downstairs and Upstairs active after reconciliation","v":0,"name":"crucible","level":30,"time":"2025-03-18T16:48:47.54135689Z","hostname":"w-01JPN225S828YGR17Y0NASFSKX","pid":1236,"session_id":"b3893b18-3ca5-4923-87ae-161c6ed9acbd"}
2042025-03-18T16:48:47.757Z{"msg":"d866bfa1-7609-43f8-85d1-205bc133f7bd is now active with session: b3893b18-3ca5-4923-87ae-161c6ed9acbd","v":0,"name":"crucible","level":30,"time":"2025-03-18T16:48:47.541380147Z","hostname":"w-01JPN225S828YGR17Y0NASFSKX","pid":1236,"session_id":"b3893b18-3ca5-4923-87ae-161c6ed9acbd"}
2052025-03-18T16:48:47.757Z{"msg":"Set Active after no reconciliation","v":0,"name":"crucible","level":30,"time":"2025-03-18T16:48:47.541402703Z","hostname":"w-01JPN225S828YGR17Y0NASFSKX","pid":1236,"session_id":"b3893b18-3ca5-4923-87ae-161c6ed9acbd"}
2062025-03-18T16:48:47.757Z{"msg":"The guest has finished waiting for activation with:31","v":0,"name":"crucible","level":30,"time":"2025-03-18T16:48:47.5414263Z","hostname":"w-01JPN225S828YGR17Y0NASFSKX","pid":1236}
2072025-03-18T16:48:47.757Z{"msg":"Activated sub_volume d866bfa1-7609-43f8-85d1-205bc133f7bd","v":0,"name":"crucible","level":30,"time":"2025-03-18T16:48:47.541644077Z","hostname":"w-01JPN225S828YGR17Y0NASFSKX","pid":1236}
2082025-03-18T16:48:47.757Z{"msg":"The guest has requested activation with gen:31","v":0,"name":"crucible","level":30,"time":"2025-03-18T16:48:47.541717937Z","hostname":"w-01JPN225S828YGR17Y0NASFSKX","pid":1236}
2092025-03-18T16:48:47.757Z{"msg":"d866bfa1-7609-43f8-85d1-205bc133f7bd active request set","v":0,"name":"crucible","level":30,"time":"2025-03-18T16:48:47.541739903Z","hostname":"w-01JPN225S828YGR17Y0NASFSKX","pid":1236,"session_id":"419b0db9-aede-46e0-9984-ed6137830fe5"}
2102025-03-18T16:48:47.757Z{"msg":"sending connect oneshot to client","v":0,"name":"crucible","level":30,"time":"2025-03-18T16:48:47.541754951Z","hostname":"w-01JPN225S828YGR17Y0NASFSKX","pid":1236,"client":"0","":"downstairs","session_id":"419b0db9-aede-46e0-9984-ed6137830fe5"}
2112025-03-18T16:48:47.757Z{"msg":"client set_active_request while in Connecting { state: Start { auto_promote: true }, mode: New }; waiting...","v":0,"name":"crucible","level":30,"time":"2025-03-18T16:48:47.541777268Z","hostname":"w-01JPN225S828YGR17Y0NASFSKX","pid":1236,"client":"0","":"downstairs","session_id":"419b0db9-aede-46e0-9984-ed6137830fe5"}
2122025-03-18T16:48:47.757Z{"msg":"sending connect oneshot to client","v":0,"name":"crucible","level":30,"time":"2025-03-18T16:48:47.541794135Z","hostname":"w-01JPN225S828YGR17Y0NASFSKX","pid":1236,"client":"1","":"downstairs","session_id":"419b0db9-aede-46e0-9984-ed6137830fe5"}
2132025-03-18T16:48:47.757Z{"msg":"client set_active_request while in Connecting { state: Start { auto_promote: true }, mode: New }; waiting...","v":0,"name":"crucible","level":30,"time":"2025-03-18T16:48:47.541820651Z","hostname":"w-01JPN225S828YGR17Y0NASFSKX","pid":1236,"client":"1","":"downstairs","session_id":"419b0db9-aede-46e0-9984-ed6137830fe5"}
2142025-03-18T16:48:47.757Z{"msg":"sending connect oneshot to client","v":0,"name":"crucible","level":30,"time":"2025-03-18T16:48:47.541834949Z","hostname":"w-01JPN225S828YGR17Y0NASFSKX","pid":1236,"client":"2","":"downstairs","session_id":"419b0db9-aede-46e0-9984-ed6137830fe5"}
2152025-03-18T16:48:47.757Z{"msg":"client set_active_request while in Connecting { state: Start { auto_promote: true }, mode: New }; waiting...","v":0,"name":"crucible","level":30,"time":"2025-03-18T16:48:47.541849037Z","hostname":"w-01JPN225S828YGR17Y0NASFSKX","pid":1236,"client":"2","":"downstairs","session_id":"419b0db9-aede-46e0-9984-ed6137830fe5"}
2162025-03-18T16:48:47.758Z{"msg":"connecting to 127.0.0.1:8860","v":0,"name":"crucible","level":30,"time":"2025-03-18T16:48:47.541868914Z","hostname":"w-01JPN225S828YGR17Y0NASFSKX","pid":1236,"":"io task","client":"2","":"downstairs","session_id":"419b0db9-aede-46e0-9984-ed6137830fe5"}
2172025-03-18T16:48:47.758Z{"msg":"connecting to 127.0.0.1:8840","v":0,"name":"crucible","level":30,"time":"2025-03-18T16:48:47.541882722Z","hostname":"w-01JPN225S828YGR17Y0NASFSKX","pid":1236,"":"io task","client":"0","":"downstairs","session_id":"419b0db9-aede-46e0-9984-ed6137830fe5"}
2182025-03-18T16:48:47.758Z{"msg":"connecting to 127.0.0.1:8850","v":0,"name":"crucible","level":30,"time":"2025-03-18T16:48:47.541909228Z","hostname":"w-01JPN225S828YGR17Y0NASFSKX","pid":1236,"":"io task","client":"1","":"downstairs","session_id":"419b0db9-aede-46e0-9984-ed6137830fe5"}
2192025-03-18T16:48:47.758Z{"msg":"ds_connection connected from Ok(127.0.0.1:41878)","v":0,"name":"crucible","level":30,"time":"2025-03-18T16:48:47.541923356Z","hostname":"w-01JPN225S828YGR17Y0NASFSKX","pid":1236,"":"io task","client":"2","":"downstairs","session_id":"419b0db9-aede-46e0-9984-ed6137830fe5"}
2202025-03-18T16:48:47.758Z{"msg":"ds_connection connected from Ok(127.0.0.1:58624)","v":0,"name":"crucible","level":30,"time":"2025-03-18T16:48:47.541953902Z","hostname":"w-01JPN225S828YGR17Y0NASFSKX","pid":1236,"":"io task","client":"0","":"downstairs","session_id":"419b0db9-aede-46e0-9984-ed6137830fe5"}
2212025-03-18T16:48:47.758Z{"msg":"ds_connection connected from Ok(127.0.0.1:39015)","v":0,"name":"crucible","level":30,"time":"2025-03-18T16:48:47.541983707Z","hostname":"w-01JPN225S828YGR17Y0NASFSKX","pid":1236,"":"io task","client":"1","":"downstairs","session_id":"419b0db9-aede-46e0-9984-ed6137830fe5"}
2222025-03-18T16:48:47.758Z{"msg":"version negotiation from state Connecting { state: WaitForPromote, mode: New }","v":0,"name":"crucible","level":30,"time":"2025-03-18T16:48:47.542011363Z","hostname":"w-01JPN225S828YGR17Y0NASFSKX","pid":1236,"client":"2","":"downstairs","session_id":"419b0db9-aede-46e0-9984-ed6137830fe5"}
2232025-03-18T16:48:47.758Z{"msg":"version negotiation from state Connecting { state: WaitForPromote, mode: New }","v":0,"name":"crucible","level":30,"time":"2025-03-18T16:48:47.5420327Z","hostname":"w-01JPN225S828YGR17Y0NASFSKX","pid":1236,"client":"1","":"downstairs","session_id":"419b0db9-aede-46e0-9984-ed6137830fe5"}
2242025-03-18T16:48:47.758Z{"msg":"version negotiation from state Connecting { state: WaitForPromote, mode: New }","v":0,"name":"crucible","level":30,"time":"2025-03-18T16:48:47.542047718Z","hostname":"w-01JPN225S828YGR17Y0NASFSKX","pid":1236,"client":"0","":"downstairs","session_id":"419b0db9-aede-46e0-9984-ed6137830fe5"}
2252025-03-18T16:48:47.758Z{"msg":"downstairs client at Some(127.0.0.1:8860) has region UUID 12345678-0000-0000-0000-000000008860","v":0,"name":"crucible","level":30,"time":"2025-03-18T16:48:47.542378729Z","hostname":"w-01JPN225S828YGR17Y0NASFSKX","pid":1236,"client":"2","":"downstairs","session_id":"419b0db9-aede-46e0-9984-ed6137830fe5"}
2262025-03-18T16:48:47.758Z{"msg":"downstairs client at Some(127.0.0.1:8850) has region UUID 12345678-0000-0000-0000-000000008850","v":0,"name":"crucible","level":30,"time":"2025-03-18T16:48:47.542433341Z","hostname":"w-01JPN225S828YGR17Y0NASFSKX","pid":1236,"client":"1","":"downstairs","session_id":"419b0db9-aede-46e0-9984-ed6137830fe5"}
2272025-03-18T16:48:47.758Z{"msg":"downstairs client at Some(127.0.0.1:8840) has region UUID 12345678-0000-0000-0000-000000008840","v":0,"name":"crucible","level":30,"time":"2025-03-18T16:48:47.542552203Z","hostname":"w-01JPN225S828YGR17Y0NASFSKX","pid":1236,"client":"0","":"downstairs","session_id":"419b0db9-aede-46e0-9984-ed6137830fe5"}
2282025-03-18T16:48:47.758Z{"msg":"Waiting for more clients to be ready","v":0,"name":"crucible","level":30,"time":"2025-03-18T16:48:47.542838881Z","hostname":"w-01JPN225S828YGR17Y0NASFSKX","pid":1236,"session_id":"419b0db9-aede-46e0-9984-ed6137830fe5"}
2292025-03-18T16:48:47.758Z{"msg":"Waiting for more clients to be ready","v":0,"name":"crucible","level":30,"time":"2025-03-18T16:48:47.542877535Z","hostname":"w-01JPN225S828YGR17Y0NASFSKX","pid":1236,"session_id":"419b0db9-aede-46e0-9984-ed6137830fe5"}
2302025-03-18T16:48:47.758Z{"msg":"[0]R flush_numbers: [5313, 5314, 5313, 5316, 5314]","v":0,"name":"crucible","level":30,"time":"2025-03-18T16:48:47.542925559Z","hostname":"w-01JPN225S828YGR17Y0NASFSKX","pid":1236,"":"downstairs","":"downstairs","session_id":"419b0db9-aede-46e0-9984-ed6137830fe5"}
2312025-03-18T16:48:47.758Z{"msg":"[0]R generation: [13, 13, 13, 14, 13]","v":0,"name":"crucible","level":30,"time":"2025-03-18T16:48:47.542965502Z","hostname":"w-01JPN225S828YGR17Y0NASFSKX","pid":1236,"":"downstairs","":"downstairs","session_id":"419b0db9-aede-46e0-9984-ed6137830fe5"}
2322025-03-18T16:48:47.758Z{"msg":"[0]R dirty: [false, false, false, false, false]","v":0,"name":"crucible","level":30,"time":"2025-03-18T16:48:47.543002007Z","hostname":"w-01JPN225S828YGR17Y0NASFSKX","pid":1236,"":"downstairs","":"downstairs","session_id":"419b0db9-aede-46e0-9984-ed6137830fe5"}
2332025-03-18T16:48:47.758Z{"msg":"[1]R flush_numbers: [5313, 5314, 5313, 5316, 5314]","v":0,"name":"crucible","level":30,"time":"2025-03-18T16:48:47.543021614Z","hostname":"w-01JPN225S828YGR17Y0NASFSKX","pid":1236,"":"downstairs","":"downstairs","session_id":"419b0db9-aede-46e0-9984-ed6137830fe5"}
2342025-03-18T16:48:47.758Z{"msg":"[1]R generation: [13, 13, 13, 14, 13]","v":0,"nameWait for a query_work_queue command to finish before sending IO
2352025-03-18T16:48:47.758Z":"crucible","level":30,"time":"2025-03-18T16:48:47.543043531Z","hostname":"w-01JPN225S828YGR17Y0NASFSKX","pid":1236,"":"downstairs","":"downstairs","session_id":"419b0db9-aede-46e0-9984-ed6137830fe5"}
2362025-03-18T16:48:47.758Z{"msg":"[1]R dirty: [false, false, false, false, false]","v":0,"name":"crucible","level":30,"time":"2025-03-18T16:48:47.543059169Z","hostname":"w-01JPN225S828YGR17Y0NASFSKX","pid":1236,"":"downstairs","":"downstairs","session_id":"419b0db9-aede-46e0-9984-ed6137830fe5"}
2372025-03-18T16:48:47.758Z{"msg":"[2]R flush_numbers: [5313, 5314, 5313, 5316, 5314]","v":0,"name":"crucible","level":30,"time":"2025-03-18T16:48:47.543072647Z","hostname":"w-01JPN225S828YGR17Y0NASFSKX","pid":1236,"":"downstairs","":"downstairs","session_id":"419b0db9-aede-46e0-9984-ed6137830fe5"}
2382025-03-18T16:48:47.758Z{"msg":"[2]R generation: [13, 13, 13, 14, 13]","v":0,"name":"crucible","level":30,"time":"2025-03-18T16:48:47.543086735Z","hostname":"w-01JPN225S828YGR17Y0NASFSKX","pid":1236,"":"downstairs","":"downstairs","session_id":"419b0db9-aede-46e0-9984-ed6137830fe5"}
2392025-03-18T16:48:47.758Z{"msg":"[2]R dirty: [false, false, false, false, false]","v":0,"name":"crucible","level":30,"time":"2025-03-18T16:48:47.543101162Z","hostname":"w-01JPN225S828YGR17Y0NASFSKX","pid":1236,"":"downstairs","":"downstairs","session_id":"419b0db9-aede-46e0-9984-ed6137830fe5"}
2402025-03-18T16:48:47.758Z{"msg":"Max found gen is 15","v":0,"name":"crucible","level":30,"time":"2025-03-18T16:48:47.543124239Z","hostname":"w-01JPN225S828YGR17Y0NASFSKX","pid":1236,"":"downstairs","":"downstairs","session_id":"419b0db9-aede-46e0-9984-ed6137830fe5"}
2412025-03-18T16:48:47.758Z{"msg":"Generation requested: 31 >= found:15","v":0,"name":"crucible","level":30,"time":"2025-03-18T16:48:47.543138987Z","hostname":"w-01JPN225S828YGR17Y0NASFSKX","pid":1236,"":"downstairs","":"downstairs","session_id":"419b0db9-aede-46e0-9984-ed6137830fe5"}
2422025-03-18T16:48:47.758Z{"msg":"Next flush: 5317","v":0,"name":"crucible","level":30,"time":"2025-03-18T16:48:47.543155554Z","hostname":"w-01JPN225S828YGR17Y0NASFSKX","pid":1236,"":"downstairs","":"downstairs","session_id":"419b0db9-aede-46e0-9984-ed6137830fe5"}
2432025-03-18T16:48:47.758Z{"msg":"All extents match","v":0,"name":"crucible","level":30,"time":"2025-03-18T16:48:47.54318781Z","hostname":"w-01JPN225S828YGR17Y0NASFSKX","pid":1236,"":"downstairs","":"downstairs","session_id":"419b0db9-aede-46e0-9984-ed6137830fe5"}
2442025-03-18T16:48:47.758Z{"msg":"No downstairs reconciliation required","v":0,"name":"crucible","level":30,"time":"2025-03-18T16:48:47.543206857Z","hostname":"w-01JPN225S828YGR17Y0NASFSKX","pid":1236,"session_id":"419b0db9-aede-46e0-9984-ed6137830fe5"}
2452025-03-18T16:48:47.758Z{"msg":"Transition from WaitQuorum to Active","v":0,"name":"crucible","level":30,"time":"2025-03-18T16:48:47.543236733Z","hostname":"w-01JPN225S828YGR17Y0NASFSKX","pid":1236,"client":"0","":"downstairs","session_id":"419b0db9-aede-46e0-9984-ed6137830fe5"}
2462025-03-18T16:48:47.758Z{"msg":"Transition from WaitQuorum to Active","v":0,"name":"crucible","level":30,"time":"2025-03-18T16:48:47.54325417Z","hostname":"w-01JPN225S828YGR17Y0NASFSKX","pid":1236,"client":"1","":"downstairs","session_id":"419b0db9-aede-46e0-9984-ed6137830fe5"}
2472025-03-18T16:48:47.758Z{"msg":"Transition from WaitQuorum to Active","v":0,"name":"crucible","level":30,"time":"2025-03-18T16:48:47.543276337Z","hostname":"w-01JPN225S828YGR17Y0NASFSKX","pid":1236,"client":"2","":"downstairs","session_id":"419b0db9-aede-46e0-9984-ed6137830fe5"}
2482025-03-18T16:48:47.758Z{"msg":"All required reconciliation work is completed","v":0,"name":"crucible","level":30,"time":"2025-03-18T16:48:47.543306822Z","hostname":"w-01JPN225S828YGR17Y0NASFSKX","pid":1236,"session_id":"419b0db9-aede-46e0-9984-ed6137830fe5"}
2492025-03-18T16:48:47.758Z{"msg":"Set Downstairs and Upstairs active after reconciliation","v":0,"name":"crucible","level":30,"time":"2025-03-18T16:48:47.543332418Z","hostname":"w-01JPN225S828YGR17Y0NASFSKX","pid":1236,"session_id":"419b0db9-aede-46e0-9984-ed6137830fe5"}
2502025-03-18T16:48:47.758Z{"msg":"d866bfa1-7609-43f8-85d1-205bc133f7bd is now active with session: 419b0db9-aede-46e0-9984-ed6137830fe5","v":0,"name":"crucible","level":30,"time":"2025-03-18T16:48:47.543349726Z","hostname":"w-01JPN225S828YGR17Y0NASFSKX","pid":1236,"session_id":"419b0db9-aede-46e0-9984-ed6137830fe5"}
2512025-03-18T16:48:47.758Z{"msg":"Set Active after no reconciliation","v":0,"name":"crucible","level":30Disk: sv:2 bs:4096 ts:409600 tb:100 max_io:100 or 409600
2522025-03-18T16:48:47.758Z,"time":"2025-03-18T16:48:47.543378781Z","hostname":"w-01JPN225S828YGR17Y0NASFSKX","pid":1236,"session_id":"419b0db9-aede-46e0-9984-ed6137830fe5"}
2532025-03-18T16:48:47.758Z{"msg":"The guest has finished waiting for activation with:31","v":0,"name":"crucible","level":30,"time":"2025-03-18T16:48:47.543394369Z","hostname":"w-01JPN225S828YGR17Y0NASFSKX","pid":1236}
2542025-03-18T16:48:47.758ZFill test
2552025-03-18T16:48:47.759Z{"msg":"Activated sub_volume d866bfa1-7609-43f8-85d1-205bc133f7bd","v":0,"name":"crucible","level":30,"time":"2025-03-18T16:48:47.543415056Z","hostname":"w-01JPN225S828YGR17Y0NASFSKX","pid":1236}
2562025-03-18T16:48:47.797ZRead and Verify all blocks (0..100 range:false)
2572025-03-18T16:48:47.877ZWrote out file "/var/tmp/test_up-build/verify_file"
2582025-03-18T16:48:47.877ZCLIENT: Tests done. All submitted work has been ACK'd
2592025-03-18T16:48:47.880Z----------------------------------------------------------------
2602025-03-18T16:48:47.880Z Crucible gen:31 GIO:true work queues: Upstairs:0 downstairs:1
2612025-03-18T16:48:47.880ZStates: Active Active Active
2622025-03-18T16:48:47.880ZJOBID ACK TYPE BKS/EXT DS:0 DS:1 DS:2 REPLAY
2632025-03-18T16:48:47.880Z 1002 Acked Read 50 Done Done Done false
2642025-03-18T16:48:47.880Z STATES DS:0 DS:1 DS:2 TOTAL
2652025-03-18T16:48:47.880Z Sent 0 0 0 0
2662025-03-18T16:48:47.880Z Done 1 1 1 3
2672025-03-18T16:48:47.880Z Skipped 0 0 0 0
2682025-03-18T16:48:47.880Z Error 0 0 0 0
2692025-03-18T16:48:47.880ZLast Flush: Some(JobId(1001)) Some(JobId(1001)) Some(JobId(1001))
2702025-03-18T16:48:47.881ZDownstairs last five completed: 1001 1000
2712025-03-18T16:48:47.881ZUpstairs last five completed: 1002 1001 1000
2722025-03-18T16:48:47.881Z----------------------------------------------------------------
2732025-03-18T16:48:47.881Z Crucible gen:31 GIO:true work queues: Upstairs:0 downstairs:1
2742025-03-18T16:48:47.881ZStates: Active Active Active
2752025-03-18T16:48:47.881ZJOBID ACK TYPE BKS/EXT DS:0 DS:1 DS:2 REPLAY
2762025-03-18T16:48:47.881Z 1002 Acked Read 50 Done Done Done false
2772025-03-18T16:48:47.881Z STATES DS:0 DS:1 DS:2 TOTAL
2782025-03-18T16:48:47.881Z Sent 0 0 0 0
2792025-03-18T16:48:47.881Z Done 1 1 1 3
2802025-03-18T16:48:47.881Z Skipped 0 0 0 0
2812025-03-18T16:48:47.881Z Error 0 0 0 0
2822025-03-18T16:48:47.881ZLast Flush: Some(JobId(1001)) Some(JobId(1001)) Some(JobId(1001))
2832025-03-18T16:48:47.881ZDownstairs last five completed: 1001 1000
2842025-03-18T16:48:47.881ZUpstairs last five completed: 1002 1001 1000
2852025-03-18T16:48:47.881ZCLIENT: Up:0 ds:2 act:6
2862025-03-18T16:48:51.879Z----------------------------------------------------------------
2872025-03-18T16:48:51.879Z Crucible gen:31 GIO:true work queues: Upstairs:0 downstairs:0
2882025-03-18T16:48:51.879ZDownstairs last five completed: 1003 1002 1001 1000
2892025-03-18T16:48:51.879ZUpstairs last five completed: 1003 1002 1001 1000
2902025-03-18T16:48:51.882Z----------------------------------------------------------------
2912025-03-18T16:48:51.882Z Crucible gen:31 GIO:true work queues: Upstairs:0 downstairs:0
2922025-03-18T16:48:51.882ZDownstairs last five completed: 1003 1002 1001 1000
2932025-03-18T16:48:51.882ZUpstairs last five completed: 1003 1002 1001 1000
2942025-03-18T16:48:51.882ZCLIENT: Up:0 ds:0 act:6
2952025-03-18T16:48:51.882ZCLIENT: All crucible jobs finished, exiting program
2962025-03-18T16:48:51.889ZRepair setup passed
2972025-03-18T16:48:51.893ZCopy the region for /var/tmp/test_up-build/8830
2982025-03-18T16:48:51.896Zcp -r /var/tmp/test_up-build/8830 /var/tmp/test_up-build/previous
2992025-03-18T16:48:51.896Z/var/tmp/bins/crutest fill -g 32 -q --key B3P3gZ9tJ5vWD72EjbZTFM1kuPb0n3pWl29LAKfzNeo= --dsc 127.0.0.1:9998 --verify-out /var/tmp/test_up-build/verify_file --verify-in /var/tmp/test_up-build/verify_file
3002025-03-18T16:48:51.954Z{"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":"2025-03-18T16:48:51.742209348Z","hostname":"w-01JPN225S828YGR17Y0NASFSKX","pid":1242,"task":"crutest"}
3012025-03-18T16:48:51.957Z{"msg":"dsc has 6 regions. This means 2 sub_volumes","v":0,"name":"crucible","level":30,"time":"2025-03-18T16:48:51.742793532Z","hostname":"w-01JPN225S828YGR17Y0NASFSKX","pid":1242,"task":"crutest"}
3022025-03-18T16:48:51.957Z{"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":"2025-03-18T16:48:51.744578578Z","hostname":"w-01JPN225S828YGR17Y0NASFSKX","pid":1242,"task":"crutest"}
3032025-03-18T16:48:51.957Z{"msg":"Upstairs starts","v":0,"name":"crucible","level":30,"time":"2025-03-18T16:48:51.744750743Z","hostname":"w-01JPN225S828YGR17Y0NASFSKX","pid":1242}
3042025-03-18T16:48:51.957Z{"msg":"Crucible Version: BuildInfo {\n version: \"0.0.1\",\n git_sha: \"e56b83235918dca6f00b1bca17876ae8794868bc\",\n git_commit_timestamp: \"2025-03-18T04:42:45.000000000Z\",\n git_branch: \"renovate/chrono-0.x-lockfile\",\n rustc_semver: \"1.84.0\",\n rustc_channel: \"stable\",\n rustc_host_triple: \"x86_64-unknown-illumos\",\n rustc_commit_sha: \"9fc6b43126469e3858e2fe86cafb4f0fd5068869\",\n cargo_triple: \"x86_64-unknown-illumos\",\n debug: true,\n opt_level: 0,\n}","v":0,"name":"crucible","level":30,"time":"2025-03-18T16:48:51.744797416Z","hostname":"w-01JPN225S828YGR17Y0NASFSKX","pid":1242}
3052025-03-18T16:48:51.957Z{"msg":"Upstairs <-> Downstairs Message Version: 13","v":0,"name":"crucible","level":30,"time":"2025-03-18T16:48:51.744821123Z","hostname":"w-01JPN225S828YGR17Y0NASFSKX","pid":1242}
3062025-03-18T16:48:51.957Z{"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":"2025-03-18T16:48:51.74483644Z","hostname":"w-01JPN225S828YGR17Y0NASFSKX","pid":1242}
3072025-03-18T16:48:51.957Z{"msg":"Crucible 2c535504-7ce7-4378-95e9-a2e694dd08c5 has session id: def4a025-8efb-479e-bf63-68249a6959bc","v":0,"name":"crucible","level":30,"time":"2025-03-18T16:48:51.745431663Z","hostname":"w-01JPN225S828YGR17Y0NASFSKX","pid":1242,"session_id":"def4a025-8efb-479e-bf63-68249a6959bc"}
3082025-03-18T16:48:51.957Z{"msg":"Upstairs opts: Upstairs UUID: 2c535504-7ce7-4378-95e9-a2e694dd08c5, 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":"2025-03-18T16:48:51.745472377Z","hostname":"w-01JPN225S828YGR17Y0NASFSKX","pid":1242,"session_id":"def4a025-8efb-479e-bf63-68249a6959bc"}
3092025-03-18T16:48:51.957Z{"msg":"Crucible stats registered with UUID: 2c535504-7ce7-4378-95e9-a2e694dd08c5","v":0,"name":"crucible","level":30,"time":"2025-03-18T16:48:51.745487824Z","hostname":"w-01JPN225S828YGR17Y0NASFSKX","pid":1242,"session_id":"def4a025-8efb-479e-bf63-68249a6959bc"}
3102025-03-18T16:48:51.957Z{"msg":"could not find Downstairs address for Nexus","v":0,"name":"crucible","level":40,"time":"2025-03-18T16:48:51.745500622Z","hostname":"w-01JPN225S828YGR17Y0NASFSKX","pid":1242,"session_id":"def4a025-8efb-479e-bf63-68249a6959bc"}
3112025-03-18T16:48:51.961Z{"msg":"SV 1 has targets: [127.0.0.1:8840, 127.0.0.1:8850, 127.0.0.1:8860]","v":0,"name":"crucible","level":30,"time":"2025-03-18T16:48:51.74755431Z","hostname":"w-01JPN225S828YGR17Y0NASFSKX","pid":1242,"task":"crutest"}
3122025-03-18T16:48:51.961Z{"msg":"Upstairs starts","v":0,"name":"crucible","level":30,"time":"2025-03-18T16:48:51.74762007Z","hostname":"w-01JPN225S828YGR17Y0NASFSKX","pid":1242}
3132025-03-18T16:48:51.961Z{"msg":"Crucible Version: BuildInfo {\n version: \"0.0.1\",\n git_sha: \"e56b83235918dca6f00b1bca17876ae8794868bc\",\n git_commit_timestamp: \"2025-03-18T04:42:45.000000000Z\",\n git_branch: \"renovate/chrono-0.x-lockfile\",\n rustc_semver: \"1.84.0\",\n rustc_channel: \"stable\",\n rustc_host_triple: \"x86_64-unknown-illumos\",\n rustc_commit_sha: \"9fc6b43126469e3858e2fe86cafb4f0fd5068869\",\n cargo_triple: \"x86_64-unknown-illumos\",\n debug: true,\n opt_level: 0,\n}","v":0,"name":"crucible","level":30,"time":"2025-03-18T16:48:51.747655015Z","hostname":"w-01JPN225S828YGR17Y0NASFSKX","pid":1242}
3142025-03-18T16:48:51.961Z{"msg":"Upstairs <-> Downstairs Message Version: 13","v":0,"name":"crucible","level":30,"time":"2025-03-18T16:48:51.747667713Z","hostname":"w-01JPN225S828YGR17Y0NASFSKX","pid":1242}
3152025-03-18T16:48:51.961Z{"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":"2025-03-18T16:48:51.747682061Z","hostname":"w-01JPN225S828YGR17Y0NASFSKX","pid":1242}
3162025-03-18T16:48:51.961Z{"msg":"Crucible 2c535504-7ce7-4378-95e9-a2e694dd08c5 has session id: a240abb9-f763-45ff-bf97-7b1834ac565c","v":0,"name":"crucible","level":30,"time":"2025-03-18T16:48:51.748100649Z","hostname":"w-01JPN225S828YGR17Y0NASFSKX","pid":1242,"session_id":"a240abb9-f763-45ff-bf97-7b1834ac565c"}
3172025-03-18T16:48:51.961Z{"msg":"Upstairs opts: Upstairs UUID: 2c535504-7ce7-4378-95e9-a2e694dd08c5, Targets: [127.0.0.1:8840, 127.0.0.1:8850, 127.0.0.1:8860], 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":"2025-03-18T16:48:51.748142183Z","hostname":"w-01JPN225S828YGR17Y0NASFSKX","pid":1242,"session_id":"a240abb9-f763-45ff-bf97-7b1834ac565c"}
3182025-03-18T16:48:51.961Z{"msg":"Crucible stats registered with UUID: 2c535504-7ce7-4378-95e9-a2e694dd08c5","v":0,"name":"crucible","level":30,"time":"2025-03-18T16:48:51.748193525Z","hostname":"w-01JPN225S828YGR17Y0NASFSKX","pid":1242,"session_id":"a240abb9-f763-45ff-bf97-7b1834ac565c"}
3192025-03-18T16:48:51.961Z{"msg":"could not find Downstairs address for Nexus","v":0,"name":"crucible","level":40,"time":"2025-03-18T16:48:51.748237839Z","hostname":"w-01JPN225S828YGR17Y0NASFSKX","pid":1242,"session_id":"a240abb9-f763-45ff-bf97-7b1834ac565c"}
3202025-03-18T16:48:51.961Z{"msg":"Downstairs in volume = 6","v":0,"name":"crucible","level":30,"time":"2025-03-18T16:48:51.748890502Z","hostname":"w-01JPN225S828YGR17Y0NASFSKX","pid":1242,"task":"crutest"}
3212025-03-18T16:48:51.961Z{"msg":"The guest has requested activation with gen:32","v":0,"name":"crucible","level":30,"time":"2025-03-18T16:48:51.748939265Z","hostname":"w-01JPN225S828YGR17Y0NASFSKX","pid":1242}
3222025-03-18T16:48:51.961Z{"msg":"2c535504-7ce7-4378-95e9-a2e694dd08c5 active request set","v":0,"name":"crucible","level":30,"time":"2025-03-18T16:48:51.748959542Z","hostname":"w-01JPN225S828YGR17Y0NASFSKX","pid":1242,"session_id":"def4a025-8efb-479e-bf63-68249a6959bc"}
3232025-03-18T16:48:51.961Z{"msg":"sending connect oneshot to client","v":0,"name":"crucible","level":30,"time":"2025-03-18T16:48:51.74897386Z","hostname":"w-01JPN225S828YGR17Y0NASFSKX","pid":1242,"client":"0","":"downstairs","session_id":"def4a025-8efb-479e-bf63-68249a6959bc"}
3242025-03-18T16:48:51.961Z{"msg":"client set_active_request while in Connecting { state: Start { auto_promote: true }, mode: New }; waiting...","v":0,"name":"crucible","level":30,"time":"2025-03-18T16:48:51.749007195Z","hostname":"w-01JPN225S828YGR17Y0NASFSKX","pid":1242,"client":"0","":"downstairs","session_id":"def4a025-8efb-479e-bf63-68249a6959bc"}
3252025-03-18T16:48:51.961Z{"msg":"sending connect oneshot to client","v":0,"name":"crucible","level":30,"time":"2025-03-18T16:48:51.74904244Z","hostname":"w-01JPN225S828YGR17Y0NASFSKX","pid":1242,"client":"1","":"downstairs","session_id":"def4a025-8efb-479e-bf63-68249a6959bc"}
3262025-03-18T16:48:51.961Z{"msg":"client set_active_request while in Connecting { state: Start { auto_promote: true }, mode: New }; waiting...","v":0,"name":"crucible","level":30,"time":"2025-03-18T16:48:51.749071316Z","hostname":"w-01JPN225S828YGR17Y0NASFSKX","pid":1242,"client":"1","":"downstairs","session_id":"def4a025-8efb-479e-bf63-68249a6959bc"}
3272025-03-18T16:48:51.961Z{"msg":"sending connect oneshot to client","v":0,"name":"crucible","level":30,"time":"2025-03-18T16:48:51.749100082Z","hostname":"w-01JPN225S828YGR17Y0NASFSKX","pid":1242,"client":"2","":"downstairs","session_id":"def4a025-8efb-479e-bf63-68249a6959bc"}
3282025-03-18T16:48:51.961Z{"msg":"client set_active_request while in Connecting { state: Start { auto_promote: true }, mode: New }; waiting...","v":0,"name":"crucible","level":30,"time":"2025-03-18T16:48:51.749140776Z","hostname":"w-01JPN225S828YGR17Y0NASFSKX","pid":1242,"client":"2","":"downstairs","session_id":"def4a025-8efb-479e-bf63-68249a6959bc"}
3292025-03-18T16:48:51.962Z{"msg":"connecting to 127.0.0.1:8830","v":0,"name":"crucible","level":30,"time":"2025-03-18T16:48:51.749166012Z","hostname":"w-01JPN225S828YGR17Y0NASFSKX","pid":1242,"":"io task","client":"2","":"downstairs","session_id":"def4a025-8efb-479e-bf63-68249a6959bc"}
3302025-03-18T16:48:51.962Z{"msg":"connecting to 127.0.0.1:8810","v":0,"name":"crucible","level":30,"time":"2025-03-18T16:48:51.749201447Z","hostname":"w-01JPN225S828YGR17Y0NASFSKX","pid":1242,"":"io task","client":"0","":"downstairs","session_id":"def4a025-8efb-479e-bf63-68249a6959bc"}
3312025-03-18T16:48:51.962Z{"msg":"connecting to 127.0.0.1:8820","v":0,"name":"crucible","level":30,"time":"2025-03-18T16:48:51.749227733Z","hostname":"w-01JPN225S828YGR17Y0NASFSKX","pid":1242,"":"io task","client":"1","":"downstairs","session_id":"def4a025-8efb-479e-bf63-68249a6959bc"}
3322025-03-18T16:48:51.962Z{"msg":"ds_connection connected from Ok(127.0.0.1:34907)","v":0,"name":"crucible","level":30,"time":"2025-03-18T16:48:51.749500922Z","hostname":"w-01JPN225S828YGR17Y0NASFSKX","pid":1242,"":"io task","client":"2","":"downstairs","session_id":"def4a025-8efb-479e-bf63-68249a6959bc"}
3332025-03-18T16:48:51.962Z{"msg":"ds_connection connected from Ok(127.0.0.1:37388)","v":0,"name":"crucible","level":30,"time":"2025-03-18T16:48:51.749551765Z","hostname":"w-01JPN225S828YGR17Y0NASFSKX","pid":1242,"":"io task","client":"0","":"downstairs","session_id":"def4a025-8efb-479e-bf63-68249a6959bc"}
3342025-03-18T16:48:51.962Z{"msg":"ds_connection connected from Ok(127.0.0.1:35942)","v":0,"name":"crucible","level":30,"time":"2025-03-18T16:48:51.749579881Z","hostname":"w-01JPN225S828YGR17Y0NASFSKX","pid":1242,"":"io task","client":"1","":"downstairs","session_id":"def4a025-8efb-479e-bf63-68249a6959bc"}
3352025-03-18T16:48:51.966Z{"msg":"version negotiation from state Connecting { state: WaitForPromote, mode: New }","v":0,"name":"crucible","level":30,"time":"2025-03-18T16:48:51.750008687Z","hostname":"w-01JPN225S828YGR17Y0NASFSKX","pid":1242,"client":"1","":"downstairs","session_id":"def4a025-8efb-479e-bf63-68249a6959bc"}
3362025-03-18T16:48:51.967Z{"msg":"version negotiation from state Connecting { state: WaitForPromote, mode: New }","v":0,"name":"crucible","level":30,"time":"2025-03-18T16:48:51.750045402Z","hostname":"w-01JPN225S828YGR17Y0NASFSKX","pid":1242,"client":"2","":"downstairs","session_id":"def4a025-8efb-479e-bf63-68249a6959bc"}
3372025-03-18T16:48:51.967Z{"msg":"version negotiation from state Connecting { state: WaitForPromote, mode: New }","v":0,"name":"crucible","level":30,"time":"2025-03-18T16:48:51.750061669Z","hostname":"w-01JPN225S828YGR17Y0NASFSKX","pid":1242,"client":"0","":"downstairs","session_id":"def4a025-8efb-479e-bf63-68249a6959bc"}
3382025-03-18T16:48:51.967Z{"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":"2025-03-18T16:48:51.750680058Z","hostname":"w-01JPN225S828YGR17Y0NASFSKX","pid":1242,"client":"1","":"downstairs","session_id":"def4a025-8efb-479e-bf63-68249a6959bc"}
3392025-03-18T16:48:51.967Z{"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":"2025-03-18T16:48:51.750716743Z","hostname":"w-01JPN225S828YGR17Y0NASFSKX","pid":1242,"client":"2","":"downstairs","session_id":"def4a025-8efb-479e-bf63-68249a6959bc"}
3402025-03-18T16:48:51.967Z{"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":"2025-03-18T16:48:51.750732491Z","hostname":"w-01JPN225S828YGR17Y0NASFSKX","pid":1242,"client":"0","":"downstairs","session_id":"def4a025-8efb-479e-bf63-68249a6959bc"}
3412025-03-18T16:48:51.967Z{"msg":"Waiting for more clients to be ready","v":0,"name":"crucible","level":30,"time":"2025-03-18T16:48:51.751137911Z","hostname":"w-01JPN225S828YGR17Y0NASFSKX","pid":1242,"session_id":"def4a025-8efb-479e-bf63-68249a6959bc"}
3422025-03-18T16:48:51.967Z{"msg":"Waiting for more clients to be ready","v":0,"name":"crucible","level":30,"time":"2025-03-18T16:48:51.751172496Z","hostname":"w-01JPN225S828YGR17Y0NASFSKX","pid":1242,"session_id":"def4a025-8efb-479e-bf63-68249a6959bc"}
3432025-03-18T16:48:51.967Z{"msg":"[0]R flush_numbers: [3996, 3996, 3996, 3996, 3996]","v":0,"name":"crucible","level":30,"time":"2025-03-18T16:48:51.751186374Z","hostname":"w-01JPN225S828YGR17Y0NASFSKX","pid":1242,"":"downstairs","":"downstairs","session_id":"def4a025-8efb-479e-bf63-68249a6959bc"}
3442025-03-18T16:48:51.967Z{"msg":"[0]R generation: [31, 31, 31, 31, 31]","v":0,"name":"crucible","level":30,"time":"2025-03-18T16:48:51.75120778Z","hostname":"w-01JPN225S828YGR17Y0NASFSKX","pid":1242,"":"downstairs","":"downstairs","session_id":"def4a025-8efb-479e-bf63-68249a6959bc"}
3452025-03-18T16:48:51.967Z{"msg":"[0]R dirty: [false, false, false, false, false]","v":0,"name":"crucible","level":30,"time":"2025-03-18T16:48:51.751221789Z","hostname":"w-01JPN225S828YGR17Y0NASFSKX","pid":1242,"":"downstairs","":"downstairs","session_id":"def4a025-8efb-479e-bf63-68249a6959bc"}
3462025-03-18T16:48:51.967Z{"msg":"[1]R flush_numbers: [3996, 3996, 3996, 3996, 3996]","v":0,"name":"crucible","level":30,"time":"2025-03-18T16:48:51.751241666Z","hostname":"w-01JPN225S828YGR17Y0NASFSKX","pid":1242,"":"downstairs","":"downstairs","session_id":"def4a025-8efb-479e-bf63-68249a6959bc"}
3472025-03-18T16:48:51.967Z{"msg":"[1]R generation: [31, 31, 31, 31, 31]","v":0,"name":"crucible","level":30,"time":"2025-03-18T16:48:51.751254753Z","hostname":"w-01JPN225S828YGR17Y0NASFSKX","pid":1242,"":"downstairs","":"downstairs","session_id":"def4a025-8efb-479e-bf63-68249a6959bc"}
3482025-03-18T16:48:51.967Z{"msg":"[1]R dirty: [false, false, false, false, false]","v":0,"name":"crucible","level":30,"time":"2025-03-18T16:48:51.751267742Z","hostname":"w-01JPN225S828YGR17Y0NASFSKX","pid":1242,"":"downstairs","":"downstairs","session_id":"def4a025-8efb-479e-bf63-68249a6959bc"}
3492025-03-18T16:48:51.967Z{"msg":"[2]R flush_numbers: [3996, 3996, 3996, 3996, 3996]","v":0,"name":"crucible","level":30,"time":"2025-03-18T16:48:51.75128137Z","hostname":"w-01JPN225S828YGR17Y0NASFSKX","pid":1242,"":"downstairs","":"downstairs","session_id":"def4a025-8efb-479e-bf63-68249a6959bc"}
3502025-03-18T16:48:51.967Z{"msg":"[2]R generation: [31, 31, 31, 31, 31]","v":0,"name":"crucible","level":30,"time":"2025-03-18T16:48:51.751294148Z","hostname":"w-01JPN225S828YGR17Y0NASFSKX","pid":1242,"":"downstairs","":"downstairs","session_id":"def4a025-8efb-479e-bf63-68249a6959bc"}
3512025-03-18T16:48:51.967Z{"msg":"[2]R dirty: [false, false, false, false, false]","v":0,"name":"crucible","level":30,"time":"2025-03-18T16:48:51.751307636Z","hostname":"w-01JPN225S828YGR17Y0NASFSKX","pid":1242,"":"downstairs","":"downstairs","session_id":"def4a025-8efb-479e-bf63-68249a6959bc"}
3522025-03-18T16:48:51.967Z{"msg":"Max found gen is 32","v":0,"name":"crucible","level":30,"time":"2025-03-18T16:48:51.751320244Z","hostname":"w-01JPN225S828YGR17Y0NASFSKX","pid":1242,"":"downstairs","":"downstairs","session_id":"def4a025-8efb-479e-bf63-68249a6959bc"}
3532025-03-18T16:48:51.967Z{"msg":"Generation requested: 32 >= found:32","v":0,"name":"crucible","level":30,"time":"2025-03-18T16:48:51.751340241Z","hostname":"w-01JPN225S828YGR17Y0NASFSKX","pid":1242,"":"downstairs","":"downstairs","session_id":"def4a025-8efb-479e-bf63-68249a6959bc"}
3542025-03-18T16:48:51.967Z{"msg":"Next flush: 3997","v":0,"name":"crucible","level":30,"time":"2025-03-18T16:48:51.751358848Z","hostname":"w-01JPN225S828YGR17Y0NASFSKX","pid":1242,"":"downstairs","":"downstairs","session_id":"def4a025-8efb-479e-bf63-68249a6959bc"}
3552025-03-18T16:48:51.967Z{"msg":"All extents match","v":0,"name":"crucible","level":30,"time":"2025-03-18T16:48:51.751393663Z","hostname":"w-01JPN225S828YGR17Y0NASFSKX","pid":1242,"":"downstairs","":"downstairs","session_id":"def4a025-8efb-479e-bf63-68249a6959bc"}
3562025-03-18T16:48:51.967Z{"msg":"No downstairs reconciliation required","v":0,"name":"crucible","level":30,"time":"2025-03-18T16:48:51.75141844Z","hostname":"w-01JPN225S828YGR17Y0NASFSKX","pid":1242,"session_id":"def4a025-8efb-479e-bf63-68249a6959bc"}
3572025-03-18T16:48:51.967Z{"msg":"Transition from WaitQuorum to Active","v":0,"name":"crucible","level":30,"time":"2025-03-18T16:48:51.751450935Z","hostname":"w-01JPN225S828YGR17Y0NASFSKX","pid":1242,"client":"0","":"downstairs","session_id":"def4a025-8efb-479e-bf63-68249a6959bc"}
3582025-03-18T16:48:51.967Z{"msg":"Transition from WaitQuorum to Active","v":0,"name":"crucible","level":30,"time":"2025-03-18T16:48:51.751477681Z","hostname":"w-01JPN225S828YGR17Y0NASFSKX","pid":1242,"client":"1","":"downstairs","session_id":"def4a025-8efb-479e-bf63-68249a6959bc"}
3592025-03-18T16:48:51.967Z{"msg":"Transition from WaitQuorum to Active","v":0,"name":"crucible","level":30,"time":"2025-03-18T16:48:51.751507826Z","hostname":"w-01JPN225S828YGR17Y0NASFSKX","pid":1242,"client":"2","":"downstairs","session_id":"def4a025-8efb-479e-bf63-68249a6959bc"}
3602025-03-18T16:48:51.967Z{"msg":"All required reconciliation work is completed","v":0,"name":"crucible","level":30,"time":"2025-03-18T16:48:51.751525534Z","hostname":"w-01JPN225S828YGR17Y0NASFSKX","pid":1242,"session_id":"def4a025-8efb-479e-bf63-68249a6959bc"}
3612025-03-18T16:48:51.967Z{"msg":"Set Downstairs and Upstairs active after reconciliation","v":0,"name":"crucible","level":30,"time":"2025-03-18T16:48:51.75154883Z","hostname":"w-01JPN225S828YGR17Y0NASFSKX","pid":1242,"session_id":"def4a025-8efb-479e-bf63-68249a6959bc"}
3622025-03-18T16:48:51.967Z{"msg":"2c535504-7ce7-4378-95e9-a2e694dd08c5 is now active with session: def4a025-8efb-479e-bf63-68249a6959bc","v":0,"name":"crucible","level":30,"time":"2025-03-18T16:48:51.751573837Z","hostname":"w-01JPN225S828YGR17Y0NASFSKX","pid":1242,"session_id":"def4a025-8efb-479e-bf63-68249a6959bc"}
3632025-03-18T16:48:51.967Z{"msg":"Set Active after no reconciliation","v":0,"name":"crucible","level":30,"time":"2025-03-18T16:48:51.751596873Z","hostname":"w-01JPN225S828YGR17Y0NASFSKX","pid":1242,"session_id":"def4a025-8efb-479e-bf63-68249a6959bc"}
3642025-03-18T16:48:51.967Z{"msg":"The guest has finished waiting for activation with:32","v":0,"name":"crucible","level":30,"time":"2025-03-18T16:48:51.751635627Z","hostname":"w-01JPN225S828YGR17Y0NASFSKX","pid":1242}
3652025-03-18T16:48:51.967Z{"msg":"Activated sub_volume 2c535504-7ce7-4378-95e9-a2e694dd08c5","v":0,"name":"crucible","level":30,"time":"2025-03-18T16:48:51.751795404Z","hostname":"w-01JPN225S828YGR17Y0NASFSKX","pid":1242}
3662025-03-18T16:48:51.967Z{"msg":"The guest has requested activation with gen:32","v":0,"name":"crucible","level":30,"time":"2025-03-18T16:48:51.751839887Z","hostname":"w-01JPN225S828YGR17Y0NASFSKX","pid":1242}
3672025-03-18T16:48:51.967Z{"msg":"2c535504-7ce7-4378-95e9-a2e694dd08c5 active request set","v":0,"name":"crucible","level":30,"time":"2025-03-18T16:48:51.751864054Z","hostname":"w-01JPN225S828YGR17Y0NASFSKX","pid":1242,"session_id":"a240abb9-f763-45ff-bf97-7b1834ac565c"}
3682025-03-18T16:48:51.967Z{"msg":"sending connect oneshot to client","v":0,"name":"crucible","level":30,"time":"2025-03-18T16:48:51.75189138Z","hostname":"w-01JPN225S828YGR17Y0NASFSKX","pid":1242,"client":"0","":"downstairs","session_id":"a240abb9-f763-45ff-bf97-7b1834ac565c"}
3692025-03-18T16:48:51.967Z{"msg":"client set_active_request while in Connecting { state: Start { auto_promote: true }, mode: New }; waiting...","v":0,"name":"crucible","level":30,"time":"2025-03-18T16:48:51.751921295Z","hostname":"w-01JPN225S828YGR17Y0NASFSKX","pid":1242,"client":"0","":"downstairs","session_id":"a240abb9-f763-45ff-bf97-7b1834ac565c"}
3702025-03-18T16:48:51.967Z{"msg":"sending connect oneshot to client","v":0,"name":"crucible","level":30,"time":"2025-03-18T16:48:51.751942242Z","hostname":"w-01JPN225S828YGR17Y0NASFSKX","pid":1242,"client":"1","":"downstairs","session_id":"a240abb9-f763-45ff-bf97-7b1834ac565c"}
3712025-03-18T16:48:51.967Z{"msg":"client set_active_request while in Connecting { state: Start { auto_promote: true }, mode: New }; waiting...","v":0,"name":"crucible","level":30,"time":"2025-03-18T16:48:51.751979007Z","hostname":"w-01JPN225S828YGR17Y0NASFSKX","pid":1242,"client":"1","":"downstairs","session_id":"a240abb9-f763-45ff-bf97-7b1834ac565c"}
3722025-03-18T16:48:51.967Z{"msg":"sending connect oneshot to client","v":0,"name":"crucible","level":30,"time":"2025-03-18T16:48:51.752010772Z","hostname":"w-01JPN225S828YGR17Y0NASFSKX","pid":1242,"client":"2","":"downstairs","session_id":"a240abb9-f763-45ff-bf97-7b1834ac565c"}
3732025-03-18T16:48:51.967Z{"msg":"client set_active_request while in Connecting { state: Start { auto_promote: true }, mode: New }; waiting...","v":0,"name":"crucible","level":30,"time":"2025-03-18T16:48:51.752032119Z","hostname":"w-01JPN225S828YGR17Y0NASFSKX","pid":1242,"client":"2","":"downstairs","session_id":"a240abb9-f763-45ff-bf97-7b1834ac565c"}
3742025-03-18T16:48:51.968Z{"msg":"connecting to 127.0.0.1:8860","v":0,"name":"crucible","level":30,"time":"2025-03-18T16:48:51.752045847Z","hostname":"w-01JPN225S828YGR17Y0NASFSKX","pid":1242,"":"io task","client":"2","":"downstairs","session_id":"a240abb9-f763-45ff-bf97-7b1834ac565c"}
3752025-03-18T16:48:51.968Z{"msg":"connecting to 127.0.0.1:8840","v":0,"name":"crucible","level":30,"time":"2025-03-18T16:48:51.752071043Z","hostname":"w-01JPN225S828YGR17Y0NASFSKX","pid":1242,"":"io task","client":"0","":"downstairs","session_id":"a240abb9-f763-45ff-bf97-7b1834ac565c"}
3762025-03-18T16:48:51.968Z{"msg":"connecting to 127.0.0.1:8850","v":0,"name":"crucible","level":30,"time":"2025-03-18T16:48:51.752116097Z","hostname":"w-01JPN225S828YGR17Y0NASFSKX","pid":1242,"":"io task","client":"1","":"downstairs","session_id":"a240abb9-f763-45ff-bf97-7b1834ac565c"}
3772025-03-18T16:48:51.968Z{"msg":"ds_connection connected from Ok(127.0.0.1:51308)","v":0,"name":"crucible","level":30,"time":"2025-03-18T16:48:51.752150341Z","hostname":"w-01JPN225S828YGR17Y0NASFSKX","pid":1242,"":"io task","client":"0","":"downstairs","session_id":"a240abb9-f763-45ff-bf97-7b1834ac565c"}
3782025-03-18T16:48:51.968Z{"msg":"ds_connection connected from Ok(127.0.0.1:41480)","v":0,"name":"crucible","level":30,"time":"2025-03-18T16:48:51.752179927Z","hostname":"w-01JPN225S828YGR17Y0NASFSKX","pid":1242,"":"io task","client":"2","":"downstairs","session_id":"a240abb9-f763-45ff-bf97-7b1834ac565c"}
3792025-03-18T16:48:51.968Z{"msg":"ds_connection connected from Ok(127.0.0.1:59850)","v":0,"name":"crucible","level":30,"time":"2025-03-18T16:48:51.752222481Z","hostname":"w-01JPN225S828YGR17Y0NASFSKX","pid":1242,"":"io task","client":"1","":"downstairs","session_id":"a240abb9-f763-45ff-bf97-7b1834ac565c"}
3802025-03-18T16:48:51.968Z{"msg":"version negotiation from state Connecting { state: WaitForPromote, mode: New }","v":0,"name":"crucible","level":30,"time":"2025-03-18T16:48:51.752265444Z","hostname":"w-01JPN225S828YGR17Y0NASFSKX","pid":1242,"client":"0","":"downstairs","session_id":"a240abb9-f763-45ff-bf97-7b1834ac565c"}
3812025-03-18T16:48:51.968Z{"msg":"version negotiation from state Connecting { state: WaitForPromote, mode: New }","v":0,"name":"crucible","level":30,"time":"2025-03-18T16:48:51.752307568Z","hostname":"w-01JPN225S828YGR17Y0NASFSKX","pid":1242,"client":"2","":"downstairs","session_id":"a240abb9-f763-45ff-bf97-7b1834ac565c"}
3822025-03-18T16:48:51.968Z{"msg":"version negotiation from state Connecting { state: WaitForPromote, mode: New }","v":0,"name":"crucible","level":30,"time":"2025-03-18T16:48:51.752342193Z","hostname":"w-01JPN225S828YGR17Y0NASFSKX","pid":1242,"client":"1","":"downstairs","session_id":"a240abb9-f763-45ff-bf97-7b1834ac565c"}
3832025-03-18T16:48:51.968Z{"msg":"downstairs client at Some(127.0.0.1:8840) has region UUID 12345678-0000-0000-0000-000000008840","v":0,"name":"crucible","level":30,"time":"2025-03-18T16:48:51.752639469Z","hostname":"w-01JPN225S828YGR17Y0NASFSKX","pid":1242,"client":"0","":"downstairs","session_id":"a240abb9-f763-45ff-bf97-7b1834ac565c"}
3842025-03-18T16:48:51.968Z{"msg":"downstairs client at Some(127.0.0.1:8860) has region UUID 12345678-0000-0000-0000-000000008860","v":0,"name":"crucible","level":30,"time":"2025-03-18T16:48:51.752902681Z","hostname":"w-01JPN225S828YGR17Y0NASFSKX","pid":1242,"client":"2","":"downstairs","session_id":"a240abb9-f763-45ff-bf97-7b1834ac565c"}
3852025-03-18T16:48:51.968Z{"msg":"Waiting for more clients to be ready","v":0,"name":"crucible","level":30,"time":"2025-03-18T16:48:51.752961522Z","hostname":"w-01JPN225S828YGR17Y0NASFSKX","pid":1242,"session_id":"a240abb9-f763-45ff-bf97-7b1834ac565c"}
3862025-03-18T16:48:51.968Z{"msg":"downstairs client at Some(127.0.0.1:8850) has region UUID 12345678-0000-0000-0000-000000008850","v":0,"name":"crucible","level":30,"time":"2025-03-18T16:48:51.753030362Z","hostname":"w-01JPN225S828YGR17Y0NASFSKX","pid":1242,"client":"1","":"downstairs","session_id":"a240abb9-f763-45ff-bf97-7b1834ac565c"}
3872025-03-18T16:48:51.968Z{"msg":"Waiting for more clients to be ready","v":0,"name":"crucible","level":30,"time":"2025-03-18T16:48:51.753160103Z","hostname":"w-01JPN225S828YGR17Y0NASFSKX","pid":1242,"session_id":"a240abb9-f763-45ff-bf97-7b1834ac565c"}
3882025-03-18T16:48:51.968Z{"msg":"[0]R flush_numbers: [5317, 5317, 5317, 5317, 5317]","v":0,"name":"crucible","level":30,"time":"2025-03-18T16:48:51.753339256Z","hostname":"w-01JPN225S828YGR17Y0NASFSKX","pid":1242,"":"downstairs","":"downstairs","session_id":"a240abb9-f763-45ff-bf97-7b1834ac565c"}
3892025-03-18T16:48:51.968Z{"msg":"[0]R generation: [31, 31, 31, 31, 31]","v":0,"name":"crucible","level":30,"time":"2025-03-18T16:48:51.753369262Z","hostname":"w-01JPN225S828YGR17Y0NASFSKX","pid":1242,"":"downstairs","":"downstairs","session_id":"a240abb9-f763-45ff-bf97-7b1834ac565c"}
3902025-03-18T16:48:51.968Z{"msg":"[0]R dirty: [false, false, false, false, false]","v":0,"name":"crucible","level":30,"time":"2025-03-18T16:48:51.753384849Z","hostname":"w-01JPN225S828YGR17Y0NASFSKX","pid":1242,"":"downstairs","":"downstairs","session_id":"a240abb9-f763-45ff-bf97-7b1834ac565c"}
3912025-03-18T16:48:51.968Z{"msg":"[1]R flush_numbers: [5317, 5317, 5317, 5317, 5317]","v":0,"name":"crucible","level":30,"time":"2025-03-18T16:48:51.753416405Z","hostname":"w-01JPN225S828YGR17Y0NASFSKX","pid":1242,"":"downstairs","":"downstairs","session_id":"a240abb9-f763-45ff-bf97-7b1834ac565c"}
3922025-03-18T16:48:51.968Z{"msg":"[1]R generation: [31, 31, 31, 31, 31]","v":0,"name":"crucible","level":30,"time":"2025-03-18T16:48:51.753453829Z","hostname":"w-01JPN225S828YGR17Y0NASFSKX","pid":1242,"":"downstairs","":"downstairs","session_id":"a240abb9-f763-45ff-bf97-7b1834ac565c"}
3932025-03-18T16:48:51.968Z{"msg":"[1]R dirty: [false, false, false, false, false]","v":0,"name":"crucible","level":30,"time":"2025-03-18T16:48:51.753491124Z","hostname":"w-01JPN225S828YGR17Y0NASFSKX","pid":1242,"":"downstairs","":"downstairs","session_id":"Wait for a query_work_queue command to finish before sending IO
3942025-03-18T16:48:51.968Za240abb9-f763-45ff-bf97-7b1834ac565c"}
3952025-03-18T16:48:51.968Z{"msg":"[2]R flush_numbers: [5317, 5317, 5317, 5317, 5317]","v":0,"name":"crucible","level":30,"time":"2025-03-18T16:48:51.753549345Z","hostname":"w-01JPN225S828YGR17Y0NASFSKX","pid":1242,"":"downstairs","":"downstairs","session_id":"a240abb9-f763-45ff-bf97-7b1834ac565c"}
3962025-03-18T16:48:51.968Z{"msg":"[2]R generation: [31, 31, 31, 31, 31]","v":0,"name":"crucible","level":30,"time":"2025-03-18T16:48:51.753574901Z","hostname":"w-01JPN225S828YGR17Y0NASFSKX","pid":1242,"":"downstairs","":"downstairs","session_id":"a240abb9-f763-45ff-bf97-7b1834ac565c"}
3972025-03-18T16:48:51.968Z{"msg":"[2]R dirty: [false, false, false, false, false]","v":0,"name":"crucible","level":30,"time":"2025-03-18T16:48:51.753609256Z","hostname":"w-01JPN225S828YGR17Y0NASFSKX","pid":1242,"":"downstairs","":"downstairs","session_id":"a240abb9-f763-45ff-bf97-7b1834ac565c"}
3982025-03-18T16:48:51.968Z{"msg":"Max found gen is 32","v":0,"name":"crucible","level":30,"time":"2025-03-18T16:48:51.753645581Z","hostname":"w-01JPN225S828YGR17Y0NASFSKX","pid":1242,"":"downstairs","":"downstairs","session_id":"a240abb9-f763-45ff-bf97-7b1834ac565c"}
3992025-03-18T16:48:51.968Z{"msg":"Generation requested: 32 >= found:32","v":0,"name":"crucible","level":30,"time":"2025-03-18T16:48:51.753684775Z","hostname":"w-01JPN225S828YGR17Y0NASFSKX","pid":1242,"":"downstairs","":"downstairs","session_id":"a240abb9-f763-45ff-bf97-7b1834ac565c"}
4002025-03-18T16:48:51.968Z{"msg":"Next flush: 5318","v":0,"name":"crucible","level":30,"time":"2025-03-18T16:48:51.753712821Z","hostname":"w-01JPN225S828YGR17Y0NASFSKX","pid":1242,"":"downstairs","":"downstairs","session_id":"a240abb9-f763-45ff-bf97-7b1834ac565c"}
4012025-03-18T16:48:51.968Z{"msg":"All extents match","v":0,"name":"crucible","level":30,"time":"2025-03-18T16:48:51.753749816Z","hostname":"w-01JPN225S828YGR17Y0NASFSKX","pid":1242,"":"downstairs","":"downstairs","session_id":"a240abb9-f763-45ff-bf97-7b1834ac565c"}
4022025-03-18T16:48:51.968Z{"msg":"No downstairs reconciliation required","v":0,"name":"crucible","level":30,"time":"2025-03-18T16:48:51.75378681Z","hostname":"w-01JPN225S828YGR17Y0NASFSKX","pid":1242,"session_id":"a240abb9-f763-45ff-bf97-7b1834ac565c"}
4032025-03-18T16:48:51.968Z{"msg":"Transition from WaitQuorum to Active","v":0,"name":"crucible","level":30,"time":"2025-03-18T16:48:51.753812476Z","hostname":"w-01JPN225S828YGR17Y0NASFSKX","pid":1242,"client":"0","":"downstairs","session_id":"a240abb9-f763-45ff-bf97-7b1834ac565c"}
4042025-03-18T16:48:51.972Z{"msg":"Transition from WaitQuorum to Active","v":0,"name":"crucible","level":30,"time":"2025-03-18T16:48:51.753838542Z","hostname":"w-01JPN225S828YGR17Y0NASFSKX","pid":1242,"client":"1","":"downstairs","session_id":"a240abb9-f763-45ff-bf97-7b1834ac565c"}
4052025-03-18T16:48:51.972Z{"msg":"Transition from WaitQuorum to Active","v":0,"name":"crucible","level":30,"time":"2025-03-18T16:48:51.753874347Z","hostname":"w-01JPN225S828YGR17Y0NASFSKX","pid":1242,"client":"2","":"downstairs","session_id":"a240abb9-f763-45ff-bf97-7b1834ac565c"}
4062025-03-18T16:48:51.972Z{"msg":"All required reconciliation work is completed","v":0,"name":"crucible","level":30,"time":"2025-03-18T16:48:51.753889895Z","hostname":"w-01JPN225S828YGR17Y0NASFSKX","pid":1242,"session_id":"a240abb9-f763-45ff-bf97-7b1834ac565c"}
4072025-03-18T16:48:51.972Z{"msg":"Set Downstairs and Upstairs active after reconciliation","v":0,"name":"crucible","level":30,"time":"2025-03-18T16:48:51.753901883Z","hostname":"w-01JPN225S828YGR17Y0NASFSKX","pid":1242,"session_id":"a240abb9-f763-45ff-bf97-7b1834ac565c"}
4082025-03-18T16:48:51.972Z{"msg":"2c535504-7ce7-4378-95e9-a2e694dd08c5 is now active with session: a240abb9-f763-45ff-bf97-7b1834ac565c","v":0,"name":"crucible","level":30,"time":"2025-03-18T16:48:51.753915031Z","hostname":"w-01JPN225S828YGR17Y0NASFSKX","pid":1242,"session_id":"a240abb9-f763-45ff-bf97-7b1834ac565c"}
4092025-03-18T16:48:51.972Z{"msg":"Set Active after no reconciliation","v":0,"name":"crucible","level":30,"time":"2025-03-18T16:48:51.753926629Z","hostname":"w-01JPN225S828YGR17Y0NASFSKX","pid":1242,"session_id":"a240abb9-f763-45ff-bf97-7b1834ac565c"}
4102025-03-18T16:48:51.972Z{"msg":"The guest has finished waiting for activation with:32","v":0,"name":"crucible","level":30,"time":"2025-03-18T16:48:51.753954975Z","hostname":"w-01JPN225S828YGR17Y0NASFSKX","pid":1242}
4112025-03-18T16:48:51.972Z{"msg":"Activated sub_volume 2c535504-7ce7-4378-95e9-a2e694dd08c5","v":0,"Disk: sv:2 bs:4096 ts:409600 tb:100 max_io:100 or 409600
4122025-03-18T16:48:51.972Zname":"crucible","level":30,"time":"2025-03-18T16:48:51.75398865Z","hostname":"w-01JPN225S828YGR17Y0NASFSKX","pid":1242}
4132025-03-18T16:48:51.972ZLoading write count information from file "/var/tmp/test_up-build/verify_file"
4142025-03-18T16:48:51.972ZFill test
4152025-03-18T16:48:52.009ZRead and Verify all blocks (0..100 range:false)
4162025-03-18T16:48:52.091ZWrote out file "/var/tmp/test_up-build/verify_file"
4172025-03-18T16:48:52.091ZCLIENT: Tests done. All submitted work has been ACK'd
4182025-03-18T16:48:52.094Z----------------------------------------------------------------
4192025-03-18T16:48:52.094Z Crucible gen:32 GIO:true work queues: Upstairs:0 downstairs:1
4202025-03-18T16:48:52.094ZStates: Active Active Active
4212025-03-18T16:48:52.094ZJOBID ACK TYPE BKS/EXT DS:0 DS:1 DS:2 REPLAY
4222025-03-18T16:48:52.095Z 1002 Acked Read 50 Done Done Done false
4232025-03-18T16:48:52.095Z STATES DS:0 DS:1 DS:2 TOTAL
4242025-03-18T16:48:52.095Z Sent 0 0 0 0
4252025-03-18T16:48:52.095Z Done 1 1 1 3
4262025-03-18T16:48:52.095Z Skipped 0 0 0 0
4272025-03-18T16:48:52.095Z Error 0 0 0 0
4282025-03-18T16:48:52.095ZLast Flush: Some(JobId(1001)) Some(JobId(1001)) Some(JobId(1001))
4292025-03-18T16:48:52.095ZDownstairs last five completed: 1001 1000
4302025-03-18T16:48:52.095ZUpstairs last five completed: 1002 1001 1000
4312025-03-18T16:48:52.095Z----------------------------------------------------------------
4322025-03-18T16:48:52.095Z Crucible gen:32 GIO:true work queues: Upstairs:0 downstairs:1
4332025-03-18T16:48:52.095ZStates: Active Active Active
4342025-03-18T16:48:52.095ZJOBID ACK TYPE BKS/EXT DS:0 DS:1 DS:2 REPLAY
4352025-03-18T16:48:52.095Z 1002 Acked Read 50 Done Done Done false
4362025-03-18T16:48:52.095Z STATES DS:0 DS:1 DS:2 TOTAL
4372025-03-18T16:48:52.095Z Sent 0 0 0 0
4382025-03-18T16:48:52.095Z Done 1 1 1 3
4392025-03-18T16:48:52.095Z Skipped 0 0 0 0
4402025-03-18T16:48:52.095Z Error 0 0 0 0
4412025-03-18T16:48:52.095ZLast Flush: Some(JobId(1001)) Some(JobId(1001)) Some(JobId(1001))
4422025-03-18T16:48:52.095ZDownstairs last five completed: 1001 1000
4432025-03-18T16:48:52.095ZUpstairs last five completed: 1002 1001 1000
4442025-03-18T16:48:52.095ZCLIENT: Up:0 ds:2 act:6
4452025-03-18T16:48:56.099Z----------------------------------------------------------------
4462025-03-18T16:48:56.099Z Crucible gen:32 GIO:true work queues: Upstairs:0 downstairs:0
4472025-03-18T16:48:56.099ZDownstairs last five completed: 1003 1002 1001 1000
4482025-03-18T16:48:56.100ZUpstairs last five completed: 1003 1002 1001 1000
4492025-03-18T16:48:56.100Z----------------------------------------------------------------
4502025-03-18T16:48:56.100Z Crucible gen:32 GIO:true work queues: Upstairs:0 downstairs:0
4512025-03-18T16:48:56.100ZDownstairs last five completed: 1003 1002 1001 1000
4522025-03-18T16:48:56.100ZUpstairs last five completed: 1003 1002 1001 1000
4532025-03-18T16:48:56.100ZCLIENT: Up:0 ds:0 act:6
4542025-03-18T16:48:56.100ZCLIENT: All crucible jobs finished, exiting program
4552025-03-18T16:48:56.103ZRepair part 1 passed
4562025-03-18T16:48:56.103Z
4572025-03-18T16:48:56.103ZKill the current downstairs
4582025-03-18T16:48:56.262ZDownstairs 2 stopped
4592025-03-18T16:48:56.262Zmv /var/tmp/test_up-build/8830 /var/tmp/test_up-build/new
4602025-03-18T16:48:56.265ZNow put back the original so we have a mismatch
4612025-03-18T16:48:56.265Zmv /var/tmp/test_up-build/previous /var/tmp/test_up-build/8830
4622025-03-18T16:48:56.269ZRestart downstairs with old directory
4632025-03-18T16:48:56.318Z/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
4642025-03-18T16:48:56.334ZEXT BLOCKS GEN0 GEN1 GEN2 FL0 FL1 FL2 D0 D1 D2 DIFF
4652025-03-18T16:48:56.338Z 0 000-009 32 32 31 3997 3997 3996 F F F <---
4662025-03-18T16:48:56.338Z 1 010-019 32 32 31 3997 3997 3996 F F F <---
4672025-03-18T16:48:56.338Z 2 020-029 32 32 31 3997 3997 3996 F F F <---
4682025-03-18T16:48:56.338Z 3 030-039 32 32 31 3997 3997 3996 F F F <---
4692025-03-18T16:48:56.338Z 4 040-049 32 32 31 3997 3997 3996 F F F <---
4702025-03-18T16:48:56.338ZMax gen: 32, Max flush: 3997
4712025-03-18T16:48:56.338ZError: Difference in extent metadata found!
4722025-03-18T16:48:56.341Zdump test found error as expected
4732025-03-18T16:48:56.341Z
4742025-03-18T16:48:56.341Z
4752025-03-18T16:48:56.341Z/var/tmp/bins/crutest verify --range -g 33 -q --key B3P3gZ9tJ5vWD72EjbZTFM1kuPb0n3pWl29LAKfzNeo= --dsc 127.0.0.1:9998 --verify-out /var/tmp/test_up-build/verify_file --verify-in /var/tmp/test_up-build/verify_file
4762025-03-18T16:48:56.396Z{"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":"2025-03-18T16:48:56.182052526Z","hostname":"w-01JPN225S828YGR17Y0NASFSKX","pid":1250,"task":"crutest"}
4772025-03-18T16:48:56.400Z{"msg":"dsc has 6 regions. This means 2 sub_volumes","v":0,"name":"crucible","level":30,"time":"2025-03-18T16:48:56.182557101Z","hostname":"w-01JPN225S828YGR17Y0NASFSKX","pid":1250,"task":"crutest"}
4782025-03-18T16:48:56.400Z{"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":"2025-03-18T16:48:56.184218516Z","hostname":"w-01JPN225S828YGR17Y0NASFSKX","pid":1250,"task":"crutest"}
4792025-03-18T16:48:56.400Z{"msg":"Upstairs starts","v":0,"name":"crucible","level":30,"time":"2025-03-18T16:48:56.18439089Z","hostname":"w-01JPN225S828YGR17Y0NASFSKX","pid":1250}
4802025-03-18T16:48:56.400Z{"msg":"Crucible Version: BuildInfo {\n version: \"0.0.1\",\n git_sha: \"e56b83235918dca6f00b1bca17876ae8794868bc\",\n git_commit_timestamp: \"2025-03-18T04:42:45.000000000Z\",\n git_branch: \"renovate/chrono-0.x-lockfile\",\n rustc_semver: \"1.84.0\",\n rustc_channel: \"stable\",\n rustc_host_triple: \"x86_64-unknown-illumos\",\n rustc_commit_sha: \"9fc6b43126469e3858e2fe86cafb4f0fd5068869\",\n cargo_triple: \"x86_64-unknown-illumos\",\n debug: true,\n opt_level: 0,\n}","v":0,"name":"crucible","level":30,"time":"2025-03-18T16:48:56.184436774Z","hostname":"w-01JPN225S828YGR17Y0NASFSKX","pid":1250}
4812025-03-18T16:48:56.400Z{"msg":"Upstairs <-> Downstairs Message Version: 13","v":0,"name":"crucible","level":30,"time":"2025-03-18T16:48:56.18446066Z","hostname":"w-01JPN225S828YGR17Y0NASFSKX","pid":1250}
4822025-03-18T16:48:56.400Z{"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":"2025-03-18T16:48:56.184475858Z","hostname":"w-01JPN225S828YGR17Y0NASFSKX","pid":1250}
4832025-03-18T16:48:56.400Z{"msg":"Crucible 494e31c0-b4be-42bc-a828-5b60e5bccc79 has session id: 3478a266-f65d-4705-a31a-be8124ecdad2","v":0,"name":"crucible","level":30,"time":"2025-03-18T16:48:56.185022547Z","hostname":"w-01JPN225S828YGR17Y0NASFSKX","pid":1250,"session_id":"3478a266-f65d-4705-a31a-be8124ecdad2"}
4842025-03-18T16:48:56.400Z{"msg":"Upstairs opts: Upstairs UUID: 494e31c0-b4be-42bc-a828-5b60e5bccc79, 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":"2025-03-18T16:48:56.185085368Z","hostname":"w-01JPN225S828YGR17Y0NASFSKX","pid":1250,"session_id":"3478a266-f65d-4705-a31a-be8124ecdad2"}
4852025-03-18T16:48:56.400Z{"msg":"Crucible stats registered with UUID: 494e31c0-b4be-42bc-a828-5b60e5bccc79","v":0,"name":"crucible","level":30,"time":"2025-03-18T16:48:56.185116743Z","hostname":"w-01JPN225S828YGR17Y0NASFSKX","pid":1250,"session_id":"3478a266-f65d-4705-a31a-be8124ecdad2"}
4862025-03-18T16:48:56.400Z{"msg":"could not find Downstairs address for Nexus","v":0,"name":"crucible","level":40,"time":"2025-03-18T16:48:56.185155998Z","hostname":"w-01JPN225S828YGR17Y0NASFSKX","pid":1250,"session_id":"3478a266-f65d-4705-a31a-be8124ecdad2"}
4872025-03-18T16:48:56.400Z{"msg":"SV 1 has targets: [127.0.0.1:8840, 127.0.0.1:8850, 127.0.0.1:8860]","v":0,"name":"crucible","level":30,"time":"2025-03-18T16:48:56.187090972Z","hostname":"w-01JPN225S828YGR17Y0NASFSKX","pid":1250,"task":"crutest"}
4882025-03-18T16:48:56.400Z{"msg":"Upstairs starts","v":0,"name":"crucible","level":30,"time":"2025-03-18T16:48:56.18717371Z","hostname":"w-01JPN225S828YGR17Y0NASFSKX","pid":1250}
4892025-03-18T16:48:56.400Z{"msg":"Crucible Version: BuildInfo {\n version: \"0.0.1\",\n git_sha: \"e56b83235918dca6f00b1bca17876ae8794868bc\",\n git_commit_timestamp: \"2025-03-18T04:42:45.000000000Z\",\n git_branch: \"renovate/chrono-0.x-lockfile\",\n rustc_semver: \"1.84.0\",\n rustc_channel: \"stable\",\n rustc_host_triple: \"x86_64-unknown-illumos\",\n rustc_commit_sha: \"9fc6b43126469e3858e2fe86cafb4f0fd5068869\",\n cargo_triple: \"x86_64-unknown-illumos\",\n debug: true,\n opt_level: 0,\n}","v":0,"name":"crucible","level":30,"time":"2025-03-18T16:48:56.187227652Z","hostname":"w-01JPN225S828YGR17Y0NASFSKX","pid":1250}
4902025-03-18T16:48:56.400Z{"msg":"Upstairs <-> Downstairs Message Version: 13","v":0,"name":"crucible","level":30,"time":"2025-03-18T16:48:56.187258047Z","hostname":"w-01JPN225S828YGR17Y0NASFSKX","pid":1250}
4912025-03-18T16:48:56.401Z{"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":"2025-03-18T16:48:56.187282984Z","hostname":"w-01JPN225S828YGR17Y0NASFSKX","pid":1250}
4922025-03-18T16:48:56.401Z{"msg":"Crucible 494e31c0-b4be-42bc-a828-5b60e5bccc79 has session id: 7139e958-9773-46ef-930a-4efe5e369499","v":0,"name":"crucible","level":30,"time":"2025-03-18T16:48:56.187583699Z","hostname":"w-01JPN225S828YGR17Y0NASFSKX","pid":1250,"session_id":"7139e958-9773-46ef-930a-4efe5e369499"}
4932025-03-18T16:48:56.401Z{"msg":"Upstairs opts: Upstairs UUID: 494e31c0-b4be-42bc-a828-5b60e5bccc79, Targets: [127.0.0.1:8840, 127.0.0.1:8850, 127.0.0.1:8860], 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":"2025-03-18T16:48:56.187634332Z","hostname":"w-01JPN225S828YGR17Y0NASFSKX","pid":1250,"session_id":"7139e958-9773-46ef-930a-4efe5e369499"}
4942025-03-18T16:48:56.401Z{"msg":"Crucible stats registered with UUID: 494e31c0-b4be-42bc-a828-5b60e5bccc79","v":0,"name":"crucible","level":30,"time":"2025-03-18T16:48:56.187672566Z","hostname":"w-01JPN225S828YGR17Y0NASFSKX","pid":1250,"session_id":"7139e958-9773-46ef-930a-4efe5e369499"}
4952025-03-18T16:48:56.401Z{"msg":"could not find Downstairs address for Nexus","v":0,"name":"crucible","level":40,"time":"2025-03-18T16:48:56.187707191Z","hostname":"w-01JPN225S828YGR17Y0NASFSKX","pid":1250,"session_id":"7139e958-9773-46ef-930a-4efe5e369499"}
4962025-03-18T16:48:56.409Z{"msg":"Downstairs in volume = 6","v":0,"name":"crucible","level":30,"time":"2025-03-18T16:48:56.188337578Z","hostname":"w-01JPN225S828YGR17Y0NASFSKX","pid":1250,"task":"crutest"}
4972025-03-18T16:48:56.409Z{"msg":"The guest has requested activation with gen:33","v":0,"name":"crucible","level":30,"time":"2025-03-18T16:48:56.188386471Z","hostname":"w-01JPN225S828YGR17Y0NASFSKX","pid":1250}
4982025-03-18T16:48:56.409Z{"msg":"494e31c0-b4be-42bc-a828-5b60e5bccc79 active request set","v":0,"name":"crucible","level":30,"time":"2025-03-18T16:48:56.188418516Z","hostname":"w-01JPN225S828YGR17Y0NASFSKX","pid":1250,"session_id":"3478a266-f65d-4705-a31a-be8124ecdad2"}
4992025-03-18T16:48:56.409Z{"msg":"sending connect oneshot to client","v":0,"name":"crucible","level":30,"time":"2025-03-18T16:48:56.188454201Z","hostname":"w-01JPN225S828YGR17Y0NASFSKX","pid":1250,"client":"0","":"downstairs","session_id":"3478a266-f65d-4705-a31a-be8124ecdad2"}
5002025-03-18T16:48:56.409Z{"msg":"client set_active_request while in Connecting { state: Start { auto_promote: true }, mode: New }; waiting...","v":0,"name":"crucible","level":30,"time":"2025-03-18T16:48:56.188510973Z","hostname":"w-01JPN225S828YGR17Y0NASFSKX","pid":1250,"client":"0","":"downstairs","session_id":"3478a266-f65d-4705-a31a-be8124ecdad2"}
5012025-03-18T16:48:56.409Z{"msg":"sending connect oneshot to client","v":0,"name":"crucible","level":30,"time":"2025-03-18T16:48:56.188552876Z","hostname":"w-01JPN225S828YGR17Y0NASFSKX","pid":1250,"client":"1","":"downstairs","session_id":"3478a266-f65d-4705-a31a-be8124ecdad2"}
5022025-03-18T16:48:56.409Z{"msg":"client set_active_request while in Connecting { state: Start { auto_promote: true }, mode: New }; waiting...","v":0,"name":"crucible","level":30,"time":"2025-03-18T16:48:56.188581852Z","hostname":"w-01JPN225S828YGR17Y0NASFSKX","pid":1250,"client":"1","":"downstairs","session_id":"3478a266-f65d-4705-a31a-be8124ecdad2"}
5032025-03-18T16:48:56.409Z{"msg":"sending connect oneshot to client","v":0,"name":"crucible","level":30,"time":"2025-03-18T16:48:56.188616177Z","hostname":"w-01JPN225S828YGR17Y0NASFSKX","pid":1250,"client":"2","":"downstairs","session_id":"3478a266-f65d-4705-a31a-be8124ecdad2"}
5042025-03-18T16:48:56.409Z{"msg":"client set_active_request while in Connecting { state: Start { auto_promote: true }, mode: New }; waiting...","v":0,"name":"crucible","level":30,"time":"2025-03-18T16:48:56.188642673Z","hostname":"w-01JPN225S828YGR17Y0NASFSKX","pid":1250,"client":"2","":"downstairs","session_id":"3478a266-f65d-4705-a31a-be8124ecdad2"}
5052025-03-18T16:48:56.409Z{"msg":"connecting to 127.0.0.1:8830","v":0,"name":"crucible","level":30,"time":"2025-03-18T16:48:56.1886643Z","hostname":"w-01JPN225S828YGR17Y0NASFSKX","pid":1250,"":"io task","client":"2","":"downstairs","session_id":"3478a266-f65d-4705-a31a-be8124ecdad2"}
5062025-03-18T16:48:56.409Z{"msg":"connecting to 127.0.0.1:8810","v":0,"name":"crucible","level":30,"time":"2025-03-18T16:48:56.188699095Z","hostname":"w-01JPN225S828YGR17Y0NASFSKX","pid":1250,"":"io task","client":"0","":"downstairs","session_id":"3478a266-f65d-4705-a31a-be8124ecdad2"}
5072025-03-18T16:48:56.409Z{"msg":"connecting to 127.0.0.1:8820","v":0,"name":"crucible","level":30,"time":"2025-03-18T16:48:56.188741129Z","hostname":"w-01JPN225S828YGR17Y0NASFSKX","pid":1250,"":"io task","client":"1","":"downstairs","session_id":"3478a266-f65d-4705-a31a-be8124ecdad2"}
5082025-03-18T16:48:56.409Z{"msg":"ds_connection connected from Ok(127.0.0.1:59836)","v":0,"name":"crucible","level":30,"time":"2025-03-18T16:48:56.188770764Z","hostname":"w-01JPN225S828YGR17Y0NASFSKX","pid":1250,"":"io task","client":"0","":"downstairs","session_id":"3478a266-f65d-4705-a31a-be8124ecdad2"}
5092025-03-18T16:48:56.409Z{"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":"2025-03-18T16:48:56.18879739Z","hostname":"w-01JPN225S828YGR17Y0NASFSKX","pid":1250,"":"io task","client":"2","":"downstairs","session_id":"3478a266-f65d-4705-a31a-be8124ecdad2"}
5102025-03-18T16:48:56.409Z{"msg":"ds_connection connected from Ok(127.0.0.1:64192)","v":0,"name":"crucible","level":30,"time":"2025-03-18T16:48:56.188821537Z","hostname":"w-01JPN225S828YGR17Y0NASFSKX","pid":1250,"":"io task","client":"1","":"downstairs","session_id":"3478a266-f65d-4705-a31a-be8124ecdad2"}
5112025-03-18T16:48:56.409Z{"msg":"client task is sending Done(ConnectionFailed(Os { code: 146, kind: ConnectionRefused, message: \"Connection refused\" }))","v":0,"name":"crucible","level":40,"time":"2025-03-18T16:48:56.188924802Z","hostname":"w-01JPN225S828YGR17Y0NASFSKX","pid":1250,"":"io task","client":"2","":"downstairs","session_id":"3478a266-f65d-4705-a31a-be8124ecdad2"}
5122025-03-18T16:48:56.409Z{"msg":"downstairs task for 2 stopped due to ConnectionFailed(Os { code: 146, kind: ConnectionRefused, message: \"Connection refused\" })","v":0,"name":"crucible","level":40,"time":"2025-03-18T16:48:56.188949538Z","hostname":"w-01JPN225S828YGR17Y0NASFSKX","pid":1250,"session_id":"3478a266-f65d-4705-a31a-be8124ecdad2"}
5132025-03-18T16:48:56.409Z{"msg":"client task is exiting","v":0,"name":"crucible","level":30,"time":"2025-03-18T16:48:56.188979304Z","hostname":"w-01JPN225S828YGR17Y0NASFSKX","pid":1250,"":"io task","client":"2","":"downstairs","session_id":"3478a266-f65d-4705-a31a-be8124ecdad2"}
5142025-03-18T16:48:56.409Z{"msg":"version negotiation from state Connecting { state: WaitForPromote, mode: New }","v":0,"name":"crucible","level":30,"time":"2025-03-18T16:48:56.189473541Z","hostname":"w-01JPN225S828YGR17Y0NASFSKX","pid":1250,"client":"1","":"downstairs","session_id":"3478a266-f65d-4705-a31a-be8124ecdad2"}
5152025-03-18T16:48:56.409Z{"msg":"version negotiation from state Connecting { state: WaitForPromote, mode: New }","v":0,"name":"crucible","level":30,"time":"2025-03-18T16:48:56.189517654Z","hostname":"w-01JPN225S828YGR17Y0NASFSKX","pid":1250,"client":"0","":"downstairs","session_id":"3478a266-f65d-4705-a31a-be8124ecdad2"}
5162025-03-18T16:48:56.409Z{"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":"2025-03-18T16:48:56.190016211Z","hostname":"w-01JPN225S828YGR17Y0NASFSKX","pid":1250,"client":"0","":"downstairs","session_id":"3478a266-f65d-4705-a31a-be8124ecdad2"}
5172025-03-18T16:48:56.409Z{"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":"2025-03-18T16:48:56.190110947Z","hostname":"w-01JPN225S828YGR17Y0NASFSKX","pid":1250,"client":"1","":"downstairs","session_id":"3478a266-f65d-4705-a31a-be8124ecdad2"}
5182025-03-18T16:48:56.409Z{"msg":"Waiting for more clients to be ready","v":0,"name":"crucible","level":30,"time":"2025-03-18T16:48:56.190396495Z","hostname":"w-01JPN225S828YGR17Y0NASFSKX","pid":1250,"session_id":"3478a266-f65d-4705-a31a-be8124ecdad2"}
5192025-03-18T16:48:56.409Z{"msg":"Waiting for more clients to be ready","v":0,"name":"crucible","level":30,"time":"2025-03-18T16:48:56.190478052Z","hostname":"w-01JPN225S828YGR17Y0NASFSKX","pid":1250,"session_id":"3478a266-f65d-4705-a31a-be8124ecdad2"}
5202025-03-18T16:49:06.405Z{"msg":"connecting to 127.0.0.1:8830","v":0,"name":"crucible","level":30,"time":"2025-03-18T16:49:06.19048974Z","hostname":"w-01JPN225S828YGR17Y0NASFSKX","pid":1250,"":"io task","client":"2","":"downstairs","session_id":"3478a266-f65d-4705-a31a-be8124ecdad2"}
5212025-03-18T16:49:06.411Z{"msg":"ds_connection connected from Ok(127.0.0.1:57920)","v":0,"name":"crucible","level":30,"time":"2025-03-18T16:49:06.190773869Z","hostname":"w-01JPN225S828YGR17Y0NASFSKX","pid":1250,"":"io task","client":"2","":"downstairs","session_id":"3478a266-f65d-4705-a31a-be8124ecdad2"}
5222025-03-18T16:49:06.411Z{"msg":"version negotiation from state Connecting { state: WaitForPromote, mode: New }","v":0,"name":"crucible","level":30,"time":"2025-03-18T16:49:06.191806386Z","hostname":"w-01JPN225S828YGR17Y0NASFSKX","pid":1250,"client":"2","":"downstairs","session_id":"3478a266-f65d-4705-a31a-be8124ecdad2"}
5232025-03-18T16:49:06.411Z{"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":"2025-03-18T16:49:06.192340447Z","hostname":"w-01JPN225S828YGR17Y0NASFSKX","pid":1250,"client":"2","":"downstairs","session_id":"3478a266-f65d-4705-a31a-be8124ecdad2"}
5242025-03-18T16:49:06.411Z{"msg":"[0]R flush_numbers: [3997, 3997, 3997, 3997, 3997]","v":0,"name":"crucible","level":30,"time":"2025-03-18T16:49:06.192733389Z","hostname":"w-01JPN225S828YGR17Y0NASFSKX","pid":1250,"":"downstairs","":"downstairs","session_id":"3478a266-f65d-4705-a31a-be8124ecdad2"}
5252025-03-18T16:49:06.411Z{"msg":"[0]R generation: [32, 32, 32, 32, 32]","v":0,"name":"crucible","level":30,"time":"2025-03-18T16:49:06.192767644Z","hostname":"w-01JPN225S828YGR17Y0NASFSKX","pid":1250,"":"downstairs","":"downstairs","session_id":"3478a266-f65d-4705-a31a-be8124ecdad2"}
5262025-03-18T16:49:06.411Z{"msg":"[0]R dirty: [false, false, false, false, false]","v":0,"name":"crucible","level":30,"time":"2025-03-18T16:49:06.192784212Z","hostname":"w-01JPN225S828YGR17Y0NASFSKX","pid":1250,"":"downstairs","":"downstairs","session_id":"3478a266-f65d-4705-a31a-be8124ecdad2"}
5272025-03-18T16:49:06.411Z{"msg":"[1]R flush_numbers: [3997, 3997, 3997, 3997, 3997]","v":0,"name":"crucible","level":30,"time":"2025-03-18T16:49:06.192805879Z","hostname":"w-01JPN225S828YGR17Y0NASFSKX","pid":1250,"":"downstairs","":"downstairs","session_id":"3478a266-f65d-4705-a31a-be8124ecdad2"}
5282025-03-18T16:49:06.411Z{"msg":"[1]R generation: [32, 32, 32, 32, 32]","v":0,"name":"crucible","level":30,"time":"2025-03-18T16:49:06.192819987Z","hostname":"w-01JPN225S828YGR17Y0NASFSKX","pid":1250,"":"downstairs","":"downstairs","session_id":"3478a266-f65d-4705-a31a-be8124ecdad2"}
5292025-03-18T16:49:06.411Z{"msg":"[1]R dirty: [false, false, false, false, false]","v":0,"name":"crucible","level":30,"time":"2025-03-18T16:49:06.192834325Z","hostname":"w-01JPN225S828YGR17Y0NASFSKX","pid":1250,"":"downstairs","":"downstairs","session_id":"3478a266-f65d-4705-a31a-be8124ecdad2"}
5302025-03-18T16:49:06.411Z{"msg":"[2]R flush_numbers: [3996, 3996, 3996, 3996, 3996]","v":0,"name":"crucible","level":30,"time":"2025-03-18T16:49:06.192847673Z","hostname":"w-01JPN225S828YGR17Y0NASFSKX","pid":1250,"":"downstairs","":"downstairs","session_id":"3478a266-f65d-4705-a31a-be8124ecdad2"}
5312025-03-18T16:49:06.411Z{"msg":"[2]R generation: [31, 31, 31, 31, 31]","v":0,"name":"crucible","level":30,"time":"2025-03-18T16:49:06.19286794Z","hostname":"w-01JPN225S828YGR17Y0NASFSKX","pid":1250,"":"downstairs","":"downstairs","session_id":"3478a266-f65d-4705-a31a-be8124ecdad2"}
5322025-03-18T16:49:06.411Z{"msg":"[2]R dirty: [false, false, false, false, false]","v":0,"name":"crucible","level":30,"time":"2025-03-18T16:49:06.192882018Z","hostname":"w-01JPN225S828YGR17Y0NASFSKX","pid":1250,"":"downstairs","":"downstairs","session_id":"3478a266-f65d-4705-a31a-be8124ecdad2"}
5332025-03-18T16:49:06.411Z{"msg":"Max found gen is 33","v":0,"name":"crucible","level":30,"time":"2025-03-18T16:49:06.192901705Z","hostname":"w-01JPN225S828YGR17Y0NASFSKX","pid":1250,"":"downstairs","":"downstairs","session_id":"3478a266-f65d-4705-a31a-be8124ecdad2"}
5342025-03-18T16:49:06.411Z{"msg":"Generation requested: 33 >= found:33","v":0,"name":"crucible","level":30,"time":"2025-03-18T16:49:06.192915273Z","hostname":"w-01JPN225S828YGR17Y0NASFSKX","pid":1250,"":"downstairs","":"downstairs","session_id":"3478a266-f65d-4705-a31a-be8124ecdad2"}
5352025-03-18T16:49:06.411Z{"msg":"Next flush: 3998","v":0,"name":"crucible","level":30,"time":"2025-03-18T16:49:06.192928401Z","hostname":"w-01JPN225S828YGR17Y0NASFSKX","pid":1250,"":"downstairs","":"downstairs","session_id":"3478a266-f65d-4705-a31a-be8124ecdad2"}
5362025-03-18T16:49:06.411Z{"msg":"extent 0 needs reconciliation: ExtentMetadata { gen: 32, flush: 3997, dirty: false } ExtentMetadata { gen: 32, flush: 3997, dirty: false } ExtentMetadata { gen: 31, flush: 3996, dirty: false }","v":0,"name":"crucible","level":30,"time":"2025-03-18T16:49:06.192943638Z","hostname":"w-01JPN225S828YGR17Y0NASFSKX","pid":1250,"":"mend","":"downstairs","":"downstairs","session_id":"3478a266-f65d-4705-a31a-be8124ecdad2"}
5372025-03-18T16:49:06.411Z{"msg":"extent:0 [ExtentMetadata { gen: 32, flush: 3997, dirty: false }, ExtentMetadata { gen: 32, flush: 3997, dirty: false }, ExtentMetadata { gen: 31, flush: 3996, dirty: false }] => 0","v":0,"name":"crucible","level":30,"time":"2025-03-18T16:49:06.192968465Z","hostname":"w-01JPN225S828YGR17Y0NASFSKX","pid":1250,"":"mend","":"downstairs","":"downstairs","session_id":"3478a266-f65d-4705-a31a-be8124ecdad2"}
5382025-03-18T16:49:06.411Z{"msg":"found dest for source 0 for extent at index 0 => [ClientId(2)]","v":0,"name":"crucible","level":30,"time":"2025-03-18T16:49:06.192982943Z","hostname":"w-01JPN225S828YGR17Y0NASFSKX","pid":1250,"":"mend","":"downstairs","":"downstairs","session_id":"3478a266-f65d-4705-a31a-be8124ecdad2"}
5392025-03-18T16:49:06.411Z{"msg":"extent 1 needs reconciliation: ExtentMetadata { gen: 32, flush: 3997, dirty: false } ExtentMetadata { gen: 32, flush: 3997, dirty: false } ExtentMetadata { gen: 31, flush: 3996, dirty: false }","v":0,"name":"crucible","level":30,"time":"2025-03-18T16:49:06.193004949Z","hostname":"w-01JPN225S828YGR17Y0NASFSKX","pid":1250,"":"mend","":"downstairs","":"downstairs","session_id":"3478a266-f65d-4705-a31a-be8124ecdad2"}
5402025-03-18T16:49:06.411Z{"msg":"extent:0 [ExtentMetadata { gen: 32, flush: 3997, dirty: false }, ExtentMetadata { gen: 32, flush: 3997, dirty: false }, ExtentMetadata { gen: 31, flush: 3996, dirty: false }] => 0","v":0,"name":"crucible","level":30,"time":"2025-03-18T16:49:06.193020627Z","hostname":"w-01JPN225S828YGR17Y0NASFSKX","pid":1250,"":"mend","":"downstairs","":"downstairs","session_id":"3478a266-f65d-4705-a31a-be8124ecdad2"}
5412025-03-18T16:49:06.411Z{"msg":"found dest for source 0 for extent at index 1 => [ClientId(2)]","v":0,"name":"crucible","level":30,"time":"2025-03-18T16:49:06.193034355Z","hostname":"w-01JPN225S828YGR17Y0NASFSKX","pid":1250,"":"mend","":"downstairs","":"downstairs","session_id":"3478a266-f65d-4705-a31a-be8124ecdad2"}
5422025-03-18T16:49:06.411Z{"msg":"extent 2 needs reconciliation: ExtentMetadata { gen: 32, flush: 3997, dirty: false } ExtentMetadata { gen: 32, flush: 3997, dirty: false } ExtentMetadata { gen: 31, flush: 3996, dirty: false }","v":0,"name":"crucible","level":30,"time":"2025-03-18T16:49:06.193057512Z","hostname":"w-01JPN225S828YGR17Y0NASFSKX","pid":1250,"":"mend","":"downstairs","":"downstairs","session_id":"3478a266-f65d-4705-a31a-be8124ecdad2"}
5432025-03-18T16:49:06.411Z{"msg":"extent:0 [ExtentMetadata { gen: 32, flush: 3997, dirty: false }, ExtentMetadata { gen: 32, flush: 3997, dirty: false }, ExtentMetadata { gen: 31, flush: 3996, dirty: false }] => 0","v":0,"name":"crucible","level":30,"time":"2025-03-18T16:49:06.19307315Z","hostname":"w-01JPN225S828YGR17Y0NASFSKX","pid":1250,"":"mend","":"downstairs","":"downstairs","session_id":"3478a266-f65d-4705-a31a-be8124ecdad2"}
5442025-03-18T16:49:06.411Z{"msg":"found dest for source 0 for extent at index 2 => [ClientId(2)]","v":0,"name":"crucible","level":30,"time":"2025-03-18T16:49:06.193087087Z","hostname":"w-01JPN225S828YGR17Y0NASFSKX","pid":1250,"":"mend","":"downstairs","":"downstairs","session_id":"3478a266-f65d-4705-a31a-be8124ecdad2"}
5452025-03-18T16:49:06.411Z{"msg":"extent 3 needs reconciliation: ExtentMetadata { gen: 32, flush: 3997, dirty: false } ExtentMetadata { gen: 32, flush: 3997, dirty: false } ExtentMetadata { gen: 31, flush: 3996, dirty: false }","v":0,"name":"crucible","level":30,"time":"2025-03-18T16:49:06.193111104Z","hostname":"w-01JPN225S828YGR17Y0NASFSKX","pid":1250,"":"mend","":"downstairs","":"downstairs","session_id":"3478a266-f65d-4705-a31a-be8124ecdad2"}
5462025-03-18T16:49:06.411Z{"msg":"extent:0 [ExtentMetadata { gen: 32, flush: 3997, dirty: false }, ExtentMetadata { gen: 32, flush: 3997, dirty: false }, ExtentMetadata { gen: 31, flush: 3996, dirty: false }] => 0","v":0,"name":"crucible","level":30,"time":"2025-03-18T16:49:06.193126782Z","hostname":"w-01JPN225S828YGR17Y0NASFSKX","pid":1250,"":"mend","":"downstairs","":"downstairs","session_id":"3478a266-f65d-4705-a31a-be8124ecdad2"}
5472025-03-18T16:49:06.411Z{"msg":"found dest for source 0 for extent at index 3 => [ClientId(2)]","v":0,"name":"crucible","level":30,"time":"2025-03-18T16:49:06.193141049Z","hostname":"w-01JPN225S828YGR17Y0NASFSKX","pid":1250,"":"mend","":"downstairs","":"downstairs","session_id":"3478a266-f65d-4705-a31a-be8124ecdad2"}
5482025-03-18T16:49:06.411Z{"msg":"extent 4 needs reconciliation: ExtentMetadata { gen: 32, flush: 3997, dirty: false } ExtentMetadata { gen: 32, flush: 3997, dirty: false } ExtentMetadata { gen: 31, flush: 3996, dirty: false }","v":0,"name":"crucible","level":30,"time":"2025-03-18T16:49:06.193156217Z","hostname":"w-01JPN225S828YGR17Y0NASFSKX","pid":1250,"":"mend","":"downstairs","":"downstairs","session_id":"3478a266-f65d-4705-a31a-be8124ecdad2"}
5492025-03-18T16:49:06.412Z{"msg":"extent:0 [ExtentMetadata { gen: 32, flush: 3997, dirty: false }, ExtentMetadata { gen: 32, flush: 3997, dirty: false }, ExtentMetadata { gen: 31, flush: 3996, dirty: false }] => 0","v":0,"name":"crucible","level":30,"time":"2025-03-18T16:49:06.193170995Z","hostname":"w-01JPN225S828YGR17Y0NASFSKX","pid":1250,"":"mend","":"downstairs","":"downstairs","session_id":"3478a266-f65d-4705-a31a-be8124ecdad2"}
5502025-03-18T16:49:06.412Z{"msg":"found dest for source 0 for extent at index 4 => [ClientId(2)]","v":0,"name":"crucible","level":30,"time":"2025-03-18T16:49:06.193191582Z","hostname":"w-01JPN225S828YGR17Y0NASFSKX","pid":1250,"":"mend","":"downstairs","":"downstairs","session_id":"3478a266-f65d-4705-a31a-be8124ecdad2"}
5512025-03-18T16:49:06.412Z{"msg":"Transition from Connecting { state: WaitQuorum, mode: New } to Reconcile","v":0,"name":"crucible","level":30,"time":"2025-03-18T16:49:06.193214109Z","hostname":"w-01JPN225S828YGR17Y0NASFSKX","pid":1250,"client":"0","":"downstairs","session_id":"3478a266-f65d-4705-a31a-be8124ecdad2"}
5522025-03-18T16:49:06.412Z{"msg":"Transition from Connecting { state: WaitQuorum, mode: New } to Reconcile","v":0,"name":"crucible","level":30,"time":"2025-03-18T16:49:06.193244974Z","hostname":"w-01JPN225S828YGR17Y0NASFSKX","pid":1250,"client":"1","":"downstairs","session_id":"3478a266-f65d-4705-a31a-be8124ecdad2"}
5532025-03-18T16:49:06.412Z{"msg":"Transition from Connecting { state: WaitQuorum, mode: New } to Reconcile","v":0,"name":"crucible","level":30,"time":"2025-03-18T16:49:06.193268181Z","hostname":"w-01JPN225S828YGR17Y0NASFSKX","pid":1250,"client":"2","":"downstairs","session_id":"3478a266-f65d-4705-a31a-be8124ecdad2"}
5542025-03-18T16:49:06.412Z{"msg":"Full repair list: {ExtentId(4): ExtentFix { source: ClientId(0), dest: [ClientId(2)] }, ExtentId(0): ExtentFix { source: ClientId(0), dest: [ClientId(2)] }, ExtentId(2): ExtentFix { source: ClientId(0), dest: [ClientId(2)] }, ExtentId(3): ExtentFix { source: ClientId(0), dest: [ClientId(2)] }, ExtentId(1): ExtentFix { source: ClientId(0), dest: [ClientId(2)] }}","v":0,"name":"crucible","level":30,"time":"2025-03-18T16:49:06.193299396Z","hostname":"w-01JPN225S828YGR17Y0NASFSKX","pid":1250,"":"downstairs","":"downstairs","session_id":"3478a266-f65d-4705-a31a-be8124ecdad2"}
5552025-03-18T16:49:06.412Z{"msg":"Task list: [ReconcileIO { id: ReconciliationId(0), op: ExtentFlush { repair_id: ReconciliationId(0), extent_id: ExtentId(4), client_id: ClientId(0), flush_number: 3998, gen_number: 33 }, state: ClientData([New, New, New]) }, ReconcileIO { id: ReconciliationId(1), op: ExtentClose { repair_id: ReconciliationId(1), extent_id: ExtentId(4) }, state: ClientData([New, New, New]) }, ReconcileIO { id: ReconciliationId(2), op: ExtentRepair { repair_id: ReconciliationId(2), extent_id: ExtentId(4), source_client_id: ClientId(0), source_repair_address: 0.0.0.0:12810, dest_clients: [ClientId(2)] }, state: ClientData([New, New, New]) }, ReconcileIO { id: ReconciliationId(3), op: ExtentReopen { repair_id: ReconciliationId(3), extent_id: ExtentId(4) }, state: ClientData([New, New, New]) }, ReconcileIO { id: ReconciliationId(4), op: ExtentFlush { repair_id: ReconciliationId(4), extent_id: ExtentId(0), client_id: ClientId(0), flush_number: 3998, gen_number: 33 }, state: ClientData([New, New, New]) }, ReconcileIO { id: ReconciliationId(5), op: ExtentClose { repair_id: ReconciliationId(5), extent_id: ExtentId(0) }, state: ClientData([New, New, New]) }, ReconcileIO { id: ReconciliationId(6), op: ExtentRepair { repair_id: ReconciliationId(6), extent_id: ExtentId(0), source_client_id: ClientId(0), source_repair_address: 0.0.0.0:12810, dest_clients: [ClientId(2)] }, state: ClientData([New, New, New]) }, ReconcileIO { id: ReconciliationId(7), op: ExtentReopen { repair_id: ReconciliationId(7), extent_id: ExtentId(0) }, state: ClientData([New, New, New]) }, ReconcileIO { id: ReconciliationId(8), op: ExtentFlush { repair_id: ReconciliationId(8), extent_id: ExtentId(2), client_id: ClientId(0), flush_number: 3998, gen_number: 33 }, state: ClientData([New, New, New]) }, ReconcileIO { id: ReconciliationId(9), op: ExtentClose { repair_id: ReconciliationId(9), extent_id: ExtentId(2) }, state: ClientData([New, New, New]) }, ReconcileIO { id: ReconciliationId(10), op: ExtentRepair { repair_id: ReconciliationId(10), extent_id: ExtentId(2), source_client_id: ClientId(0), source_repair_address: 0.0.0.0:12810, dest_clients: [ClientId(2)] }, state: ClientData([New, New, New]) }, ReconcileIO { id: ReconciliationId(11), op: ExtentReopen { repair_id: ReconciliationId(11), extent_id: ExtentId(2) }, state: ClientData([New, New, New]) }, ReconcileIO { id: ReconciliationId(12), op: ExtentFlush { repair_id: ReconciliationId(12), extent_id: ExtentId(3), client_id: ClientId(0), flush_number: 3998, gen_number: 33 }, state: ClientData([New, New, New]) }, ReconcileIO { id: ReconciliationId(13), op: ExtentClose { repair_id: ReconciliationId(13), extent_id: ExtentId(3) }, state: ClientData([New, New, New]) }, ReconcileIO { id: ReconciliationId(14), op: ExtentRepair { repair_id: ReconciliationId(14), extent_id: ExtentId(3), source_client_id: ClientId(0), source_repair_address: 0.0.0.0:12810, dest_clients: [ClientId(2)] }, state: ClientData([New, New, New]) }, ReconcileIO { id: ReconciliationId(15), op: ExtentReopen { repair_id: ReconciliationId(15), extent_id: ExtentId(3) }, state: ClientData([New, New, New]) }, ReconcileIO { id: ReconciliationId(16), op: ExtentFlush { repair_id: ReconciliationId(16), extent_id: ExtentId(1), client_id: ClientId(0), flush_number: 3998, gen_number: 33 }, state: ClientData([New, New, New]) }, ReconcileIO { id: ReconciliationId(17), op: ExtentClose { repair_id: ReconciliationId(17), extent_id: ExtentId(1) }, state: ClientData([New, New, New]) }, ReconcileIO { id: ReconciliationId(18), op: ExtentRepair { repair_id: ReconciliationId(18), 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(19), op: ExtentReopen { repair_id: ReconciliationId(19), extent_id: ExtentId(1) }, state: ClientData([New, New, New]) }]","v":0,"name":"crucible","level":30,"time":"2025-03-18T16:49:06.193450454Z","hostname":"w-01JPN225S828YGR17Y0NASFSKX","pid":1250,"":"downstairs","":"downstairs","session_id":"3478a266-f65d-4705-a31a-be8124ecdad2"}
5562025-03-18T16:49:06.412Z{"msg":"starting reconciliation 1685d215-beb5-4519-9111-82428c0cfe3e: found 20 extents that need repair","v":0,"name":"crucible","level":30,"time":"2025-03-18T16:49:06.193486478Z","hostname":"w-01JPN225S828YGR17Y0NASFSKX","pid":1250,"":"downstairs","":"downstairs","session_id":"3478a266-f65d-4705-a31a-be8124ecdad2"}
5572025-03-18T16:49:06.412Z{"msg":"sending reconcile request ReconciliationId(2)","v":0,"name":"crucible","level":30,"time":"2025-03-18T16:49:06.193628957Z","hostname":"w-01JPN225S828YGR17Y0NASFSKX","pid":1250,"client":"2","":"downstairs","session_id":"3478a266-f65d-4705-a31a-be8124ecdad2"}
5582025-03-18T16:49:06.416Z{"msg":"sending reconcile request ReconciliationId(6)","v":0,"name":"crucible","level":30,"time":"2025-03-18T16:49:06.202526895Z","hostname":"w-01JPN225S828YGR17Y0NASFSKX","pid":1250,"client":"2","":"downstairs","session_id":"3478a266-f65d-4705-a31a-be8124ecdad2"}
5592025-03-18T16:49:06.420Z{"msg":"sending reconcile request ReconciliationId(10)","v":0,"name":"crucible","level":30,"time":"2025-03-18T16:49:06.206158039Z","hostname":"w-01JPN225S828YGR17Y0NASFSKX","pid":1250,"client":"2","":"downstairs","session_id":"3478a266-f65d-4705-a31a-be8124ecdad2"}
5602025-03-18T16:49:06.423Z{"msg":"sending reconcile request ReconciliationId(14)","v":0,"name":"crucible","level":30,"time":"2025-03-18T16:49:06.209656243Z","hostname":"w-01JPN225S828YGR17Y0NASFSKX","pid":1250,"client":"2","":"downstairs","session_id":"3478a266-f65d-4705-a31a-be8124ecdad2"}
5612025-03-18T16:49:06.427Z{"msg":"sending reconcile request ReconciliationId(18)","v":0,"name":"crucible","level":30,"time":"2025-03-18T16:49:06.213180953Z","hostname":"w-01JPN225S828YGR17Y0NASFSKX","pid":1250,"client":"2","":"downstairs","session_id":"3478a266-f65d-4705-a31a-be8124ecdad2"}
5622025-03-18T16:49:06.430Z{"msg":"done with reconciliation","v":0,"name":"crucible","level":30,"time":"2025-03-18T16:49:06.216370072Z","hostname":"w-01JPN225S828YGR17Y0NASFSKX","pid":1250,"":"downstairs","":"downstairs","session_id":"3478a266-f65d-4705-a31a-be8124ecdad2"}
5632025-03-18T16:49:06.434Z{"msg":"Transition from Reconcile to Active","v":0,"name":"crucible","level":30,"time":"2025-03-18T16:49:06.216413496Z","hostname":"w-01JPN225S828YGR17Y0NASFSKX","pid":1250,"client":"0","":"downstairs","session_id":"3478a266-f65d-4705-a31a-be8124ecdad2"}
5642025-03-18T16:49:06.434Z{"msg":"Transition from Reconcile to Active","v":0,"name":"crucible","level":30,"time":"2025-03-18T16:49:06.216449501Z","hostname":"w-01JPN225S828YGR17Y0NASFSKX","pid":1250,"client":"1","":"downstairs","session_id":"3478a266-f65d-4705-a31a-be8124ecdad2"}
5652025-03-18T16:49:06.434Z{"msg":"Transition from Reconcile to Active","v":0,"name":"crucible","level":30,"time":"2025-03-18T16:49:06.216475487Z","hostname":"w-01JPN225S828YGR17Y0NASFSKX","pid":1250,"client":"2","":"downstairs","session_id":"3478a266-f65d-4705-a31a-be8124ecdad2"}
5662025-03-18T16:49:06.434Z{"msg":"All required reconciliation work is completed","v":0,"name":"crucible","level":30,"time":"2025-03-18T16:49:06.216510322Z","hostname":"w-01JPN225S828YGR17Y0NASFSKX","pid":1250,"session_id":"3478a266-f65d-4705-a31a-be8124ecdad2"}
5672025-03-18T16:49:06.434Z{"msg":"Set Downstairs and Upstairs active after reconciliation","v":0,"name":"crucible","level":30,"time":"2025-03-18T16:49:06.216527599Z","hostname":"w-01JPN225S828YGR17Y0NASFSKX","pid":1250,"session_id":"3478a266-f65d-4705-a31a-be8124ecdad2"}
5682025-03-18T16:49:06.434Z{"msg":"494e31c0-b4be-42bc-a828-5b60e5bccc79 is now active with session: 3478a266-f65d-4705-a31a-be8124ecdad2","v":0,"name":"crucible","level":30,"time":"2025-03-18T16:49:06.216541087Z","hostname":"w-01JPN225S828YGR17Y0NASFSKX","pid":1250,"session_id":"3478a266-f65d-4705-a31a-be8124ecdad2"}
5692025-03-18T16:49:06.434Z{"msg":"The guest has finished waiting for activation with:33","v":0,"name":"crucible","level":30,"time":"2025-03-18T16:49:06.216558754Z","hostname":"w-01JPN225S828YGR17Y0NASFSKX","pid":1250}
5702025-03-18T16:49:06.434Z{"msg":"Activated sub_volume 494e31c0-b4be-42bc-a828-5b60e5bccc79","v":0,"name":"crucible","level":30,"time":"2025-03-18T16:49:06.21659012Z","hostname":"w-01JPN225S828YGR17Y0NASFSKX","pid":1250}
5712025-03-18T16:49:06.434Z{"msg":"The guest has requested activation with gen:33","v":0,"name":"crucible","level":30,"time":"2025-03-18T16:49:06.21672534Z","hostname":"w-01JPN225S828YGR17Y0NASFSKX","pid":1250}
5722025-03-18T16:49:06.434Z{"msg":"494e31c0-b4be-42bc-a828-5b60e5bccc79 active request set","v":0,"name":"crucible","level":30,"time":"2025-03-18T16:49:06.216760195Z","hostname":"w-01JPN225S828YGR17Y0NASFSKX","pid":1250,"session_id":"7139e958-9773-46ef-930a-4efe5e369499"}
5732025-03-18T16:49:06.434Z{"msg":"sending connect oneshot to client","v":0,"name":"crucible","level":30,"time":"2025-03-18T16:49:06.216776722Z","hostname":"w-01JPN225S828YGR17Y0NASFSKX","pid":1250,"client":"0","":"downstairs","session_id":"7139e958-9773-46ef-930a-4efe5e369499"}
5742025-03-18T16:49:06.434Z{"msg":"client set_active_request while in Connecting { state: Start { auto_promote: true }, mode: New }; waiting...","v":0,"name":"crucible","level":30,"time":"2025-03-18T16:49:06.21679203Z","hostname":"w-01JPN225S828YGR17Y0NASFSKX","pid":1250,"client":"0","":"downstairs","session_id":"7139e958-9773-46ef-930a-4efe5e369499"}
5752025-03-18T16:49:06.434Z{"msg":"sending connect oneshot to client","v":0,"name":"crucible","level":30,"time":"2025-03-18T16:49:06.216813577Z","hostname":"w-01JPN225S828YGR17Y0NASFSKX","pid":1250,"client":"1","":"downstairs","session_id":"7139e958-9773-46ef-930a-4efe5e369499"}
5762025-03-18T16:49:06.434Z{"msg":"client set_active_request while in Connecting { state: Start { auto_promote: true }, mode: New }; waiting...","v":0,"name":"crucible","level":30,"time":"2025-03-18T16:49:06.216833464Z","hostname":"w-01JPN225S828YGR17Y0NASFSKX","pid":1250,"client":"1","":"downstairs","session_id":"7139e958-9773-46ef-930a-4efe5e369499"}
5772025-03-18T16:49:06.434Z{"msg":"sending connect oneshot to client","v":0,"name":"crucible","level":30,"time":"2025-03-18T16:49:06.216856001Z","hostname":"w-01JPN225S828YGR17Y0NASFSKX","pid":1250,"client":"2","":"downstairs","session_id":"7139e958-9773-46ef-930a-4efe5e369499"}
5782025-03-18T16:49:06.434Z{"msg":"client set_active_request while in Connecting { state: Start { auto_promote: true }, mode: New }; waiting...","v":0,"name":"crucible","level":30,"time":"2025-03-18T16:49:06.216881747Z","hostname":"w-01JPN225S828YGR17Y0NASFSKX","pid":1250,"client":"2","":"downstairs","session_id":"7139e958-9773-46ef-930a-4efe5e369499"}
5792025-03-18T16:49:06.434Z{"msg":"connecting to 127.0.0.1:8860","v":0,"name":"crucible","level":30,"time":"2025-03-18T16:49:06.216918252Z","hostname":"w-01JPN225S828YGR17Y0NASFSKX","pid":1250,"":"io task","client":"2","":"downstairs","session_id":"7139e958-9773-46ef-930a-4efe5e369499"}
5802025-03-18T16:49:06.434Z{"msg":"connecting to 127.0.0.1:8840","v":0,"name":"crucible","level":30,"time":"2025-03-18T16:49:06.216945627Z","hostname":"w-01JPN225S828YGR17Y0NASFSKX","pid":1250,"":"io task","client":"0","":"downstairs","session_id":"7139e958-9773-46ef-930a-4efe5e369499"}
5812025-03-18T16:49:06.434Z{"msg":"connecting to 127.0.0.1:8850","v":0,"name":"crucible","level":30,"time":"2025-03-18T16:49:06.216970014Z","hostname":"w-01JPN225S828YGR17Y0NASFSKX","pid":1250,"":"io task","client":"1","":"downstairs","session_id":"7139e958-9773-46ef-930a-4efe5e369499"}
5822025-03-18T16:49:06.434Z{"msg":"ds_connection connected from Ok(127.0.0.1:63714)","v":0,"name":"crucible","level":30,"time":"2025-03-18T16:49:06.2169968Z","hostname":"w-01JPN225S828YGR17Y0NASFSKX","pid":1250,"":"io task","client":"1","":"downstairs","session_id":"7139e958-9773-46ef-930a-4efe5e369499"}
5832025-03-18T16:49:06.434Z{"msg":"ds_connection connected from Ok(127.0.0.1:38042)","v":0,"name":"crucible","level":30,"time":"2025-03-18T16:49:06.217025526Z","hostname":"w-01JPN225S828YGR17Y0NASFSKX","pid":1250,"":"io task","client":"0","":"downstairs","session_id":"7139e958-9773-46ef-930a-4efe5e369499"}
5842025-03-18T16:49:06.434Z{"msg":"ds_connection connected from Ok(127.0.0.1:49319)","v":0,"name":"crucible","level":30,"time":"2025-03-18T16:49:06.217058911Z","hostname":"w-01JPN225S828YGR17Y0NASFSKX","pid":1250,"":"io task","client":"2","":"downstairs","session_id":"7139e958-9773-46ef-930a-4efe5e369499"}
5852025-03-18T16:49:06.434Z{"msg":"version negotiation from state Connecting { state: WaitForPromote, mode: New }","v":0,"name":"crucible","level":30,"time":"2025-03-18T16:49:06.217323482Z","hostname":"w-01JPN225S828YGR17Y0NASFSKX","pid":1250,"client":"1","":"downstairs","session_id":"7139e958-9773-46ef-930a-4efe5e369499"}
5862025-03-18T16:49:06.434Z{"msg":"version negotiation from state Connecting { state: WaitForPromote, mode: New }","v":0,"name":"crucible","level":30,"time":"2025-03-18T16:49:06.217454192Z","hostname":"w-01JPN225S828YGR17Y0NASFSKX","pid":1250,"client":"0","":"downstairs","session_id":"7139e958-9773-46ef-930a-4efe5e369499"}
5872025-03-18T16:49:06.434Z{"msg":"version negotiation from state Connecting { state: WaitForPromote, mode: New }","v":0,"name":"crucible","level":30,"time":"2025-03-18T16:49:06.217578734Z","hostname":"w-01JPN225S828YGR17Y0NASFSKX","pid":1250,"client":"2","":"downstairs","session_id":"7139e958-9773-46ef-930a-4efe5e369499"}
5882025-03-18T16:49:06.434Z{"msg":"downstairs client at Some(127.0.0.1:8850) has region UUID 12345678-0000-0000-0000-000000008850","v":0,"name":"crucible","level":30,"time":"2025-03-18T16:49:06.217840056Z","hostname":"w-01JPN225S828YGR17Y0NASFSKX","pid":1250,"client":"1","":"downstairs","session_id":"7139e958-9773-46ef-930a-4efe5e369499"}
5892025-03-18T16:49:06.435Z{"msg":"downstairs client at Some(127.0.0.1:8840) has region UUID 12345678-0000-0000-0000-000000008840","v":0,"name":"crucible","level":30,"time":"2025-03-18T16:49:06.217968346Z","hostname":"w-01JPN225S828YGR17Y0NASFSKX","pid":1250,"client":"0","":"downstairs","session_id":"7139e958-9773-46ef-930a-4efe5e369499"}
5902025-03-18T16:49:06.435Z{"msg":"Waiting for more clients to be ready","v":0,"name":"crucible","level":30,"time":"2025-03-18T16:49:06.218222149Z","hostname":"w-01JPN225S828YGR17Y0NASFSKX","pid":1250,"session_id":"7139e958-9773-46ef-930a-4efe5e369499"}
5912025-03-18T16:49:06.435Z{"msg":"downstairs client at Some(127.0.0.1:8860) has region UUID 12345678-0000-0000-0000-000000008860","v":0,"name":"crucible","level":30,"time":"2025-03-18T16:49:06.218318485Z","hostname":"w-01JPN225S828YGR17Y0NASFSKX","pid":1250,"client":"2","":"downstairs","session_id":"7139e958-9773-46ef-930a-4efe5e369499"}
5922025-03-18T16:49:06.435Z{"msg":"Waiting for more clients to be ready","v":0,"name":"crucible","level":30,"time":"2025-03-18T16:49:06.218455805Z","hostname":"w-01JPN225S828YGR17Y0NASFSKX","pid":1250,"session_id":"7139e958-9773-46ef-930a-4efe5e369499"}
5932025-03-18T16:49:06.435Z{"msg":"[0]R flush_numbers: [5318, 5318, 5318, 5318, 5318]","v":0,"name":"crucible","level":30,"time":"2025-03-18T16:49:06.218641667Z","hostname":"w-01JPN225S828YGR17Y0NASFSKX","pid":1250,"":"downstairs","":"downstairs","session_id":"7139e958-9773-46ef-930a-4efe5e369499"}
5942025-03-18T16:49:06.435Z{"msg":"[0]R generation: [32, 32, 32, 32, 32]","v":0,"name":"crucible","level":30,"time":"2025-03-18T16:49:06.218670473Z","hostname":"w-01JPN225S828YGR17Y0NASFSKX","pid":1250,"":"downstairs","":"downstairs","session_id":"7139e958-9773-46ef-930a-4efe5e369499"}
5952025-03-18T16:49:06.435Z{"msg":"[0]R dirty: [false, false, false, false, false]","v":0,"name":"crucible","level":30,"time":"2025-03-18T16:49:06.218686511Z","hostname":"w-01JPN225S828YGR17Y0NASFSKX","pid":1250,"":"downstairs","":"downstairs","session_id":"7139e958-9773-46ef-930a-4efe5e369499"}
5962025-03-18T16:49:06.435Z{"msg":"[1]R flush_numbers: [5318, 5318, 5318, 5318, 5318]","v":0,"name":"crucible","level":30,"time":"2025-03-18T16:49:06.218700258Z","hostname":"w-01JPN225S828YGR17Y0NASFSKX","pid":1250,"":"downstairs","":"downstairs","session_id":"7139e958-9773-46ef-930a-4efe5e369499"}
5972025-03-18T16:49:06.435Z{"msg":"[1]R generation: [32, 32, 32, 32, 32]","v":0,"name":"crucible","level":30,"time":"2025-03-18T16:49:06.218721615Z","hostname":"w-01JPN225S828YGR17Y0NASFSKX","pid":1250,"":"downstairs","":"downstairs","session_id":"7139e958-9773-46ef-930a-4efe5e369499"}
5982025-03-18T16:49:06.435Z{"msg":"[1]R dirty: [false, false, false, false, false]","v":0,"name":"crucible","level":30,"time":"2025-03-18T16:49:06.218736163Z","hostname":"w-01JPN225S828YGR17Y0NASFSKX","pid":1250,"":"downstairs","":"downstairs","session_id":"7139e958-9773-46ef-930a-4efe5e369499"}
5992025-03-18T16:49:06.435Z{"msg":"[2]R flush_numbers: [5318, 5318, 5318, 5318, 5318]","v":0,"name":"crucible","level":30,"time":"2025-03-18T16:49:06.218767599Z","hostname":"w-01JPN225S828YGR17Y0NASFSKX","pid":Wait for a query_work_queue command to finish before sending IO
6002025-03-18T16:49:06.435Z1250,"":"downstairs","":"downstairs","session_id":"7139e958-9773-46ef-930a-4efe5e369499"}
6012025-03-18T16:49:06.435Z{"msg":"[2]R generation: [32, 32, 32, 32, 32]","v":0,"name":"crucible","level":30,"time":"2025-03-18T16:49:06.218807483Z","hostname":"w-01JPN225S828YGR17Y0NASFSKX","pid":1250,"":"downstairs","":"downstairs","session_id":"7139e958-9773-46ef-930a-4efe5e369499"}
6022025-03-18T16:49:06.435Z{"msg":"[2]R dirty: [false, false, false, false, false]","v":0,"name":"crucible","level":30,"time":"2025-03-18T16:49:06.218830609Z","hostname":"w-01JPN225S828YGR17Y0NASFSKX","pid":1250,"":"downstairs","":"downstairs","session_id":"7139e958-9773-46ef-930a-4efe5e369499"}
6032025-03-18T16:49:06.435Z{"msg":"Max found gen is 33","v":0,"name":"crucible","level":30,"time":"2025-03-18T16:49:06.218844397Z","hostname":"w-01JPN225S828YGR17Y0NASFSKX","pid":1250,"":"downstairs","":"downstairs","session_id":"7139e958-9773-46ef-930a-4efe5e369499"}
6042025-03-18T16:49:06.435Z{"msg":"Generation requested: 33 >= found:33","v":0,"name":"crucible","level":30,"time":"2025-03-18T16:49:06.218874263Z","hostname":"w-01JPN225S828YGR17Y0NASFSKX","pid":1250,"":"downstairs","":"downstairs","session_id":"7139e958-9773-46ef-930a-4efe5e369499"}
6052025-03-18T16:49:06.435Z{"msg":"Next flush: 5319","v":0,"name":"crucible","level":30,"time":"2025-03-18T16:49:06.218907738Z","hostname":"w-01JPN225S828YGR17Y0NASFSKX","pid":1250,"":"downstairs","":"downstairs","session_id":"7139e958-9773-46ef-930a-4efe5e369499"}
6062025-03-18T16:49:06.435Z{"msg":"All extents match","v":0,"name":"crucible","level":30,"time":"2025-03-18T16:49:06.218925045Z","hostname":"w-01JPN225S828YGR17Y0NASFSKX","pid":1250,"":"downstairs","":"downstairs","session_id":"7139e958-9773-46ef-930a-4efe5e369499"}
6072025-03-18T16:49:06.435Z{"msg":"No downstairs reconciliation required","v":0,"name":"crucible","level":30,"time":"2025-03-18T16:49:06.218949262Z","hostname":"w-01JPN225S828YGR17Y0NASFSKX","pid":1250,"session_id":"7139e958-9773-46ef-930a-4efe5e369499"}
6082025-03-18T16:49:06.435Z{"msg":"Transition from WaitQuorum to Active","v":0,"name":"crucible","level":30,"time":"2025-03-18T16:49:06.218981137Z","hostname":"w-01JPN225S828YGR17Y0NASFSKX","pid":1250,"client":"0","":"downstairs","session_id":"7139e958-9773-46ef-930a-4efe5e369499"}
6092025-03-18T16:49:06.435Z{"msg":"Transition from WaitQuorum to Active","v":0,"name":"crucible","level":30,"time":"2025-03-18T16:49:06.219001544Z","hostname":"w-01JPN225S828YGR17Y0NASFSKX","pid":1250,"client":"1","":"downstairs","session_id":"7139e958-9773-46ef-930a-4efe5e369499"}
6102025-03-18T16:49:06.435Z{"msg":"Transition from WaitQuorum to Active","v":0,"name":"crucible","level":30,"time":"2025-03-18T16:49:06.219016382Z","hostname":"w-01JPN225S828YGR17Y0NASFSKX","pid":1250,"client":"2","":"downstairs","session_id":"7139e958-9773-46ef-930a-4efe5e369499"}
6112025-03-18T16:49:06.435Z{"msg":"All required reconciliation work is completed","v":0,"name":"crucible","level":30,"time":"2025-03-18T16:49:06.219044398Z","hostname":"w-01JPN225S828YGR17Y0NASFSKX","pid":1250,"session_id":"7139e958-9773-46ef-930a-4efe5e369499"}
6122025-03-18T16:49:06.435Z{"msg":"Set Downstairs and Upstairs active after reconciliation","v":0,"name":"crucible","level":30,"time":"2025-03-18T16:49:06.219068284Z","hostname":"w-01JPN225S828YGR17Y0NASFSKX","pid":1250,"session_id":"7139e958-9773-46ef-930a-4efe5e369499"}
6132025-03-18T16:49:06.435Z{"msg":"494e31c0-b4be-42bc-a828-5b60e5bccc79 is now active with session: 7139e958-9773-46ef-930a-4efe5e369499","v":0,"name":"crucible","level":30,"time":"2025-03-18T16:49:06.21909874Z","hostname":"w-01JPN225S828YGR17Y0NASFSKX","pid":1250,"session_id":"7139e958-9773-46ef-930a-4efe5e369499"}
6142025-03-18T16:49:06.435Z{"msg":"Set Active after no reconciliation","v":0,"name":"crucible","level":30,"time":"2025-03-18T16:49:06.219133335Z","hostname":"w-01JPN225S828YGR17Y0NASFSKX","pid":1250,"session_id":"7139e958-9773-46ef-930a-4efe5e369499"}
6152025-03-18T16:49:06.435Z{"msg":"The guest has finished waiting for activation with:33","v":0,"name":"crucible","level":30,"time":"2025-03-18T16:49:06.219158061Z","hostname":"w-01JPN225S828YGR17Y0NASFSKX","pid":1250}
6162025-03-18T16:49:06.435Z{"msg":"Activated sub_volume 494e31c0-b4be-42bc-a828-5b60e5bccc79","v":0,"name":"crucible","level":30,"time":"2025-03-18T16:49:06.219170639Z","hostname":"w-01JPN225S828YGR17Y0NASFSKX","pid":1250}
6172025-03-18T16:49:06.435ZDisk: sv:2 bs:4096 ts:409600 tb:100 max_io:100 or 409600
6182025-03-18T16:49:06.435ZLoading write count information from file "/var/tmp/test_up-build/verify_file"
6192025-03-18T16:49:06.435ZRead and Verify all blocks (0..100 range:true)
6202025-03-18T16:49:06.523ZWrote out file "/var/tmp/test_up-build/verify_file"
6212025-03-18T16:49:06.523ZVerify test completed
6222025-03-18T16:49:06.527ZWrote out file "/var/tmp/test_up-build/verify_file"
6232025-03-18T16:49:06.527ZCLIENT: Tests done. All submitted work has been ACK'd
6242025-03-18T16:49:06.527Z----------------------------------------------------------------
6252025-03-18T16:49:06.527Z Crucible gen:33 GIO:true work queues: Upstairs:0 downstairs:1
6262025-03-18T16:49:06.527ZStates: Active Active Active
6272025-03-18T16:49:06.527ZJOBID ACK TYPE BKS/EXT DS:0 DS:1 DS:2 REPLAY
6282025-03-18T16:49:06.527Z 1000 Acked Read 50 Done Done Done false
6292025-03-18T16:49:06.527Z STATES DS:0 DS:1 DS:2 TOTAL
6302025-03-18T16:49:06.527Z Sent 0 0 0 0
6312025-03-18T16:49:06.527Z Done 1 1 1 3
6322025-03-18T16:49:06.527Z Skipped 0 0 0 0
6332025-03-18T16:49:06.527Z Error 0 0 0 0
6342025-03-18T16:49:06.527ZLast Flush: None None None
6352025-03-18T16:49:06.527ZDownstairs last five completed:
6362025-03-18T16:49:06.527ZUpstairs last five completed: 1000
6372025-03-18T16:49:06.527Z----------------------------------------------------------------
6382025-03-18T16:49:06.527Z Crucible gen:33 GIO:true work queues: Upstairs:0 downstairs:1
6392025-03-18T16:49:06.527ZStates: Active Active Active
6402025-03-18T16:49:06.527ZJOBID ACK TYPE BKS/EXT DS:0 DS:1 DS:2 REPLAY
6412025-03-18T16:49:06.527Z 1000 Acked Read 50 Done Done Done false
6422025-03-18T16:49:06.527Z STATES DS:0 DS:1 DS:2 TOTAL
6432025-03-18T16:49:06.527Z Sent 0 0 0 0
6442025-03-18T16:49:06.528Z Done 1 1 1 3
6452025-03-18T16:49:06.528Z Skipped 0 0 0 0
6462025-03-18T16:49:06.528Z Error 0 0 0 0
6472025-03-18T16:49:06.528ZLast Flush: None None None
6482025-03-18T16:49:06.528ZDownstairs last five completed:
6492025-03-18T16:49:06.528ZUpstairs last five completed: 1000
6502025-03-18T16:49:06.528ZCLIENT: Up:0 ds:2 act:6
6512025-03-18T16:49:10.526Z----------------------------------------------------------------
6522025-03-18T16:49:10.526Z Crucible gen:33 GIO:true work queues: Upstairs:0 downstairs:0
6532025-03-18T16:49:10.526ZDownstairs last five completed: 1001 1000
6542025-03-18T16:49:10.529ZUpstairs last five completed: 1001 1000
6552025-03-18T16:49:10.529Z----------------------------------------------------------------
6562025-03-18T16:49:10.529Z Crucible gen:33 GIO:true work queues: Upstairs:0 downstairs:0
6572025-03-18T16:49:10.529ZDownstairs last five completed: 1001 1000
6582025-03-18T16:49:10.529ZUpstairs last five completed: 1001 1000
6592025-03-18T16:49:10.529ZCLIENT: Up:0 ds:0 act:6
6602025-03-18T16:49:10.529ZCLIENT: All crucible jobs finished, exiting program
6612025-03-18T16:49:10.533ZRepair part 2 passed
6622025-03-18T16:49:10.536Z/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
6632025-03-18T16:49:10.551ZEXT BLOCKS GEN0 GEN1 GEN2 FL0 FL1 FL2 D0 D1 D2 DIFF
6642025-03-18T16:49:10.554Z 0 000-009 32 32 32 3997 3997 3997 F F F
6652025-03-18T16:49:10.554Z 1 010-019 32 32 32 3997 3997 3997 F F F
6662025-03-18T16:49:10.554Z 2 020-029 32 32 32 3997 3997 3997 F F F
6672025-03-18T16:49:10.554Z 3 030-039 32 32 32 3997 3997 3997 F F F
6682025-03-18T16:49:10.554Z 4 040-049 32 32 32 3997 3997 3997 F F F
6692025-03-18T16:49:10.554ZMax gen: 32, Max flush: 3997
6702025-03-18T16:49:10.554Zdump test passed
6712025-03-18T16:49:10.557Z/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
6722025-03-18T16:49:10.570Z Extent 1
6732025-03-18T16:49:10.573ZGEN 32 32 32
6742025-03-18T16:49:10.573ZFLUSH_ID 3997 3997 3997
6752025-03-18T16:49:10.573ZDIRTY
6762025-03-18T16:49:10.573Z
6772025-03-18T16:49:10.573ZBLOCK D0 D1 D2 C0 C1 C2 DIFF
6782025-03-18T16:49:10.573Z010 A A A A A A
6792025-03-18T16:49:10.573Z011 A A A A A A
6802025-03-18T16:49:10.576Z012 A A A A A A
6812025-03-18T16:49:10.576Z013 A A A A A A
6822025-03-18T16:49:10.579Z014 A A A A A A
6832025-03-18T16:49:10.580Z015 A A A A A A
6842025-03-18T16:49:10.583Z016 A A A A A A
6852025-03-18T16:49:10.583Z017 A A A A A A
6862025-03-18T16:49:10.583Z018 A A A A A A
6872025-03-18T16:49:10.586Z019 A A A A A A
6882025-03-18T16:49:10.589Zdump extent test passed
6892025-03-18T16:49:10.589Z/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
6902025-03-18T16:49:10.603ZExtent 2 Block in extent 0 Actual block 20
6912025-03-18T16:49:10.606Z
6922025-03-18T16:49:10.606Z DATA SHA256 VER
6932025-03-18T16:49:10.606Z------ ---------------------------------------------------------------- ---
6942025-03-18T16:49:10.606Z 0 1dccf0c51ec363e803ac699b77cd586f8c79ad32aec02a830645719b32a5bd2e A
6952025-03-18T16:49:10.606Z 1 1dccf0c51ec363e803ac699b77cd586f8c79ad32aec02a830645719b32a5bd2e A
6962025-03-18T16:49:10.606Z 2 1dccf0c51ec363e803ac699b77cd586f8c79ad32aec02a830645719b32a5bd2e A
6972025-03-18T16:49:10.606Z
6982025-03-18T16:49:10.606ZNONCES 0 1 2 DIFF
6992025-03-18T16:49:10.606Z------ ------------------------ ------------------------ ------------------------ -----
7002025-03-18T16:49:10.606Z 0 38c89e91e37de0ef452a7ab3 38c89e91e37de0ef452a7ab3 38c89e91e37de0ef452a7ab3
7012025-03-18T16:49:10.606Z
7022025-03-18T16:49:10.606Z TAGS 0 1 2 DIFF
7032025-03-18T16:49:10.606Z------ -------------------------------- -------------------------------- -------------------------------- -----
7042025-03-18T16:49:10.606Z 0 95c9de43214d0511dc277220e83f22f6 95c9de43214d0511dc277220e83f22f6 95c9de43214d0511dc277220e83f22f6
7052025-03-18T16:49:10.606Z
7062025-03-18T16:49:10.606ZHASHES 0 1 2 DIFF
7072025-03-18T16:49:10.607Z------ ---------------- ---------------- ---------------- -----
7082025-03-18T16:49:10.607Z
7092025-03-18T16:49:10.610Zdump block test passed
7102025-03-18T16:49:10.610ZInitial upstairs tests have completed, stopping all downstairs
7112025-03-18T16:49:15.673ZCreating 7 larger downstairs regions
7122025-03-18T16:49:15.858ZStarting 7 downstairs
7132025-03-18T16:49:20.867Zdsc restarted at PID: 1266
7142025-03-18T16:49:21.237ZNow do the replace-reconcile test
7152025-03-18T16:49:21.290ZUsing 8870 for the replacement port
7162025-03-18T16:51:58.668ZCompleted test: replace-reconcile
7172025-03-18T16:51:58.671ZNow do the replace-before-active test
7182025-03-18T16:55:32.654ZCompleted test: replace-before-active
7192025-03-18T16:55:32.654ZAll tests have completed, stopping all downstairs
7202025-03-18T16:55:32.711Z
7212025-03-18T16:55:32.711ZAll Tests have passed
7222025-03-18T16:55:32.714Z13:26 Test duration
7232025-03-18T16:55:32.714Z
7242025-03-18T16:55:32.714Zreal 13:26.403119107
7252025-03-18T16:55:32.714Zuser 18:40.194447209
7262025-03-18T16:55:32.714Zsys 24.277085522
7272025-03-18T16:55:32.714Ztrap 0.517030648
7282025-03-18T16:55:32.715Ztflt 0.041048486
7292025-03-18T16:55:32.715Zdflt 0.044265237
7302025-03-18T16:55:32.715Zkflt 0.001092840
7312025-03-18T16:55:32.715Zlock 25:45:26.177146540
7322025-03-18T16:55:32.715Zslp 1:14:52.535768948
7332025-03-18T16:55:32.715Zlat 2:00.077503612
7342025-03-18T16:55:32.715Zstop 0.198193889
7352025-03-18T16:55:32.715Z+ echo 'test-up-2region-encrypted ends'
7362025-03-18T16:55:32.715Ztest-up-2region-encrypted ends
7372025-03-18T16:55:37.719Zprocess exited: duration 814888 ms, exit code 0
7382025-03-18T16:55:37.719Zexec warning: : stdio descriptors remain open after task exit; waiting 60 seconds for them to close
7392025-03-18T16:56:37.774Zexec warning: : stdout descriptor may be held open by a background process; giving up!
7402025-03-18T16:56:37.774Zexec warning: : stderr descriptor may be held open by a background process; giving up!
 
7412025-03-18T16:56:37.788Zfound 17 output files
7422025-03-18T16:56:37.788Zuploading: /tmp/test_up-build/dsc-out.txt (49356 bytes)
7432025-03-18T16:56:38.804Zuploaded: /tmp/test_up-build/dsc-out.txt
7442025-03-18T16:56:38.813Zuploading: /tmp/test_up-build/test_up_out.txt (8572169 bytes)
7452025-03-18T16:56:39.949Zuploaded: /tmp/test_up-build/test_up_out.txt
7462025-03-18T16:56:39.953Zuploading: /tmp/test_up-build/dsc/downstairs-8810.txt (147248 bytes)
7472025-03-18T16:56:40.969Zuploaded: /tmp/test_up-build/dsc/downstairs-8810.txt
7482025-03-18T16:56:40.972Zuploading: /tmp/test_up-build/dsc/downstairs-8820.txt (144661 bytes)
7492025-03-18T16:56:41.987Zuploaded: /tmp/test_up-build/dsc/downstairs-8820.txt
7502025-03-18T16:56:41.990Zuploading: /tmp/test_up-build/dsc/downstairs-8830.txt (250971 bytes)
7512025-03-18T16:56:43.008Zuploaded: /tmp/test_up-build/dsc/downstairs-8830.txt
7522025-03-18T16:56:43.011Zuploading: /tmp/test_up-build/dsc/downstairs-8840.txt (139426 bytes)
7532025-03-18T16:56:44.026Zuploaded: /tmp/test_up-build/dsc/downstairs-8840.txt
7542025-03-18T16:56:44.029Zuploading: /tmp/test_up-build/dsc/downstairs-8850.txt (358042 bytes)
7552025-03-18T16:56:45.062Zuploaded: /tmp/test_up-build/dsc/downstairs-8850.txt
7562025-03-18T16:56:45.065Zuploading: /tmp/test_up-build/dsc/downstairs-8860.txt (33795 bytes)
7572025-03-18T16:56:46.077Zuploaded: /tmp/test_up-build/dsc/downstairs-8860.txt
7582025-03-18T16:56:46.080Zuploading: /tmp/test_up-build/dsc/downstairs-8870.txt (735595 bytes)
7592025-03-18T16:56:47.127Zuploaded: /tmp/test_up-build/dsc/downstairs-8870.txt
7602025-03-18T16:56:47.131Zuploading: /tmp/debug/df.txt (1270 bytes)
7612025-03-18T16:56:48.141Zuploaded: /tmp/debug/df.txt
7622025-03-18T16:56:48.144Zuploading: /tmp/debug/dtrace.txt (934103 bytes)
7632025-03-18T16:56:49.204Zuploaded: /tmp/debug/dtrace.txt
7642025-03-18T16:56:49.208Zuploading: /tmp/debug/iostat.txt (259915 bytes)
7652025-03-18T16:56:49.233Zupload warning: file "/tmp/debug/iostat.txt" changed size mid upload: 259915 -> 263193
7662025-03-18T16:56:50.241Zuploaded: /tmp/debug/iostat.txt
7672025-03-18T16:56:50.241Zuploading: /tmp/debug/mpstat.txt (633955 bytes)
7682025-03-18T16:56:50.285Zupload warning: file "/tmp/debug/mpstat.txt" changed size mid upload: 633955 -> 642679
7692025-03-18T16:56:51.293Zuploaded: /tmp/debug/mpstat.txt
7702025-03-18T16:56:51.293Zuploading: /tmp/debug/paging.txt (112440 bytes)
7712025-03-18T16:56:51.310Zupload warning: file "/tmp/debug/paging.txt" changed size mid upload: 112440 -> 114067
7722025-03-18T16:56:52.318Zuploaded: /tmp/debug/paging.txt
7732025-03-18T16:56:52.322Zuploading: /tmp/debug/prstat.txt (1234687 bytes)
7742025-03-18T16:56:52.379Zupload warning: file "/tmp/debug/prstat.txt" changed size mid upload: 1234687 -> 1252786
7752025-03-18T16:56:53.387Zuploaded: /tmp/debug/prstat.txt
7762025-03-18T16:56:53.388Zuploading: /tmp/debug/psrinfo.txt (1528 bytes)
7772025-03-18T16:56:54.399Zuploaded: /tmp/debug/psrinfo.txt
7782025-03-18T16:56:54.402Zuploading: /tmp/debug/upstairs-info.txt (180400 bytes)
7792025-03-18T16:56:55.427Zuploaded: /tmp/debug/upstairs-info.txt