01JPMW42TK24BZGG6BWDCSA8NA: test-up-encrypted

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

Buildomat Job: 01JPMW4EB2Q5634E1NNHY6M6A3

Tags:

Artefacts:

Output:

SEQ GLOBAL TIME DETAILS
12025-03-18T15:11:24.544Zjob dependencies complete; ready to run (waiting for 14 m 11 s)
22025-03-18T15:12:19.790Zjob assigned to worker 01JPMWYMFERKMJPH1PTRHF4EXH [factory aws, i-0da2548f729ef4ee7] (queued for 55 s)
32025-03-18T15:12:28.860Zdownloading input: /input/build/work/bins/crucible-downstairs.gz
42025-03-18T15:12:30.176Zdownloaded input: /input/build/work/bins/crucible-downstairs.gz
52025-03-18T15:12:30.176Zdownloading input: /input/build/work/bins/crucible-hammer.gz
62025-03-18T15:12:31.473Zdownloaded input: /input/build/work/bins/crucible-hammer.gz
72025-03-18T15:12:31.473Zdownloading input: /input/build/work/bins/crutest.gz
82025-03-18T15:12:32.699Zdownloaded input: /input/build/work/bins/crutest.gz
92025-03-18T15:12:32.699Zdownloading input: /input/build/work/bins/dsc.gz
102025-03-18T15:12:33.613Zdownloaded input: /input/build/work/bins/dsc.gz
112025-03-18T15:12:33.616Zdownloading input: /input/build/work/scripts/perf-downstairs-tick.d
122025-03-18T15:12:33.633Zdownloaded input: /input/build/work/scripts/perf-downstairs-tick.d
132025-03-18T15:12:33.633Zdownloading input: /input/build/work/scripts/test_ds.sh
142025-03-18T15:12:33.651Zdownloaded input: /input/build/work/scripts/test_ds.sh
152025-03-18T15:12:33.651Zdownloading input: /input/build/work/scripts/test_live_repair.sh
162025-03-18T15:12:33.670Zdownloaded input: /input/build/work/scripts/test_live_repair.sh
172025-03-18T15:12:33.670Zdownloading input: /input/build/work/scripts/test_repair.sh
182025-03-18T15:12:33.689Zdownloaded input: /input/build/work/scripts/test_repair.sh
192025-03-18T15:12:33.689Zdownloading input: /input/build/work/scripts/test_replay.sh
202025-03-18T15:12:33.705Zdownloaded input: /input/build/work/scripts/test_replay.sh
212025-03-18T15:12:33.705Zdownloading input: /input/build/work/scripts/test_up.sh
222025-03-18T15:12:33.726Zdownloaded input: /input/build/work/scripts/test_up.sh
232025-03-18T15:12:33.726Zdownloading input: /input/build/work/scripts/upstairs_info.d
242025-03-18T15:12:33.748Zdownloaded input: /input/build/work/scripts/upstairs_info.d
252025-03-18T15:12:33.751Zdownloading input: /input/build/tmp/cargo-test-out.log
262025-03-18T15:12:34.657Zdownloaded input: /input/build/tmp/cargo-test-out.log
 
272025-03-18T15:12:34.657Zstarting task 0: "setup"
282025-03-18T15:12:34.665Z++ uname -s
292025-03-18T15:12:34.674Z+ kern=SunOS
302025-03-18T15:12:34.674Z+ build_user=build
312025-03-18T15:12:34.674Z+ build_uid=12345
322025-03-18T15:12:34.674Z+ work_dir=/work
332025-03-18T15:12:34.675Z+ input_dir=/input
342025-03-18T15:12:34.675Z+ [[ 0 == 12345 ]]
352025-03-18T15:12:34.675Z+ case "$kern" in
362025-03-18T15:12:34.675Z+ groupadd -g 12345 build
372025-03-18T15:12:34.675Z+ useradd -u 12345 -g build -d /home/build -s /bin/bash -c build -P 'Primary Administrator' build
382025-03-18T15:12:36.677Z+ zfs create -o mountpoint=/work rpool/work
392025-03-18T15:12:36.943Z++ awk '$2 == "/home" { print $3 }' /etc/mnttab
402025-03-18T15:12:36.947Z+ home_fs=zfs
412025-03-18T15:12:36.947Z+ [[ zfs == autofs ]]
422025-03-18T15:12:36.947Z+ mkdir -p /home/build
432025-03-18T15:12:36.951Z+ chown build:build /home/build /work
442025-03-18T15:12:37.950Z+ chmod 0700 /home/build /work
452025-03-18T15:12:37.954Zprocess exited: duration 3297 ms, exit code 0
 
462025-03-18T15:12:37.961Zstarting task 1: "authentication"
472025-03-18T15:12:37.982Zprocess exited: duration 20 ms, exit code 0
 
482025-03-18T15:12:37.989Zstarting task 2: "build"
492025-03-18T15:12:37.995Z+ banner cores
502025-03-18T15:12:38.009Z
512025-03-18T15:12:38.010Z #### #### ##### ###### ####
522025-03-18T15:12:38.010Z # # # # # # # #
532025-03-18T15:12:38.013Z # # # # # ##### ####
542025-03-18T15:12:38.014Z # # # ##### # #
552025-03-18T15:12:38.014Z # # # # # # # # #
562025-03-18T15:12:38.014Z #### #### # # ###### ####
572025-03-18T15:12:38.014Z
582025-03-18T15:12:38.014Z+ pfexec coreadm -i /tmp/core.%f.%p -g /tmp/core.%f.%p -e global -e log -e proc-setid -e global-setid
592025-03-18T15:12:38.019Z+ echo 'input bins dir contains:'
602025-03-18T15:12:38.019Zinput bins dir contains:
612025-03-18T15:12:38.022Z+ ls -ltr /input/build/work/bins
622025-03-18T15:12:38.022Ztotal 794998
632025-03-18T15:12:38.022Z-rw-r--r-- 1 root root 118598220 Mar 18 15:12 crucible-downstairs.gz
642025-03-18T15:12:38.023Z-rw-r--r-- 1 root root 106365330 Mar 18 15:12 crucible-hammer.gz
652025-03-18T15:12:38.023Z-rw-r--r-- 1 root root 115625406 Mar 18 15:12 crutest.gz
662025-03-18T15:12:38.023Z-rw-r--r-- 1 root root 66179735 Mar 18 15:12 dsc.gz
672025-03-18T15:12:38.023Z+ banner unpack
682025-03-18T15:12:38.027Z
692025-03-18T15:12:38.027Z # # # # ##### ## #### # #
702025-03-18T15:12:38.027Z # # ## # # # # # # # # #
712025-03-18T15:12:38.027Z # # # # # # # # # # ####
722025-03-18T15:12:38.027Z # # # # # ##### ###### # # #
732025-03-18T15:12:38.027Z # # # ## # # # # # # #
742025-03-18T15:12:38.027Z #### # # # # # #### # #
752025-03-18T15:12:38.027Z
762025-03-18T15:12:38.027Z+ mkdir -p /var/tmp/bins
772025-03-18T15:12:38.031Z+ for t in "$input/bins/"*.gz
782025-03-18T15:12:38.031Z++ basename /input/build/work/bins/crucible-downstairs.gz
792025-03-18T15:12:38.031Z+ b=crucible-downstairs.gz
802025-03-18T15:12:38.031Z+ b=crucible-downstairs
812025-03-18T15:12:38.031Z+ gunzip
822025-03-18T15:12:40.495Z+ chmod +x /var/tmp/bins/crucible-downstairs
832025-03-18T15:12:40.498Z+ for t in "$input/bins/"*.gz
842025-03-18T15:12:40.502Z++ basename /input/build/work/bins/crucible-hammer.gz
852025-03-18T15:12:40.502Z+ b=crucible-hammer.gz
862025-03-18T15:12:40.502Z+ b=crucible-hammer
872025-03-18T15:12:40.502Z+ gunzip
882025-03-18T15:12:42.749Z+ chmod +x /var/tmp/bins/crucible-hammer
892025-03-18T15:12:42.753Z+ for t in "$input/bins/"*.gz
902025-03-18T15:12:42.756Z++ basename /input/build/work/bins/crutest.gz
912025-03-18T15:12:42.756Z+ b=crutest.gz
922025-03-18T15:12:42.756Z+ b=crutest
932025-03-18T15:12:42.756Z+ gunzip
942025-03-18T15:12:45.156Z+ chmod +x /var/tmp/bins/crutest
952025-03-18T15:12:45.159Z+ for t in "$input/bins/"*.gz
962025-03-18T15:12:45.159Z++ basename /input/build/work/bins/dsc.gz
972025-03-18T15:12:45.162Z+ b=dsc.gz
982025-03-18T15:12:45.162Z+ b=dsc
992025-03-18T15:12:45.163Z+ gunzip
1002025-03-18T15:12:46.588Z+ chmod +x /var/tmp/bins/dsc
1012025-03-18T15:12:46.592Z+ export BINDIR=/var/tmp/bins
1022025-03-18T15:12:46.592Z+ BINDIR=/var/tmp/bins
1032025-03-18T15:12:46.592Z+ export RUST_BACKTRACE=1
1042025-03-18T15:12:46.592Z+ RUST_BACKTRACE=1
1052025-03-18T15:12:46.592Z+ jobpid=1147
1062025-03-18T15:12:46.595Z+ echo 'Setup debug logging'
1072025-03-18T15:12:46.595ZSetup debug logging
1082025-03-18T15:12:46.595Z+ mkdir /tmp/debug
1092025-03-18T15:12:46.595Z+ sleep 3600
1102025-03-18T15:12:46.595Z+ psrinfo -v
1112025-03-18T15:12:46.598Z+ df -h
1122025-03-18T15:12:46.620Z+ prstat -d d -mLc 1
1132025-03-18T15:12:46.623Z+ iostat -T d -xn 1
1142025-03-18T15:12:46.623Z+ mpstat -T d 1
1152025-03-18T15:12:46.623Z+ vmstat -T d -p 1
1162025-03-18T15:12:46.623Z+ pfexec dtrace -Z -s /input/build/work/scripts/perf-downstairs-tick.d
1172025-03-18T15:12:46.626Z+ banner test_up_encrypted
1182025-03-18T15:12:46.626Z+ pfexec dtrace -Z -s /input/build/work/scripts/upstairs_info.d
1192025-03-18T15:12:46.626Z
1202025-03-18T15:12:46.626Z ##### ###### #### ##### # # ##### ###### # #
1212025-03-18T15:12:46.626Z # # # # # # # # # ## #
1222025-03-18T15:12:46.626Z # ##### #### # # # # # ##### # # #
1232025-03-18T15:12:46.626Z # # # # # # ##### # # # #
1242025-03-18T15:12:46.626Z # # # # # # # # # # ##
1252025-03-18T15:12:46.626Z # ###### #### # ####### #### # ####### ###### # #
1262025-03-18T15:12:46.626Z
1272025-03-18T15:12:46.626Z+ ptime -m bash /input/build/work/scripts/test_up.sh -N encrypted
1282025-03-18T15:12:46.638Z/input/build/work
1292025-03-18T15:12:46.663ZTurn off color for downstairs dump
1302025-03-18T15:12:46.690ZUpstairs using key: qRwlisSXLB+O+Do4pZaAHY5s4Y94pYcqRtknqy5v5gA=
1312025-03-18T15:12:46.693Zdsc output goes to /tmp/test_up-build/dsc-out.txt
1322025-03-18T15:12:46.693ZCreating 3 downstairs regions
1332025-03-18T15:12:47.005ZStarting 3 downstairs
1342025-03-18T15:12:47.008Zdsc started at PID: 1193
1352025-03-18T15:12:52.201ZDisable automatic restart on all downstairs
1362025-03-18T15:12:52.260Z
1372025-03-18T15:12:52.260ZBegin tests, output goes to /tmp/test_up-build/test_up_out.txt
1382025-03-18T15:12:52.264ZRunning test: span
1392025-03-18T15:12:56.379ZCompleted test: span
1402025-03-18T15:13:01.387ZRunning test: big
1412025-03-18T15:13:05.710ZCompleted test: big
1422025-03-18T15:13:10.717ZRunning test: dep
1432025-03-18T15:14:04.119ZCompleted test: dep
1442025-03-18T15:14:09.127ZRunning test: balloon
1452025-03-18T15:14:50.500ZCompleted test: balloon
1462025-03-18T15:14:55.507ZRunning test: deactivate
1472025-03-18T15:15:50.225ZCompleted test: deactivate
1482025-03-18T15:15:55.232ZRunning hammer
1492025-03-18T15:16:08.183ZRun repair tests
1502025-03-18T15:16:08.186Z/var/tmp/bins/crutest fill -g 31 -q --key qRwlisSXLB+O+Do4pZaAHY5s4Y94pYcqRtknqy5v5gA= --dsc 127.0.0.1:9998 --verify-out /var/tmp/test_up-build/verify_file
1512025-03-18T15:16:08.245Z{"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-18T15:16:07.350688199Z","hostname":"w-01JPMWYMFERKMJPH1PTRHF4EXH","pid":1230,"task":"crutest"}
1522025-03-18T15:16:08.249Z{"msg":"dsc has 3 regions. This means 1 sub_volumes","v":0,"name":"crucible","level":30,"time":"2025-03-18T15:16:07.351277939Z","hostname":"w-01JPMWYMFERKMJPH1PTRHF4EXH","pid":1230,"task":"crutest"}
1532025-03-18T15:16:08.249Z{"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-18T15:16:07.353031549Z","hostname":"w-01JPMWYMFERKMJPH1PTRHF4EXH","pid":1230,"task":"crutest"}
1542025-03-18T15:16:08.249Z{"msg":"Upstairs starts","v":0,"name":"crucible","level":30,"time":"2025-03-18T15:16:07.353257584Z","hostname":"w-01JPMWYMFERKMJPH1PTRHF4EXH","pid":1230}
1552025-03-18T15:16:08.249Z{"msg":"Crucible Version: BuildInfo {\n version: \"0.0.1\",\n git_sha: \"a70f3a885a6160c78d68c43ecf4da40ad9a7b327\",\n git_commit_timestamp: \"2025-03-18T14:56:23.000000000Z\",\n git_branch: \"main\",\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-18T15:16:07.353297031Z","hostname":"w-01JPMWYMFERKMJPH1PTRHF4EXH","pid":1230}
1562025-03-18T15:16:08.249Z{"msg":"Upstairs <-> Downstairs Message Version: 13","v":0,"name":"crucible","level":30,"time":"2025-03-18T15:16:07.35331881Z","hostname":"w-01JPMWYMFERKMJPH1PTRHF4EXH","pid":1230}
1572025-03-18T15:16:08.249Z{"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-18T15:16:07.353334079Z","hostname":"w-01JPMWYMFERKMJPH1PTRHF4EXH","pid":1230}
1582025-03-18T15:16:08.249Z{"msg":"Crucible c1033b9a-0020-4ddf-9303-ef667a3993c1 has session id: 2a7cc94d-30a1-45dd-99b3-c8c5ff0095de","v":0,"name":"crucible","level":30,"time":"2025-03-18T15:16:07.354035181Z","hostname":"w-01JPMWYMFERKMJPH1PTRHF4EXH","pid":1230,"session_id":"2a7cc94d-30a1-45dd-99b3-c8c5ff0095de"}
1592025-03-18T15:16:08.249Z{"msg":"Upstairs opts: Upstairs UUID: c1033b9a-0020-4ddf-9303-ef667a3993c1, 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-18T15:16:07.354072468Z","hostname":"w-01JPMWYMFERKMJPH1PTRHF4EXH","pid":1230,"session_id":"2a7cc94d-30a1-45dd-99b3-c8c5ff0095de"}
1602025-03-18T15:16:08.249Z{"msg":"Crucible stats registered with UUID: c1033b9a-0020-4ddf-9303-ef667a3993c1","v":0,"name":"crucible","level":30,"time":"2025-03-18T15:16:07.354088007Z","hostname":"w-01JPMWYMFERKMJPH1PTRHF4EXH","pid":1230,"session_id":"2a7cc94d-30a1-45dd-99b3-c8c5ff0095de"}
1612025-03-18T15:16:08.249Z{"msg":"could not find Downstairs address for Nexus","v":0,"name":"crucible","level":40,"time":"2025-03-18T15:16:07.354101676Z","hostname":"w-01JPMWYMFERKMJPH1PTRHF4EXH","pid":1230,"session_id":"2a7cc94d-30a1-45dd-99b3-c8c5ff0095de"}
1622025-03-18T15:16:08.252Z{"msg":"Downstairs in volume = 3","v":0,"name":"crucible","level":30,"time":"2025-03-18T15:16:07.355465164Z","hostname":"w-01JPMWYMFERKMJPH1PTRHF4EXH","pid":1230,"task":"crutest"}
1632025-03-18T15:16:08.252Z{"msg":"The guest has requested activation with gen:31","v":0,"name":"crucible","level":30,"time":"2025-03-18T15:16:07.355555627Z","hostname":"w-01JPMWYMFERKMJPH1PTRHF4EXH","pid":1230}
1642025-03-18T15:16:08.252Z{"msg":"c1033b9a-0020-4ddf-9303-ef667a3993c1 active request set","v":0,"name":"crucible","level":30,"time":"2025-03-18T15:16:07.355621383Z","hostname":"w-01JPMWYMFERKMJPH1PTRHF4EXH","pid":1230,"session_id":"2a7cc94d-30a1-45dd-99b3-c8c5ff0095de"}
1652025-03-18T15:16:08.252Z{"msg":"sending connect oneshot to client","v":0,"name":"crucible","level":30,"time":"2025-03-18T15:16:07.355672589Z","hostname":"w-01JPMWYMFERKMJPH1PTRHF4EXH","pid":1230,"client":"0","":"downstairs","session_id":"2a7cc94d-30a1-45dd-99b3-c8c5ff0095de"}
1662025-03-18T15:16:08.252Z{"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-18T15:16:07.355730325Z","hostname":"w-01JPMWYMFERKMJPH1PTRHF4EXH","pid":1230,"client":"0","":"downstairs","session_id":"2a7cc94d-30a1-45dd-99b3-c8c5ff0095de"}
1672025-03-18T15:16:08.252Z{"msg":"sending connect oneshot to client","v":0,"name":"crucible","level":30,"time":"2025-03-18T15:16:07.355765483Z","hostname":"w-01JPMWYMFERKMJPH1PTRHF4EXH","pid":1230,"client":"1","":"downstairs","session_id":"2a7cc94d-30a1-45dd-99b3-c8c5ff0095de"}
1682025-03-18T15:16:08.252Z{"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-18T15:16:07.35581488Z","hostname":"w-01JPMWYMFERKMJPH1PTRHF4EXH","pid":1230,"client":"1","":"downstairs","session_id":"2a7cc94d-30a1-45dd-99b3-c8c5ff0095de"}
1692025-03-18T15:16:08.253Z{"msg":"sending connect oneshot to client","v":0,"name":"crucible","level":30,"time":"2025-03-18T15:16:07.355838928Z","hostname":"w-01JPMWYMFERKMJPH1PTRHF4EXH","pid":1230,"client":"2","":"downstairs","session_id":"2a7cc94d-30a1-45dd-99b3-c8c5ff0095de"}
1702025-03-18T15:16:08.253Z{"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-18T15:16:07.355866146Z","hostname":"w-01JPMWYMFERKMJPH1PTRHF4EXH","pid":1230,"client":"2","":"downstairs","session_id":"2a7cc94d-30a1-45dd-99b3-c8c5ff0095de"}
1712025-03-18T15:16:08.253Z{"msg":"connecting to 127.0.0.1:8830","v":0,"name":"crucible","level":30,"time":"2025-03-18T15:16:07.355880995Z","hostname":"w-01JPMWYMFERKMJPH1PTRHF4EXH","pid":1230,"":"io task","client":"2","":"downstairs","session_id":"2a7cc94d-30a1-45dd-99b3-c8c5ff0095de"}
1722025-03-18T15:16:08.253Z{"msg":"connecting to 127.0.0.1:8810","v":0,"name":"crucible","level":30,"time":"2025-03-18T15:16:07.355915583Z","hostname":"w-01JPMWYMFERKMJPH1PTRHF4EXH","pid":1230,"":"io task","client":"0","":"downstairs","session_id":"2a7cc94d-30a1-45dd-99b3-c8c5ff0095de"}
1732025-03-18T15:16:08.253Z{"msg":"connecting to 127.0.0.1:8820","v":0,"name":"crucible","level":30,"time":"2025-03-18T15:16:07.355938561Z","hostname":"w-01JPMWYMFERKMJPH1PTRHF4EXH","pid":1230,"":"io task","client":"1","":"downstairs","session_id":"2a7cc94d-30a1-45dd-99b3-c8c5ff0095de"}
1742025-03-18T15:16:08.253Z{"msg":"ds_connection connected from Ok(127.0.0.1:62478)","v":0,"name":"crucible","level":30,"time":"2025-03-18T15:16:07.35596149Z","hostname":"w-01JPMWYMFERKMJPH1PTRHF4EXH","pid":1230,"":"io task","client":"0","":"downstairs","session_id":"2a7cc94d-30a1-45dd-99b3-c8c5ff0095de"}
1752025-03-18T15:16:08.253Z{"msg":"ds_connection connected from Ok(127.0.0.1:41413)","v":0,"name":"crucible","level":30,"time":"2025-03-18T15:16:07.35624806Z","hostname":"w-01JPMWYMFERKMJPH1PTRHF4EXH","pid":1230,"":"io task","client":"2","":"downstairs","session_id":"2a7cc94d-30a1-45dd-99b3-c8c5ff0095de"}
1762025-03-18T15:16:08.253Z{"msg":"ds_connection connected from Ok(127.0.0.1:58157)","v":0,"name":"crucible","level":30,"time":"2025-03-18T15:16:07.356324745Z","hostname":"w-01JPMWYMFERKMJPH1PTRHF4EXH","pid":1230,"":"io task","client":"1","":"downstairs","session_id":"2a7cc94d-30a1-45dd-99b3-c8c5ff0095de"}
1772025-03-18T15:16:08.253Z{"msg":"version negotiation from state Connecting { state: WaitForPromote, mode: New }","v":0,"name":"crucible","level":30,"time":"2025-03-18T15:16:07.356921514Z","hostname":"w-01JPMWYMFERKMJPH1PTRHF4EXH","pid":1230,"client":"1","":"downstairs","session_id":"2a7cc94d-30a1-45dd-99b3-c8c5ff0095de"}
1782025-03-18T15:16:08.253Z{"msg":"version negotiation from state Connecting { state: WaitForPromote, mode: New }","v":0,"name":"crucible","level":30,"time":"2025-03-18T15:16:07.356962841Z","hostname":"w-01JPMWYMFERKMJPH1PTRHF4EXH","pid":1230,"client":"2","":"downstairs","session_id":"2a7cc94d-30a1-45dd-99b3-c8c5ff0095de"}
1792025-03-18T15:16:08.253Z{"msg":"version negotiation from state Connecting { state: WaitForPromote, mode: New }","v":0,"name":"crucible","level":30,"time":"2025-03-18T15:16:07.35698075Z","hostname":"w-01JPMWYMFERKMJPH1PTRHF4EXH","pid":1230,"client":"0","":"downstairs","session_id":"2a7cc94d-30a1-45dd-99b3-c8c5ff0095de"}
1802025-03-18T15:16:08.253Z{"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-18T15:16:07.357624686Z","hostname":"w-01JPMWYMFERKMJPH1PTRHF4EXH","pid":1230,"client":"1","":"downstairs","session_id":"2a7cc94d-30a1-45dd-99b3-c8c5ff0095de"}
1812025-03-18T15:16:08.253Z{"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-18T15:16:07.357668783Z","hostname":"w-01JPMWYMFERKMJPH1PTRHF4EXH","pid":1230,"client":"0","":"downstairs","session_id":"2a7cc94d-30a1-45dd-99b3-c8c5ff0095de"}
1822025-03-18T15:16:08.253Z{"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-18T15:16:07.357684422Z","hostname":"w-01JPMWYMFERKMJPH1PTRHF4EXH","pid":1230,"client":"2","":"downstairs","session_id":"2a7cc94d-30a1-45dd-99b3-c8c5ff0095de"}
1832025-03-18T15:16:08.256Z{"msg":"Waiting for more clients to be ready","v":0,"name":"crucible","level":30,"time":"2025-03-18T15:16:07.358132602Z","hostname":"w-01JPMWYMFERKMJPH1PTRHF4EXH","pid":1230,"session_id":"2a7cc94d-30a1-45dd-99b3-c8c5ff0095de"}
1842025-03-18T15:16:08.256Z{"msg":"Waiting for more clients to be ready","v":0,"name":"crucible","level":30,"time":"2025-03-18T15:16:07.358171739Z","hostname":"w-01JPMWYMFERKMJPH1PTRHF4EXH","pid":1230,"session_id":"2a7cc94d-30a1-45dd-99b3-c8c5ff0095de"}
1852025-03-18T15:16:08.256Z{"msg":"[0]R flush_numbers: [1505, 1505, 1505, 1505, 1505]","v":0,"name":"crucible","level":30,"time":"2025-03-18T15:16:07.358227135Z","hostname":"w-01JPMWYMFERKMJPH1PTRHF4EXH","pid":1230,"":"downstairs","":"downstairs","session_id":"2a7cc94d-30a1-45dd-99b3-c8c5ff0095de"}
1862025-03-18T15:16:08.256Z{"msg":"[0]R generation: [25, 25, 25, 25, 25]","v":0,"name":"crucible","level":30,"time":"2025-03-18T15:16:07.358262213Z","hostname":"w-01JPMWYMFERKMJPH1PTRHF4EXH","pid":1230,"":"downstairs","":"downstairs","session_id":"2a7cc94d-30a1-45dd-99b3-c8c5ff0095de"}
1872025-03-18T15:16:08.256Z{"msg":"[0]R dirty: [false, false, false, false, false]","v":0,"name":"crucible","level":30,"time":"2025-03-18T15:16:07.358279842Z","hostname":"w-01JPMWYMFERKMJPH1PTRHF4EXH","pid":1230,"":"downstairs","":"downstairs","session_id":"2a7cc94d-30a1-45dd-99b3-c8c5ff0095de"}
1882025-03-18T15:16:08.257Z{"msg":"[1]R flush_numbers: [1505, 1505, 1505, 1505, 1505]","v":0,"name":"crucible","level":30,"time":"2025-03-18T15:16:07.35830131Z","hostname":"w-01JPMWYMFERKMJPH1PTRHF4EXH","pid":1230,"":"downstairs","":"downstairs","session_id":"2a7cc94d-30a1-45dd-99b3-c8c5ff0095de"}
1892025-03-18T15:16:08.257Z{"msg":"[1]R generation: [25, 25, 25, 25, 25]","v":0,"name":"crucible","level":30,"time":"2025-03-18T15:16:07.358315319Z","hostname":"w-01JPMWYMFERKMJPH1PTRHF4EXH","pid":1230,"":"downstairs","":"downstairs","session_id":"2a7cc94d-30a1-45dd-99b3-c8c5ff0095de"}
1902025-03-18T15:16:08.257Z{"msg":"[1]R dirty: [false, false, false, false, false]","v":0,"name":"crucible","level":30,"time":"2025-03-18T15:16:07.358335928Z","hostname":"w-01JPMWYMFERKMJPH1PTRHF4EXH","pid":1230,"":"downstairs","":"downstairs","session_id":"2a7cc94d-30a1-45dd-99b3-c8c5ff0095de"}
1912025-03-18T15:16:08.257Z{"msg":"[2]R flush_numbers: [1505, 1505, 1505, 1505, 1505]","v":0,"name":"crucible","level":30,"time":"2025-03-18T15:16:07.358349607Z","hostname":"w-01JPMWYMFERKMJPH1PTRHF4EXH","pid":1230,"":"downstairs","":"downstairs","session_id":"2a7cc94d-30a1-45dd-99b3-c8c5ff0095de"}
1922025-03-18T15:16:08.257Z{"msg":"[2]R generation: [25, 25, 25, 25, 25]","v":0,"name":"crucible","level":30,"time":"2025-03-18T15:16:07.358369555Z","hostname":"w-01JPMWYMFERKMJPH1PTRHF4EXH","pid":1230,"":"downstairs","":"downstairs","session_id":"2a7cc94d-30a1-45dd-99b3-c8c5ff0095de"}
1932025-03-18T15:16:08.257Z{"msg":"[2]R dirty: [false, false, false, false, false]","v":0,"name":"crucible","level":30,"time":"2025-03-18T15:16:07.358383045Z","hostname":"w-01JPMWYMFERKMJPH1PTRHF4EXH","pid":1230,"":"downstairs","":"downstairs","session_id":"2a7cc94d-30a1-45dd-99b3-c8c5ff0095de"}
1942025-03-18T15:16:08.257Z{"msg":"Max found gen is 26","v":0,"name":"crucible","level":30,"time":"2025-03-18T15:16:07.358402523Z","hostname":"w-01JPMWYMFERKMJPH1PTRHF4EXH","pid":1230,"":"downstairs","":"downstairs","session_id":"2a7cc94d-30a1-45dd-99b3-c8c5ff0095de"}
1952025-03-18T15:16:08.257Z{"msg":"Generation requested: 31 >= found:26","v":0,"name":"crucible","level":30,"time":"2025-03-18T15:16:07.358415503Z","hostname":"w-01JPMWYMFERKMJPH1PTRHF4EXH","pid":1230,"":"downstairs","":"downstairs","session_id":"2a7cc94d-30a1-45dd-99b3-c8c5ff0095de"}
1962025-03-18T15:16:08.257Z{"msg":"Next flush: 1506","v":0,"name":"crucible","level":30,"time":"2025-03-18T15:16:07.358438261Z","hostname":"w-01JPMWYMFERKMJPH1PTRHF4EXH","pid":1230,"":"downstairs","":"downstairs","session_id":"2a7cc94d-30a1-45dd-99b3-c8c5ff0095de"}
1972025-03-18T15:16:08.257Z{"msg":"All extents match","v":0,"name":"crucible","level":30,"time":"2025-03-18T15:16:07.35845918Z","hostname":"w-01JPMWYMFERKMJPH1PTRHF4EXH","pid":1230,"":"downstairs","":"downstairs","session_id":"2a7cc94d-30a1-45dd-99b3-c8c5ff0095de"}
1982025-03-18T15:16:08.257ZWait for a query_work_queue command to finish before sending IO
1992025-03-18T15:16:08.257Z{"msg":"No downstairs reconciliation required","v":0,"name":"crucible","level":30,"time":"2025-03-18T15:16:07.358498917Z","hostname":"w-01JPMWYMFERKMJPH1PTRHF4EXH","pid":1230,"session_id":"2a7cc94d-30a1-45dd-99b3-c8c5ff0095de"}
2002025-03-18T15:16:08.257Z{"msg":"Transition from WaitQuorum to Active","v":0,"name":"crucible","level":30,"time":"2025-03-18T15:16:07.358532564Z","hostname":"w-01JPMWYMFERKMJPH1PTRHF4EXH","pid":1230,"client":"0","":"downstairs","session_id":"2a7cc94d-30a1-45dd-99b3-c8c5ff0095de"}
2012025-03-18T15:16:08.257Z{"msg":"Transition from WaitQuorum to Active","v":0,"name":"crucible","level":30,"time":"2025-03-18T15:16:07.358558113Z","hostname":"w-01JPMWYMFERKMJPH1PTRHF4EXH","pid":1230,"client":"1","":"downstairs","session_id":"2a7cc94d-30a1-45dd-99b3-c8c5ff0095de"}
2022025-03-18T15:16:08.257Z{"msg":"Transition from WaitQuorum to Active","v":0,"name":"crucible","level":30,"time":"2025-03-18T15:16:07.358571552Z","hostname":"w-01JPMWYMFERKMJPH1PTRHF4EXH","pid":1230,"client":"2","":"downstairs","session_id":"2a7cc94d-30a1-45dd-99b3-c8c5ff0095de"}
2032025-03-18T15:16:08.257Z{"msg":"All required reconciliation work is completed","v":0,"name":"crucible","level":30,"time":"2025-03-18T15:16:07.358602Z","hostname":"w-01JPMWYMFERKMJPH1PTRHF4EXH","pid":1230,"session_id":"2a7cc94d-30a1-45dd-99b3-c8c5ff0095de"}
2042025-03-18T15:16:08.257Z{"msg":"Set Downstairs and Upstairs active after reconciliation","v":0,"name":"crucible","level":30,"time":"2025-03-18T15:16:07.358637877Z","hostname":"w-01JPMWYMFERKMJPH1PTRHF4EXH","pid":1230,"session_id":"2a7cc94d-30a1-45dd-99b3-c8c5ff0095de"}
2052025-03-18T15:16:08.257Z{"msg":"c1033b9a-0020-4ddf-9303-ef667a3993c1 is now active with session: 2a7cc94d-30a1-45dd-99b3-c8c5ff0095de","v":0,"name":"crucible","level":30,"time":"2025-03-18T15:16:07.358654276Z","hostname":"w-01JPMWYMFERKMJPH1PTRHF4EXH","pid":1230,"session_id":"2a7cc94d-30a1-45dd-99b3-c8c5ff0095de"}
2062025-03-18T15:16:08.257Z{"msg":"Set Active after no reconciliation","v":0,"name":"crucible","level":30,"time":"2025-03-18T15:16:07.358678114Z","hostname":"w-01JPMWYMFERKMJPH1PTRHF4EXH","pid":1230,"session_id":"2a7cc94d-30a1-45dd-99b3-c8c5ff0095de"}
2072025-03-18T15:16:08.257Z{"msg":"The guest has finished waiting for activation with:31","v":0,"name":"crucible","level":30,"time":"2025-03-18T15:16:07.358710732Z","hostname":"w-01JPMWYMFERKMJPH1PTRHF4EXH","pid":1230}
2082025-03-18T15:16:08.257Z{"msg":"Activated sub_volume c1033b9a-0020-4ddf-9303-ef667a3993c1","v":0,"name":"crucible","level":30,"time":"2025-03-18T15:16:07.3587424Z","hostname":"w-01JPMWYMFERKMJPH1PTRHF4EXH","pid":1230}
2092025-03-18T15:16:08.257ZDisk: sv:1 bs:4096 ts:204800 tb:50 max_io:50 or 204800
2102025-03-18T15:16:08.257ZFill test
2112025-03-18T15:16:08.293ZRead and Verify all blocks (0..50 range:false)
2122025-03-18T15:16:08.337ZWrote out file "/var/tmp/test_up-build/verify_file"
2132025-03-18T15:16:08.337ZCLIENT: Tests done. All submitted work has been ACK'd
2142025-03-18T15:16:08.337Z----------------------------------------------------------------
2152025-03-18T15:16:08.337Z Crucible gen:31 GIO:true work queues: Upstairs:0 downstairs:1
2162025-03-18T15:16:08.337ZStates: Active Active Active
2172025-03-18T15:16:08.337ZJOBID ACK TYPE BKS/EXT DS:0 DS:1 DS:2 REPLAY
2182025-03-18T15:16:08.340Z 1002 Acked Read 50 Done Done Done false
2192025-03-18T15:16:08.340Z STATES DS:0 DS:1 DS:2 TOTAL
2202025-03-18T15:16:08.340Z Sent 0 0 0 0
2212025-03-18T15:16:08.340Z Done 1 1 1 3
2222025-03-18T15:16:08.340Z Skipped 0 0 0 0
2232025-03-18T15:16:08.340Z Error 0 0 0 0
2242025-03-18T15:16:08.340ZLast Flush: Some(JobId(1001)) Some(JobId(1001)) Some(JobId(1001))
2252025-03-18T15:16:08.340ZDownstairs last five completed: 1001 1000
2262025-03-18T15:16:08.341ZUpstairs last five completed: 1002 1001 1000
2272025-03-18T15:16:08.341ZCLIENT: Up:0 ds:1 act:3
2282025-03-18T15:16:12.342Z----------------------------------------------------------------
2292025-03-18T15:16:12.342Z Crucible gen:31 GIO:true work queues: Upstairs:0 downstairs:0
2302025-03-18T15:16:12.342ZDownstairs last five completed: 1003 1002 1001 1000
2312025-03-18T15:16:12.342ZUpstairs last five completed: 1003 1002 1001 1000
2322025-03-18T15:16:12.342ZCLIENT: Up:0 ds:0 act:3
2332025-03-18T15:16:12.342ZCLIENT: All crucible jobs finished, exiting program
2342025-03-18T15:16:12.350ZRepair setup passed
2352025-03-18T15:16:12.353ZCopy the region for /var/tmp/test_up-build/8830
2362025-03-18T15:16:12.353Zcp -r /var/tmp/test_up-build/8830 /var/tmp/test_up-build/previous
2372025-03-18T15:16:12.357Z/var/tmp/bins/crutest fill -g 32 -q --key qRwlisSXLB+O+Do4pZaAHY5s4Y94pYcqRtknqy5v5gA= --dsc 127.0.0.1:9998 --verify-out /var/tmp/test_up-build/verify_file --verify-in /var/tmp/test_up-build/verify_file
2382025-03-18T15:16:12.415Z{"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-18T15:16:11.519444825Z","hostname":"w-01JPMWYMFERKMJPH1PTRHF4EXH","pid":1236,"task":"crutest"}
2392025-03-18T15:16:12.429Z{"msg":"dsc has 3 regions. This means 1 sub_volumes","v":0,"name":"crucible","level":30,"time":"2025-03-18T15:16:11.519972349Z","hostname":"w-01JPMWYMFERKMJPH1PTRHF4EXH","pid":1236,"task":"crutest"}
2402025-03-18T15:16:12.429Z{"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-18T15:16:11.521679262Z","hostname":"w-01JPMWYMFERKMJPH1PTRHF4EXH","pid":1236,"task":"crutest"}
2412025-03-18T15:16:12.429Z{"msg":"Upstairs starts","v":0,"name":"crucible","level":30,"time":"2025-03-18T15:16:11.521901727Z","hostname":"w-01JPMWYMFERKMJPH1PTRHF4EXH","pid":1236}
2422025-03-18T15:16:12.429Z{"msg":"Crucible Version: BuildInfo {\n version: \"0.0.1\",\n git_sha: \"a70f3a885a6160c78d68c43ecf4da40ad9a7b327\",\n git_commit_timestamp: \"2025-03-18T14:56:23.000000000Z\",\n git_branch: \"main\",\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-18T15:16:11.521940895Z","hostname":"w-01JPMWYMFERKMJPH1PTRHF4EXH","pid":1236}
2432025-03-18T15:16:12.429Z{"msg":"Upstairs <-> Downstairs Message Version: 13","v":0,"name":"crucible","level":30,"time":"2025-03-18T15:16:11.521963913Z","hostname":"w-01JPMWYMFERKMJPH1PTRHF4EXH","pid":1236}
2442025-03-18T15:16:12.429Z{"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-18T15:16:11.521979132Z","hostname":"w-01JPMWYMFERKMJPH1PTRHF4EXH","pid":1236}
2452025-03-18T15:16:12.429Z{"msg":"Crucible fd8ac3f1-3a1d-46bc-b8fe-d59262ab2fdd has session id: ce12c9a4-29f2-48f3-b2ca-de0b4b31e787","v":0,"name":"crucible","level":30,"time":"2025-03-18T15:16:11.522686974Z","hostname":"w-01JPMWYMFERKMJPH1PTRHF4EXH","pid":1236,"session_id":"ce12c9a4-29f2-48f3-b2ca-de0b4b31e787"}
2462025-03-18T15:16:12.429Z{"msg":"Upstairs opts: Upstairs UUID: fd8ac3f1-3a1d-46bc-b8fe-d59262ab2fdd, 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-18T15:16:11.52274561Z","hostname":"w-01JPMWYMFERKMJPH1PTRHF4EXH","pid":1236,"session_id":"ce12c9a4-29f2-48f3-b2ca-de0b4b31e787"}
2472025-03-18T15:16:12.429Z{"msg":"Crucible stats registered with UUID: fd8ac3f1-3a1d-46bc-b8fe-d59262ab2fdd","v":0,"name":"crucible","level":30,"time":"2025-03-18T15:16:11.522789047Z","hostname":"w-01JPMWYMFERKMJPH1PTRHF4EXH","pid":1236,"session_id":"ce12c9a4-29f2-48f3-b2ca-de0b4b31e787"}
2482025-03-18T15:16:12.429Z{"msg":"could not find Downstairs address for Nexus","v":0,"name":"crucible","level":40,"time":"2025-03-18T15:16:11.522830954Z","hostname":"w-01JPMWYMFERKMJPH1PTRHF4EXH","pid":1236,"session_id":"ce12c9a4-29f2-48f3-b2ca-de0b4b31e787"}
2492025-03-18T15:16:12.433Z{"msg":"Downstairs in volume = 3","v":0,"name":"crucible","level":30,"time":"2025-03-18T15:16:11.523870153Z","hostname":"w-01JPMWYMFERKMJPH1PTRHF4EXH","pid":1236,"task":"crutest"}
2502025-03-18T15:16:12.433Z{"msg":"The guest has requested activation with gen:32","v":0,"name":"crucible","level":30,"time":"2025-03-18T15:16:11.523931939Z","hostname":"w-01JPMWYMFERKMJPH1PTRHF4EXH","pid":1236}
2512025-03-18T15:16:12.433Z{"msg":"fd8ac3f1-3a1d-46bc-b8fe-d59262ab2fdd active request set","v":0,"name":"crucible","level":30,"time":"2025-03-18T15:16:11.523971376Z","hostname":"w-01JPMWYMFERKMJPH1PTRHF4EXH","pid":1236,"session_id":"ce12c9a4-29f2-48f3-b2ca-de0b4b31e787"}
2522025-03-18T15:16:12.433Z{"msg":"sending connect oneshot to client","v":0,"name":"crucible","level":30,"time":"2025-03-18T15:16:11.524007684Z","hostname":"w-01JPMWYMFERKMJPH1PTRHF4EXH","pid":1236,"client":"0","":"downstairs","session_id":"ce12c9a4-29f2-48f3-b2ca-de0b4b31e787"}
2532025-03-18T15:16:12.433Z{"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-18T15:16:11.52406954Z","hostname":"w-01JPMWYMFERKMJPH1PTRHF4EXH","pid":1236,"client":"0","":"downstairs","session_id":"ce12c9a4-29f2-48f3-b2ca-de0b4b31e787"}
2542025-03-18T15:16:12.433Z{"msg":"sending connect oneshot to client","v":0,"name":"crucible","level":30,"time":"2025-03-18T15:16:11.524126436Z","hostname":"w-01JPMWYMFERKMJPH1PTRHF4EXH","pid":1236,"client":"1","":"downstairs","session_id":"ce12c9a4-29f2-48f3-b2ca-de0b4b31e787"}
2552025-03-18T15:16:12.433Z{"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-18T15:16:11.524154094Z","hostname":"w-01JPMWYMFERKMJPH1PTRHF4EXH","pid":1236,"client":"1","":"downstairs","session_id":"ce12c9a4-29f2-48f3-b2ca-de0b4b31e787"}
2562025-03-18T15:16:12.433Z{"msg":"sending connect oneshot to client","v":0,"name":"crucible","level":30,"time":"2025-03-18T15:16:11.524190651Z","hostname":"w-01JPMWYMFERKMJPH1PTRHF4EXH","pid":1236,"client":"2","":"downstairs","session_id":"ce12c9a4-29f2-48f3-b2ca-de0b4b31e787"}
2572025-03-18T15:16:12.433Z{"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-18T15:16:11.524220339Z","hostname":"w-01JPMWYMFERKMJPH1PTRHF4EXH","pid":1236,"client":"2","":"downstairs","session_id":"ce12c9a4-29f2-48f3-b2ca-de0b4b31e787"}
2582025-03-18T15:16:12.434Z{"msg":"connecting to 127.0.0.1:8810","v":0,"name":"crucible","level":30,"time":"2025-03-18T15:16:11.524264676Z","hostname":"w-01JPMWYMFERKMJPH1PTRHF4EXH","pid":1236,"":"io task","client":"0","":"downstairs","session_id":"ce12c9a4-29f2-48f3-b2ca-de0b4b31e787"}
2592025-03-18T15:16:12.434Z{"msg":"connecting to 127.0.0.1:8830","v":0,"name":"crucible","level":30,"time":"2025-03-18T15:16:11.524294434Z","hostname":"w-01JPMWYMFERKMJPH1PTRHF4EXH","pid":1236,"":"io task","client":"2","":"downstairs","session_id":"ce12c9a4-29f2-48f3-b2ca-de0b4b31e787"}
2602025-03-18T15:16:12.434Z{"msg":"connecting to 127.0.0.1:8820","v":0,"name":"crucible","level":30,"time":"2025-03-18T15:16:11.524596224Z","hostname":"w-01JPMWYMFERKMJPH1PTRHF4EXH","pid":1236,"":"io task","client":"1","":"downstairs","session_id":"ce12c9a4-29f2-48f3-b2ca-de0b4b31e787"}
2612025-03-18T15:16:12.434Z{"msg":"ds_connection connected from Ok(127.0.0.1:63451)","v":0,"name":"crucible","level":30,"time":"2025-03-18T15:16:11.52465388Z","hostname":"w-01JPMWYMFERKMJPH1PTRHF4EXH","pid":1236,"":"io task","client":"1","":"downstairs","session_id":"ce12c9a4-29f2-48f3-b2ca-de0b4b31e787"}
2622025-03-18T15:16:12.434Z{"msg":"ds_connection connected from Ok(127.0.0.1:45631)","v":0,"name":"crucible","level":30,"time":"2025-03-18T15:16:11.524735434Z","hostname":"w-01JPMWYMFERKMJPH1PTRHF4EXH","pid":1236,"":"io task","client":"2","":"downstairs","session_id":"ce12c9a4-29f2-48f3-b2ca-de0b4b31e787"}
2632025-03-18T15:16:12.434Z{"msg":"ds_connection connected from Ok(127.0.0.1:48664)","v":0,"name":"crucible","level":30,"time":"2025-03-18T15:16:11.524776162Z","hostname":"w-01JPMWYMFERKMJPH1PTRHF4EXH","pid":1236,"":"io task","client":"0","":"downstairs","session_id":"ce12c9a4-29f2-48f3-b2ca-de0b4b31e787"}
2642025-03-18T15:16:12.434Z{"msg":"version negotiation from state Connecting { state: WaitForPromote, mode: New }","v":0,"name":"crucible","level":30,"time":"2025-03-18T15:16:11.525039213Z","hostname":"w-01JPMWYMFERKMJPH1PTRHF4EXH","pid":1236,"client":"1","":"downstairs","session_id":"ce12c9a4-29f2-48f3-b2ca-de0b4b31e787"}
2652025-03-18T15:16:12.434Z{"msg":"version negotiation from state Connecting { state: WaitForPromote, mode: New }","v":0,"name":"crucible","level":30,"time":"2025-03-18T15:16:11.52509036Z","hostname":"w-01JPMWYMFERKMJPH1PTRHF4EXH","pid":1236,"client":"2","":"downstairs","session_id":"ce12c9a4-29f2-48f3-b2ca-de0b4b31e787"}
2662025-03-18T15:16:12.434Z{"msg":"version negotiation from state Connecting { state: WaitForPromote, mode: New }","v":0,"name":"crucible","level":30,"time":"2025-03-18T15:16:11.525136707Z","hostname":"w-01JPMWYMFERKMJPH1PTRHF4EXH","pid":1236,"client":"0","":"downstairs","session_id":"ce12c9a4-29f2-48f3-b2ca-de0b4b31e787"}
2672025-03-18T15:16:12.434Z{"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-18T15:16:11.525750725Z","hostname":"w-01JPMWYMFERKMJPH1PTRHF4EXH","pid":1236,"client":"1","":"downstairs","session_id":"ce12c9a4-29f2-48f3-b2ca-de0b4b31e787"}
2682025-03-18T15:16:12.434Z{"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-18T15:16:11.525778983Z","hostname":"w-01JPMWYMFERKMJPH1PTRHF4EXH","pid":1236,"client":"0","":"downstairs","session_id":"ce12c9a4-29f2-48f3-b2ca-de0b4b31e787"}
2692025-03-18T15:16:12.434Z{"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-18T15:16:11.525800742Z","hostname":"w-01JPMWYMFERKMJPH1PTRHF4EXH","pid":1236,"client":"2","":"downstairs","session_id":"ce12c9a4-29f2-48f3-b2ca-de0b4b31e787"}
2702025-03-18T15:16:12.434Z{"msg":"Waiting for more clients to be ready","v":0,"name":"crucible","level":30,"time":"2025-03-18T15:16:11.526204034Z","hostname":"w-01JPMWYMFERKMJPH1PTRHF4EXH","pid":1236,"session_id":"ce12c9a4-29f2-48f3-b2ca-de0b4b31e787"}
2712025-03-18T15:16:12.434Z{"msg":"Waiting for more clients to be ready","v":0,"name":"crucible","level":30,"time":"2025-03-18T15:16:11.526348754Z","hostname":"w-01JPMWYMFERKMJPH1PTRHF4EXH","pid":1236,"session_id":"ce12c9a4-29f2-48f3-b2ca-de0b4b31e787"}
2722025-03-18T15:16:12.434Z{"msg":"[0]R flush_numbers: [1506, 1506, 1506, 1506, 1506]","v":0,"name":"crucible","level":30,"time":"2025-03-18T15:16:11.526394551Z","hostname":"w-01JPMWYMFERKMJPH1PTRHF4EXH","pid":1236,"":"downstairs","":"downstairs","session_id":"ce12c9a4-29f2-48f3-b2ca-de0b4b31e787"}
2732025-03-18T15:16:12.434Z{"msg":"[0]R generation: [31, 31, 31, 31, 31]","v":0,"name":"crucible","level":30,"time":"2025-03-18T15:16:11.526443888Z","hostname":"w-01JPMWYMFERKMJPH1PTRHF4EXH","pid":1236,"":"downstairs","":"downstairs","session_id":"ce12c9a4-29f2-48f3-b2ca-de0b4b31e787"}
2742025-03-18T15:16:12.434Z{"msg":"[0]R dirty: [false, false, false, false, false]","v":0,"name":"crucible","level":30,"time":"2025-03-18T15:16:11.526482885Z","hostname":"w-01JPMWYMFERKMJPH1PTRHF4EXH","pid":1236,"":"downstairs","":"downstairs","session_id":"ce12c9a4-29f2-48f3-b2ca-de0b4b31e787"}
2752025-03-18T15:16:12.434Z{"msg":"[1]R flush_numbers: [1506, 1506, 1506, 1506, 1506]","v":0,"name":"crucible","level":30,"time":"2025-03-18T15:16:11.526509244Z","hostname":"w-01JPMWYMFERKMJPH1PTRHF4EXH","pid":1236,"":"downstairs","":"downstairs","session_id":"ce12c9a4-29f2-48f3-b2ca-de0b4b31e787"}
2762025-03-18T15:16:12.434Z{"msg":"[1]R generation: [31, 31, 31, 31, 31]","v":0,"name":"crucible","level":30,"time":"2025-03-18T15:16:11.526543301Z","hostname":"w-01JPMWYMFERKMJPH1PTRHF4EXH","pid":1236,"":"downstairs","":"downstairs","session_id":"ce12c9a4-29f2-48f3-b2ca-de0b4b31e787"}
2772025-03-18T15:16:12.434Z{"msg":"[1]R dirty: [false, false, false, false, false]","v":0,"name":"crucible","level":30,"time":"2025-03-18T15:16:11.526580169Z","hostname":"w-01JPMWYMFERKMJPH1PTRHF4EXH","pid":1236,"":"downstairs","":"downstairs","session_id":"ce12c9a4-29f2-48f3-b2ca-de0b4b31e787"}
2782025-03-18T15:16:12.434Z{"msg":"[2]R flush_numbers: [1506, 1506, 1506, 1506, 1506]","v":0,"name":"crucible","level":30,"time":"2025-03-18T15:16:11.526617306Z","hostname":"w-01JPMWYMFERKMJPH1PTRHF4EXH","pid":1236,"":"downstairs","":"downstairs","session_id":"ce12c9a4-29f2-48f3-b2ca-de0b4b31e787"}
2792025-03-18T15:16:12.434Z{"msg":"[2]R generation: [31, 31, 31, 31, 31]","v":0,"name":"crucible","level":30,"time":"2025-03-18T15:16:11.526646044Z","hostname":"w-01JPMWYMFERKMJPH1PTRHF4EXH","pid":1236,"":"downstairs","":"downstairs","session_id":"ce12c9a4-29f2-48f3-b2ca-de0b4b31e787"}
2802025-03-18T15:16:12.434Z{"msg":"[2]R dirty: [false, false, false, false, false]","v":0,"name":"crucible","level":30,"time":"2025-03-18T15:16:11.526670922Z","hostname":"w-01JPMWYMFERKMJPH1PTRHF4EXH","pid":1236,"":"downstairs","":"downstairs","session_id":"ce12c9a4-29f2-48f3-b2ca-de0b4b31e787"}Wait for a query_work_queue command to finish before sending IO
2812025-03-18T15:16:12.434Z
2822025-03-18T15:16:12.434Z{"msg":"Max found gen is 32","v":0,"name":"crucible","level":30,"time":"2025-03-18T15:16:11.52670612Z","hostname":"w-01JPMWYMFERKMJPH1PTRHF4EXH","pid":1236,"":"downstairs","":"downstairs","session_id":"ce12c9a4-29f2-48f3-b2ca-de0b4b31e787"}
2832025-03-18T15:16:12.434Z{"msg":"Generation requested: 32 >= found:32","v":0,"name":"crucible","level":30,"time":"2025-03-18T15:16:11.526720059Z","hostname":"w-01JPMWYMFERKMJPH1PTRHF4EXH","pid":1236,"":"downstairs","":"downstairs","session_id":"ce12c9a4-29f2-48f3-b2ca-de0b4b31e787"}
2842025-03-18T15:16:12.434Z{"msg":"Next flush: 1507","v":0,"name":"crucible","level":30,"time":"2025-03-18T15:16:11.526742837Z","hostname":"w-01JPMWYMFERKMJPH1PTRHF4EXH","pid":1236,"":"downstairs","":"downstairs","session_id":"ce12c9a4-29f2-48f3-b2ca-de0b4b31e787"}
2852025-03-18T15:16:12.434Z{"msg":"All extents match","v":0,"name":"crucible","level":30,"time":"2025-03-18T15:16:11.526775945Z","hostname":"w-01JPMWYMFERKMJPH1PTRHF4EXH","pid":1236,"":"downstairs","":"downstairs","session_id":"ce12c9a4-29f2-48f3-b2ca-de0b4b31e787"}
2862025-03-18T15:16:12.434Z{"msg":"No downstairs reconciliation required","v":0,"name":"crucible","level":30,"time":"2025-03-18T15:16:11.526800713Z","hostname":"w-01JPMWYMFERKMJPH1PTRHF4EXH","pid":1236,"session_id":"ce12c9a4-29f2-48f3-b2ca-de0b4b31e787"}
2872025-03-18T15:16:12.434Z{"msg":"Transition from WaitQuorum to Active","v":0,"name":"crucible","level":30,"time":"2025-03-18T15:16:11.526813113Z","hostname":"w-01JPMWYMFERKMJPH1PTRHF4EXH","pid":1236,"client":"0","":"downstairs","session_id":"ce12c9a4-29f2-48f3-b2ca-de0b4b31e787"}
2882025-03-18T15:16:12.434Z{"msg":"Transition from WaitQuorum to Active","v":0,"name":"crucible","level":30,"time":"2025-03-18T15:16:11.526832731Z","hostname":"w-01JPMWYMFERKMJPH1PTRHF4EXH","pid":1236,"client":"1","":"downstairs","session_id":"ce12c9a4-29f2-48f3-b2ca-de0b4b31e787"}
2892025-03-18T15:16:12.434Z{"msg":"Transition from WaitQuorum to Active","v":0,"name":"crucible","level":30,"time":"2025-03-18T15:16:11.52684585Z","hostname":"w-01JPMWYMFERKMJPH1PTRHF4EXH","pid":1236,"client":"2","":"downstairs","session_id":"ce12c9a4-29f2-48f3-b2ca-de0b4b31e787"}
2902025-03-18T15:16:12.434ZDisk: sv:1 bs:4096 ts:204800 tb:50 max_io:50 or 204800
2912025-03-18T15:16:12.434Z{"msg":"All required reconciliation work is completed","v":0,"name":"crucible","level":30,"time":"2025-03-18T15:16:11.526875959Z","hostname":"w-01JPMWYMFERKMJPH1PTRHF4EXH","pid":1236,"session_id":"ce12c9a4-29f2-48f3-b2ca-de0b4b31e787"}
2922025-03-18T15:16:12.434Z{"msg":"Set Downstairs and Upstairs active after reconciliation","v":0,"name":"crucible","level":30,"time":"2025-03-18T15:16:11.526894497Z","hostname":"w-01JPMWYMFERKMJPH1PTRHF4EXH","pid":1236,"session_id":"ce12c9a4-29f2-48f3-b2ca-de0b4b31e787"}
2932025-03-18T15:16:12.434Z{"msg":"fd8ac3f1-3a1d-46bc-b8fe-d59262ab2fdd is now active with session: ce12c9a4-29f2-48f3-b2ca-de0b4b31e787","v":0,"name":"crucible","level":30,"time":"2025-03-18T15:16:11.526915636Z","hostname":"w-01JPMWYMFERKMJPH1PTRHF4EXH","pid":1236,"session_id":"ce12c9a4-29f2-48f3-b2ca-de0b4b31e787"}
2942025-03-18T15:16:12.434Z{"msg":"Set Active after no reconciliation","v":0,"name":"crucible","level":30,"time":"2025-03-18T15:16:11.526927995Z","hostname":"w-01JPMWYMFERKMJPH1PTRHF4EXH","pid":1236,"session_id":"ce12c9a4-29f2-48f3-b2ca-de0b4b31e787"}
2952025-03-18T15:16:12.434Z{"msg":"The guest has finished waiting for activation with:32","v":0,"name":"crucible","level":30,"time":"2025-03-18T15:16:11.526940094Z","hostname":"w-01JPMWYMFERKMJPH1PTRHF4EXH","pid":1236}
2962025-03-18T15:16:12.434Z{"msg":"Activated sub_volume fd8ac3f1-3a1d-46bc-b8fe-d59262ab2fdd","v":0,"name":"crucible","level":30,"time":"2025-03-18T15:16:11.526951573Z","hostname":"w-01JPMWYMFERKMJPH1PTRHF4EXH","pid":1236}
2972025-03-18T15:16:12.435ZLoading write count information from file "/var/tmp/test_up-build/verify_file"
2982025-03-18T15:16:12.435ZFill test
2992025-03-18T15:16:12.462ZRead and Verify all blocks (0..50 range:false)
3002025-03-18T15:16:12.501ZWrote out file "/var/tmp/test_up-build/verify_file"
3012025-03-18T15:16:12.501ZCLIENT: Tests done. All submitted work has been ACK'd
3022025-03-18T15:16:12.504Z----------------------------------------------------------------
3032025-03-18T15:16:12.504Z Crucible gen:32 GIO:true work queues: Upstairs:0 downstairs:1
3042025-03-18T15:16:12.504ZStates: Active Active Active
3052025-03-18T15:16:12.504ZJOBID ACK TYPE BKS/EXT DS:0 DS:1 DS:2 REPLAY
3062025-03-18T15:16:12.504Z 1002 Acked Read 50 Done Done Done false
3072025-03-18T15:16:12.504Z STATES DS:0 DS:1 DS:2 TOTAL
3082025-03-18T15:16:12.504Z Sent 0 0 0 0
3092025-03-18T15:16:12.504Z Done 1 1 1 3
3102025-03-18T15:16:12.504Z Skipped 0 0 0 0
3112025-03-18T15:16:12.504Z Error 0 0 0 0
3122025-03-18T15:16:12.504ZLast Flush: Some(JobId(1001)) Some(JobId(1001)) Some(JobId(1001))
3132025-03-18T15:16:12.504ZDownstairs last five completed: 1001 1000
3142025-03-18T15:16:12.504ZUpstairs last five completed: 1002 1001 1000
3152025-03-18T15:16:12.504ZCLIENT: Up:0 ds:1 act:3
3162025-03-18T15:16:16.504Z----------------------------------------------------------------
3172025-03-18T15:16:16.504Z Crucible gen:32 GIO:true work queues: Upstairs:0 downstairs:0
3182025-03-18T15:16:16.504ZDownstairs last five completed: 1003 1002 1001 1000
3192025-03-18T15:16:16.504ZUpstairs last five completed: 1003 1002 1001 1000
3202025-03-18T15:16:16.504ZCLIENT: Up:0 ds:0 act:3
3212025-03-18T15:16:16.504ZCLIENT: All crucible jobs finished, exiting program
3222025-03-18T15:16:16.510ZRepair part 1 passed
3232025-03-18T15:16:16.514Z
3242025-03-18T15:16:16.514ZKill the current downstairs
3252025-03-18T15:16:16.680ZDownstairs 2 stopped
3262025-03-18T15:16:16.680Zmv /var/tmp/test_up-build/8830 /var/tmp/test_up-build/new
3272025-03-18T15:16:16.683ZNow put back the original so we have a mismatch
3282025-03-18T15:16:16.683Zmv /var/tmp/test_up-build/previous /var/tmp/test_up-build/8830
3292025-03-18T15:16:16.686ZRestart downstairs with old directory
3302025-03-18T15:16:16.741Z/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
3312025-03-18T15:16:16.758ZEXT BLOCKS GEN0 GEN1 GEN2 FL0 FL1 FL2 D0 D1 D2 DIFF
3322025-03-18T15:16:16.761Z 0 000-009 32 32 31 1507 1507 1506 F F F <---
3332025-03-18T15:16:16.761Z 1 010-019 32 32 31 1507 1507 1506 F F F <---
3342025-03-18T15:16:16.761Z 2 020-029 32 32 31 1507 1507 1506 F F F <---
3352025-03-18T15:16:16.761Z 3 030-039 32 32 31 1507 1507 1506 F F F <---
3362025-03-18T15:16:16.761Z 4 040-049 32 32 31 1507 1507 1506 F F F <---
3372025-03-18T15:16:16.761ZMax gen: 32, Max flush: 1507
3382025-03-18T15:16:16.974ZError: Difference in extent metadata found!
3392025-03-18T15:16:16.975Z
3402025-03-18T15:16:16.975ZStack backtrace:
3412025-03-18T15:16:16.975Z 0: anyhow::error::<impl anyhow::Error>::msg
3422025-03-18T15:16:16.975Z at /home/build/.cargo/registry/src/index.crates.io-6f17d22bba15001f/anyhow-1.0.97/src/backtrace.rs:27:14
3432025-03-18T15:16:16.975Z 1: anyhow::__private::format_err
3442025-03-18T15:16:16.975Z at /home/build/.cargo/registry/src/index.crates.io-6f17d22bba15001f/anyhow-1.0.97/src/lib.rs:692:13
3452025-03-18T15:16:16.994Zdump test found error as expected
3462025-03-18T15:16:16.994Z
3472025-03-18T15:16:16.994Z
3482025-03-18T15:16:16.997Z/var/tmp/bins/crutest verify --range -g 33 -q --key qRwlisSXLB+O+Do4pZaAHY5s4Y94pYcqRtknqy5v5gA= --dsc 127.0.0.1:9998 --verify-out /var/tmp/test_up-build/verify_file --verify-in /var/tmp/test_up-build/verify_file
3492025-03-18T15:16:17.052Z{"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-18T15:16:16.156986973Z","hostname":"w-01JPMWYMFERKMJPH1PTRHF4EXH","pid":1244,"task":"crutest"}
3502025-03-18T15:16:17.056Z{"msg":"dsc has 3 regions. This means 1 sub_volumes","v":0,"name":"crucible","level":30,"time":"2025-03-18T15:16:16.157535396Z","hostname":"w-01JPMWYMFERKMJPH1PTRHF4EXH","pid":1244,"task":"crutest"}
3512025-03-18T15:16:17.056Z{"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-18T15:16:16.15923416Z","hostname":"w-01JPMWYMFERKMJPH1PTRHF4EXH","pid":1244,"task":"crutest"}
3522025-03-18T15:16:17.056Z{"msg":"Upstairs starts","v":0,"name":"crucible","level":30,"time":"2025-03-18T15:16:16.159476744Z","hostname":"w-01JPMWYMFERKMJPH1PTRHF4EXH","pid":1244}
3532025-03-18T15:16:17.056Z{"msg":"Crucible Version: BuildInfo {\n version: \"0.0.1\",\n git_sha: \"a70f3a885a6160c78d68c43ecf4da40ad9a7b327\",\n git_commit_timestamp: \"2025-03-18T14:56:23.000000000Z\",\n git_branch: \"main\",\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-18T15:16:16.1595255Z","hostname":"w-01JPMWYMFERKMJPH1PTRHF4EXH","pid":1244}
3542025-03-18T15:16:17.056Z{"msg":"Upstairs <-> Downstairs Message Version: 13","v":0,"name":"crucible","level":30,"time":"2025-03-18T15:16:16.159564498Z","hostname":"w-01JPMWYMFERKMJPH1PTRHF4EXH","pid":1244}
3552025-03-18T15:16:17.056Z{"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-18T15:16:16.159605735Z","hostname":"w-01JPMWYMFERKMJPH1PTRHF4EXH","pid":1244}
3562025-03-18T15:16:17.056Z{"msg":"Crucible e67d0a20-c5b0-45e1-9d2d-da14715fee67 has session id: bbb5f647-7f05-4812-bf0a-dc0897cb9fc7","v":0,"name":"crucible","level":30,"time":"2025-03-18T15:16:16.160208374Z","hostname":"w-01JPMWYMFERKMJPH1PTRHF4EXH","pid":1244,"session_id":"bbb5f647-7f05-4812-bf0a-dc0897cb9fc7"}
3572025-03-18T15:16:17.056Z{"msg":"Upstairs opts: Upstairs UUID: e67d0a20-c5b0-45e1-9d2d-da14715fee67, 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-18T15:16:16.1602625Z","hostname":"w-01JPMWYMFERKMJPH1PTRHF4EXH","pid":1244,"session_id":"bbb5f647-7f05-4812-bf0a-dc0897cb9fc7"}
3582025-03-18T15:16:17.056Z{"msg":"Crucible stats registered with UUID: e67d0a20-c5b0-45e1-9d2d-da14715fee67","v":0,"name":"crucible","level":30,"time":"2025-03-18T15:16:16.160297798Z","hostname":"w-01JPMWYMFERKMJPH1PTRHF4EXH","pid":1244,"session_id":"bbb5f647-7f05-4812-bf0a-dc0897cb9fc7"}
3592025-03-18T15:16:17.056Z{"msg":"could not find Downstairs address for Nexus","v":0,"name":"crucible","level":40,"time":"2025-03-18T15:16:16.160320596Z","hostname":"w-01JPMWYMFERKMJPH1PTRHF4EXH","pid":1244,"session_id":"bbb5f647-7f05-4812-bf0a-dc0897cb9fc7"}
3602025-03-18T15:16:17.060Z{"msg":"Downstairs in volume = 3","v":0,"name":"crucible","level":30,"time":"2025-03-18T15:16:16.161553052Z","hostname":"w-01JPMWYMFERKMJPH1PTRHF4EXH","pid":1244,"task":"crutest"}
3612025-03-18T15:16:17.060Z{"msg":"The guest has requested activation with gen:33","v":0,"name":"crucible","level":30,"time":"2025-03-18T15:16:16.16159591Z","hostname":"w-01JPMWYMFERKMJPH1PTRHF4EXH","pid":1244}
3622025-03-18T15:16:17.060Z{"msg":"e67d0a20-c5b0-45e1-9d2d-da14715fee67 active request set","v":0,"name":"crucible","level":30,"time":"2025-03-18T15:16:16.161619828Z","hostname":"w-01JPMWYMFERKMJPH1PTRHF4EXH","pid":1244,"session_id":"bbb5f647-7f05-4812-bf0a-dc0897cb9fc7"}
3632025-03-18T15:16:17.060Z{"msg":"sending connect oneshot to client","v":0,"name":"crucible","level":30,"time":"2025-03-18T15:16:16.161719341Z","hostname":"w-01JPMWYMFERKMJPH1PTRHF4EXH","pid":1244,"client":"0","":"downstairs","session_id":"bbb5f647-7f05-4812-bf0a-dc0897cb9fc7"}
3642025-03-18T15:16:17.060Z{"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-18T15:16:16.161773397Z","hostname":"w-01JPMWYMFERKMJPH1PTRHF4EXH","pid":1244,"client":"0","":"downstairs","session_id":"bbb5f647-7f05-4812-bf0a-dc0897cb9fc7"}
3652025-03-18T15:16:17.060Z{"msg":"sending connect oneshot to client","v":0,"name":"crucible","level":30,"time":"2025-03-18T15:16:16.161793716Z","hostname":"w-01JPMWYMFERKMJPH1PTRHF4EXH","pid":1244,"client":"1","":"downstairs","session_id":"bbb5f647-7f05-4812-bf0a-dc0897cb9fc7"}
3662025-03-18T15:16:17.060Z{"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-18T15:16:16.161836853Z","hostname":"w-01JPMWYMFERKMJPH1PTRHF4EXH","pid":1244,"client":"1","":"downstairs","session_id":"bbb5f647-7f05-4812-bf0a-dc0897cb9fc7"}
3672025-03-18T15:16:17.060Z{"msg":"sending connect oneshot to client","v":0,"name":"crucible","level":30,"time":"2025-03-18T15:16:16.161860811Z","hostname":"w-01JPMWYMFERKMJPH1PTRHF4EXH","pid":1244,"client":"2","":"downstairs","session_id":"bbb5f647-7f05-4812-bf0a-dc0897cb9fc7"}
3682025-03-18T15:16:17.060Z{"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-18T15:16:16.161896129Z","hostname":"w-01JPMWYMFERKMJPH1PTRHF4EXH","pid":1244,"client":"2","":"downstairs","session_id":"bbb5f647-7f05-4812-bf0a-dc0897cb9fc7"}
3692025-03-18T15:16:17.060Z{"msg":"connecting to 127.0.0.1:8830","v":0,"name":"crucible","level":30,"time":"2025-03-18T15:16:16.161927697Z","hostname":"w-01JPMWYMFERKMJPH1PTRHF4EXH","pid":1244,"":"io task","client":"2","":"downstairs","session_id":"bbb5f647-7f05-4812-bf0a-dc0897cb9fc7"}
3702025-03-18T15:16:17.060Z{"msg":"connecting to 127.0.0.1:8810","v":0,"name":"crucible","level":30,"time":"2025-03-18T15:16:16.162006222Z","hostname":"w-01JPMWYMFERKMJPH1PTRHF4EXH","pid":1244,"":"io task","client":"0","":"downstairs","session_id":"bbb5f647-7f05-4812-bf0a-dc0897cb9fc7"}
3712025-03-18T15:16:17.060Z{"msg":"connecting to 127.0.0.1:8820","v":0,"name":"crucible","level":30,"time":"2025-03-18T15:16:16.162064538Z","hostname":"w-01JPMWYMFERKMJPH1PTRHF4EXH","pid":1244,"":"io task","client":"1","":"downstairs","session_id":"bbb5f647-7f05-4812-bf0a-dc0897cb9fc7"}
3722025-03-18T15:16:17.060Z{"msg":"ds_connection connected from Ok(127.0.0.1:34018)","v":0,"name":"crucible","level":30,"time":"2025-03-18T15:16:16.1621733Z","hostname":"w-01JPMWYMFERKMJPH1PTRHF4EXH","pid":1244,"":"io task","client":"1","":"downstairs","session_id":"bbb5f647-7f05-4812-bf0a-dc0897cb9fc7"}
3732025-03-18T15:16:17.060Z{"msg":"ds_connection connected from Ok(127.0.0.1:58222)","v":0,"name":"crucible","level":30,"time":"2025-03-18T15:16:16.162198158Z","hostname":"w-01JPMWYMFERKMJPH1PTRHF4EXH","pid":1244,"":"io task","client":"0","":"downstairs","session_id":"bbb5f647-7f05-4812-bf0a-dc0897cb9fc7"}
3742025-03-18T15:16:17.060Z{"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-18T15:16:16.162240595Z","hostname":"w-01JPMWYMFERKMJPH1PTRHF4EXH","pid":1244,"":"io task","client":"2","":"downstairs","session_id":"bbb5f647-7f05-4812-bf0a-dc0897cb9fc7"}
3752025-03-18T15:16:17.061Z{"msg":"client task is sending Done(ConnectionFailed(Os { code: 146, kind: ConnectionRefused, message: \"Connection refused\" }))","v":0,"name":"crucible","level":40,"time":"2025-03-18T15:16:16.162270664Z","hostname":"w-01JPMWYMFERKMJPH1PTRHF4EXH","pid":1244,"":"io task","client":"2","":"downstairs","session_id":"bbb5f647-7f05-4812-bf0a-dc0897cb9fc7"}
3762025-03-18T15:16:17.061Z{"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-18T15:16:16.16231925Z","hostname":"w-01JPMWYMFERKMJPH1PTRHF4EXH","pid":1244,"session_id":"bbb5f647-7f05-4812-bf0a-dc0897cb9fc7"}
3772025-03-18T15:16:17.061Z{"msg":"client task is exiting","v":0,"name":"crucible","level":30,"time":"2025-03-18T15:16:16.162343959Z","hostname":"w-01JPMWYMFERKMJPH1PTRHF4EXH","pid":1244,"":"io task","client":"2","":"downstairs","session_id":"bbb5f647-7f05-4812-bf0a-dc0897cb9fc7"}
3782025-03-18T15:16:17.061Z{"msg":"version negotiation from state Connecting { state: WaitForPromote, mode: New }","v":0,"name":"crucible","level":30,"time":"2025-03-18T15:16:16.16261092Z","hostname":"w-01JPMWYMFERKMJPH1PTRHF4EXH","pid":1244,"client":"0","":"downstairs","session_id":"bbb5f647-7f05-4812-bf0a-dc0897cb9fc7"}
3792025-03-18T15:16:17.061Z{"msg":"version negotiation from state Connecting { state: WaitForPromote, mode: New }","v":0,"name":"crucible","level":30,"time":"2025-03-18T15:16:16.162645828Z","hostname":"w-01JPMWYMFERKMJPH1PTRHF4EXH","pid":1244,"client":"1","":"downstairs","session_id":"bbb5f647-7f05-4812-bf0a-dc0897cb9fc7"}
3802025-03-18T15:16:17.061Z{"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-18T15:16:16.163233908Z","hostname":"w-01JPMWYMFERKMJPH1PTRHF4EXH","pid":1244,"client":"1","":"downstairs","session_id":"bbb5f647-7f05-4812-bf0a-dc0897cb9fc7"}
3812025-03-18T15:16:17.061Z{"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-18T15:16:16.163275185Z","hostname":"w-01JPMWYMFERKMJPH1PTRHF4EXH","pid":1244,"client":"0","":"downstairs","session_id":"bbb5f647-7f05-4812-bf0a-dc0897cb9fc7"}
3822025-03-18T15:16:17.061Z{"msg":"Waiting for more clients to be ready","v":0,"name":"crucible","level":30,"time":"2025-03-18T15:16:16.163619041Z","hostname":"w-01JPMWYMFERKMJPH1PTRHF4EXH","pid":1244,"session_id":"bbb5f647-7f05-4812-bf0a-dc0897cb9fc7"}
3832025-03-18T15:16:17.061Z{"msg":"Waiting for more clients to be ready","v":0,"name":"crucible","level":30,"time":"2025-03-18T15:16:16.163685757Z","hostname":"w-01JPMWYMFERKMJPH1PTRHF4EXH","pid":1244,"session_id":"bbb5f647-7f05-4812-bf0a-dc0897cb9fc7"}
3842025-03-18T15:16:27.059Z{"msg":"connecting to 127.0.0.1:8830","v":0,"name":"crucible","level":30,"time":"2025-03-18T15:16:26.162749542Z","hostname":"w-01JPMWYMFERKMJPH1PTRHF4EXH","pid":1244,"":"io task","client":"2","":"downstairs","session_id":"bbb5f647-7f05-4812-bf0a-dc0897cb9fc7"}
3852025-03-18T15:16:27.059Z{"msg":"ds_connection connected from Ok(127.0.0.1:44698)","v":0,"name":"crucible","level":30,"time":"2025-03-18T15:16:26.162839656Z","hostname":"w-01JPMWYMFERKMJPH1PTRHF4EXH","pid":1244,"":"io task","client":"2","":"downstairs","session_id":"bbb5f647-7f05-4812-bf0a-dc0897cb9fc7"}
3862025-03-18T15:16:27.064Z{"msg":"version negotiation from state Connecting { state: WaitForPromote, mode: New }","v":0,"name":"crucible","level":30,"time":"2025-03-18T15:16:26.164013976Z","hostname":"w-01JPMWYMFERKMJPH1PTRHF4EXH","pid":1244,"client":"2","":"downstairs","session_id":"bbb5f647-7f05-4812-bf0a-dc0897cb9fc7"}
3872025-03-18T15:16:27.064Z{"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-18T15:16:26.164600746Z","hostname":"w-01JPMWYMFERKMJPH1PTRHF4EXH","pid":1244,"client":"2","":"downstairs","session_id":"bbb5f647-7f05-4812-bf0a-dc0897cb9fc7"}
3882025-03-18T15:16:27.064Z{"msg":"[0]R flush_numbers: [1507, 1507, 1507, 1507, 1507]","v":0,"name":"crucible","level":30,"time":"2025-03-18T15:16:26.165013818Z","hostname":"w-01JPMWYMFERKMJPH1PTRHF4EXH","pid":1244,"":"downstairs","":"downstairs","session_id":"bbb5f647-7f05-4812-bf0a-dc0897cb9fc7"}
3892025-03-18T15:16:27.064Z{"msg":"[0]R generation: [32, 32, 32, 32, 32]","v":0,"name":"crucible","level":30,"time":"2025-03-18T15:16:26.165060974Z","hostname":"w-01JPMWYMFERKMJPH1PTRHF4EXH","pid":1244,"":"downstairs","":"downstairs","session_id":"bbb5f647-7f05-4812-bf0a-dc0897cb9fc7"}
3902025-03-18T15:16:27.064Z{"msg":"[0]R dirty: [false, false, false, false, false]","v":0,"name":"crucible","level":30,"time":"2025-03-18T15:16:26.165089243Z","hostname":"w-01JPMWYMFERKMJPH1PTRHF4EXH","pid":1244,"":"downstairs","":"downstairs","session_id":"bbb5f647-7f05-4812-bf0a-dc0897cb9fc7"}
3912025-03-18T15:16:27.064Z{"msg":"[1]R flush_numbers: [1507, 1507, 1507, 1507, 1507]","v":0,"name":"crucible","level":30,"time":"2025-03-18T15:16:26.16512359Z","hostname":"w-01JPMWYMFERKMJPH1PTRHF4EXH","pid":1244,"":"downstairs","":"downstairs","session_id":"bbb5f647-7f05-4812-bf0a-dc0897cb9fc7"}
3922025-03-18T15:16:27.064Z{"msg":"[1]R generation: [32, 32, 32, 32, 32]","v":0,"name":"crucible","level":30,"time":"2025-03-18T15:16:26.165158678Z","hostname":"w-01JPMWYMFERKMJPH1PTRHF4EXH","pid":1244,"":"downstairs","":"downstairs","session_id":"bbb5f647-7f05-4812-bf0a-dc0897cb9fc7"}
3932025-03-18T15:16:27.064Z{"msg":"[1]R dirty: [false, false, false, false, false]","v":0,"name":"crucible","level":30,"time":"2025-03-18T15:16:26.165210064Z","hostname":"w-01JPMWYMFERKMJPH1PTRHF4EXH","pid":1244,"":"downstairs","":"downstairs","session_id":"bbb5f647-7f05-4812-bf0a-dc0897cb9fc7"}
3942025-03-18T15:16:27.064Z{"msg":"[2]R flush_numbers: [1506, 1506, 1506, 1506, 1506]","v":0,"name":"crucible","level":30,"time":"2025-03-18T15:16:26.165246512Z","hostname":"w-01JPMWYMFERKMJPH1PTRHF4EXH","pid":1244,"":"downstairs","":"downstairs","session_id":"bbb5f647-7f05-4812-bf0a-dc0897cb9fc7"}
3952025-03-18T15:16:27.064Z{"msg":"[2]R generation: [31, 31, 31, 31, 31]","v":0,"name":"crucible","level":30,"time":"2025-03-18T15:16:26.16528105Z","hostname":"w-01JPMWYMFERKMJPH1PTRHF4EXH","pid":1244,"":"downstairs","":"downstairs","session_id":"bbb5f647-7f05-4812-bf0a-dc0897cb9fc7"}
3962025-03-18T15:16:27.064Z{"msg":"[2]R dirty: [false, false, false, false, false]","v":0,"name":"crucible","level":30,"time":"2025-03-18T15:16:26.165316417Z","hostname":"w-01JPMWYMFERKMJPH1PTRHF4EXH","pid":1244,"":"downstairs","":"downstairs","session_id":"bbb5f647-7f05-4812-bf0a-dc0897cb9fc7"}
3972025-03-18T15:16:27.065Z{"msg":"Max found gen is 33","v":0,"name":"crucible","level":30,"time":"2025-03-18T15:16:26.165351745Z","hostname":"w-01JPMWYMFERKMJPH1PTRHF4EXH","pid":1244,"":"downstairs","":"downstairs","session_id":"bbb5f647-7f05-4812-bf0a-dc0897cb9fc7"}
3982025-03-18T15:16:27.065Z{"msg":"Generation requested: 33 >= found:33","v":0,"name":"crucible","level":30,"time":"2025-03-18T15:16:26.165380463Z","hostname":"w-01JPMWYMFERKMJPH1PTRHF4EXH","pid":1244,"":"downstairs","":"downstairs","session_id":"bbb5f647-7f05-4812-bf0a-dc0897cb9fc7"}
3992025-03-18T15:16:27.065Z{"msg":"Next flush: 1508","v":0,"name":"crucible","level":30,"time":"2025-03-18T15:16:26.16541864Z","hostname":"w-01JPMWYMFERKMJPH1PTRHF4EXH","pid":1244,"":"downstairs","":"downstairs","session_id":"bbb5f647-7f05-4812-bf0a-dc0897cb9fc7"}
4002025-03-18T15:16:27.065Z{"msg":"extent 0 needs reconciliation: ExtentMetadata { gen: 32, flush: 1507, dirty: false } ExtentMetadata { gen: 32, flush: 1507, dirty: false } ExtentMetadata { gen: 31, flush: 1506, dirty: false }","v":0,"name":"crucible","level":30,"time":"2025-03-18T15:16:26.165460807Z","hostname":"w-01JPMWYMFERKMJPH1PTRHF4EXH","pid":1244,"":"mend","":"downstairs","":"downstairs","session_id":"bbb5f647-7f05-4812-bf0a-dc0897cb9fc7"}
4012025-03-18T15:16:27.065Z{"msg":"extent:0 [ExtentMetadata { gen: 32, flush: 1507, dirty: false }, ExtentMetadata { gen: 32, flush: 1507, dirty: false }, ExtentMetadata { gen: 31, flush: 1506, dirty: false }] => 0","v":0,"name":"crucible","level":30,"time":"2025-03-18T15:16:26.165490875Z","hostname":"w-01JPMWYMFERKMJPH1PTRHF4EXH","pid":1244,"":"mend","":"downstairs","":"downstairs","session_id":"bbb5f647-7f05-4812-bf0a-dc0897cb9fc7"}
4022025-03-18T15:16:27.065Z{"msg":"found dest for source 0 for extent at index 0 => [ClientId(2)]","v":0,"name":"crucible","level":30,"time":"2025-03-18T15:16:26.165527173Z","hostname":"w-01JPMWYMFERKMJPH1PTRHF4EXH","pid":1244,"":"mend","":"downstairs","":"downstairs","session_id":"bbb5f647-7f05-4812-bf0a-dc0897cb9fc7"}
4032025-03-18T15:16:27.065Z{"msg":"extent 1 needs reconciliation: ExtentMetadata { gen: 32, flush: 1507, dirty: false } ExtentMetadata { gen: 32, flush: 1507, dirty: false } ExtentMetadata { gen: 31, flush: 1506, dirty: false }","v":0,"name":"crucible","level":30,"time":"2025-03-18T15:16:26.16557073Z","hostname":"w-01JPMWYMFERKMJPH1PTRHF4EXH","pid":1244,"":"mend","":"downstairs","":"downstairs","session_id":"bbb5f647-7f05-4812-bf0a-dc0897cb9fc7"}
4042025-03-18T15:16:27.065Z{"msg":"extent:0 [ExtentMetadata { gen: 32, flush: 1507, dirty: false }, ExtentMetadata { gen: 32, flush: 1507, dirty: false }, ExtentMetadata { gen: 31, flush: 1506, dirty: false }] => 0","v":0,"name":"crucible","level":30,"time":"2025-03-18T15:16:26.165618956Z","hostname":"w-01JPMWYMFERKMJPH1PTRHF4EXH","pid":1244,"":"mend","":"downstairs","":"downstairs","session_id":"bbb5f647-7f05-4812-bf0a-dc0897cb9fc7"}
4052025-03-18T15:16:27.065Z{"msg":"found dest for source 0 for extent at index 1 => [ClientId(2)]","v":0,"name":"crucible","level":30,"time":"2025-03-18T15:16:26.165662964Z","hostname":"w-01JPMWYMFERKMJPH1PTRHF4EXH","pid":1244,"":"mend","":"downstairs","":"downstairs","session_id":"bbb5f647-7f05-4812-bf0a-dc0897cb9fc7"}
4062025-03-18T15:16:27.065Z{"msg":"extent 2 needs reconciliation: ExtentMetadata { gen: 32, flush: 1507, dirty: false } ExtentMetadata { gen: 32, flush: 1507, dirty: false } ExtentMetadata { gen: 31, flush: 1506, dirty: false }","v":0,"name":"crucible","level":30,"time":"2025-03-18T15:16:26.165702891Z","hostname":"w-01JPMWYMFERKMJPH1PTRHF4EXH","pid":1244,"":"mend","":"downstairs","":"downstairs","session_id":"bbb5f647-7f05-4812-bf0a-dc0897cb9fc7"}
4072025-03-18T15:16:27.065Z{"msg":"extent:0 [ExtentMetadata { gen: 32, flush: 1507, dirty: false }, ExtentMetadata { gen: 32, flush: 1507, dirty: false }, ExtentMetadata { gen: 31, flush: 1506, dirty: false }] => 0","v":0,"name":"crucible","level":30,"time":"2025-03-18T15:16:26.165746838Z","hostname":"w-01JPMWYMFERKMJPH1PTRHF4EXH","pid":1244,"":"mend","":"downstairs","":"downstairs","session_id":"bbb5f647-7f05-4812-bf0a-dc0897cb9fc7"}
4082025-03-18T15:16:27.065Z{"msg":"found dest for source 0 for extent at index 2 => [ClientId(2)]","v":0,"name":"crucible","level":30,"time":"2025-03-18T15:16:26.165774736Z","hostname":"w-01JPMWYMFERKMJPH1PTRHF4EXH","pid":1244,"":"mend","":"downstairs","":"downstairs","session_id":"bbb5f647-7f05-4812-bf0a-dc0897cb9fc7"}
4092025-03-18T15:16:27.065Z{"msg":"extent 3 needs reconciliation: ExtentMetadata { gen: 32, flush: 1507, dirty: false } ExtentMetadata { gen: 32, flush: 1507, dirty: false } ExtentMetadata { gen: 31, flush: 1506, dirty: false }","v":0,"name":"crucible","level":30,"time":"2025-03-18T15:16:26.165818693Z","hostname":"w-01JPMWYMFERKMJPH1PTRHF4EXH","pid":1244,"":"mend","":"downstairs","":"downstairs","session_id":"bbb5f647-7f05-4812-bf0a-dc0897cb9fc7"}
4102025-03-18T15:16:27.065Z{"msg":"extent:0 [ExtentMetadata { gen: 32, flush: 1507, dirty: false }, ExtentMetadata { gen: 32, flush: 1507, dirty: false }, ExtentMetadata { gen: 31, flush: 1506, dirty: false }] => 0","v":0,"name":"crucible","level":30,"time":"2025-03-18T15:16:26.165880749Z","hostname":"w-01JPMWYMFERKMJPH1PTRHF4EXH","pid":1244,"":"mend","":"downstairs","":"downstairs","session_id":"bbb5f647-7f05-4812-bf0a-dc0897cb9fc7"}
4112025-03-18T15:16:27.065Z{"msg":"found dest for source 0 for extent at index 3 => [ClientId(2)]","v":0,"name":"crucible","level":30,"time":"2025-03-18T15:16:26.165925006Z","hostname":"w-01JPMWYMFERKMJPH1PTRHF4EXH","pid":1244,"":"mend","":"downstairs","":"downstairs","session_id":"bbb5f647-7f05-4812-bf0a-dc0897cb9fc7"}
4122025-03-18T15:16:27.065Z{"msg":"extent 4 needs reconciliation: ExtentMetadata { gen: 32, flush: 1507, dirty: false } ExtentMetadata { gen: 32, flush: 1507, dirty: false } ExtentMetadata { gen: 31, flush: 1506, dirty: false }","v":0,"name":"crucible","level":30,"time":"2025-03-18T15:16:26.165965093Z","hostname":"w-01JPMWYMFERKMJPH1PTRHF4EXH","pid":1244,"":"mend","":"downstairs","":"downstairs","session_id":"bbb5f647-7f05-4812-bf0a-dc0897cb9fc7"}
4132025-03-18T15:16:27.065Z{"msg":"extent:0 [ExtentMetadata { gen: 32, flush: 1507, dirty: false }, ExtentMetadata { gen: 32, flush: 1507, dirty: false }, ExtentMetadata { gen: 31, flush: 1506, dirty: false }] => 0","v":0,"name":"crucible","level":30,"time":"2025-03-18T15:16:26.1660037Z","hostname":"w-01JPMWYMFERKMJPH1PTRHF4EXH","pid":1244,"":"mend","":"downstairs","":"downstairs","session_id":"bbb5f647-7f05-4812-bf0a-dc0897cb9fc7"}
4142025-03-18T15:16:27.065Z{"msg":"found dest for source 0 for extent at index 4 => [ClientId(2)]","v":0,"name":"crucible","level":30,"time":"2025-03-18T15:16:26.166028019Z","hostname":"w-01JPMWYMFERKMJPH1PTRHF4EXH","pid":1244,"":"mend","":"downstairs","":"downstairs","session_id":"bbb5f647-7f05-4812-bf0a-dc0897cb9fc7"}
4152025-03-18T15:16:27.065Z{"msg":"Transition from Connecting { state: WaitQuorum, mode: New } to Reconcile","v":0,"name":"crucible","level":30,"time":"2025-03-18T15:16:26.166055247Z","hostname":"w-01JPMWYMFERKMJPH1PTRHF4EXH","pid":1244,"client":"0","":"downstairs","session_id":"bbb5f647-7f05-4812-bf0a-dc0897cb9fc7"}
4162025-03-18T15:16:27.065Z{"msg":"Transition from Connecting { state: WaitQuorum, mode: New } to Reconcile","v":0,"name":"crucible","level":30,"time":"2025-03-18T15:16:26.166080525Z","hostname":"w-01JPMWYMFERKMJPH1PTRHF4EXH","pid":1244,"client":"1","":"downstairs","session_id":"bbb5f647-7f05-4812-bf0a-dc0897cb9fc7"}
4172025-03-18T15:16:27.065Z{"msg":"Transition from Connecting { state: WaitQuorum, mode: New } to Reconcile","v":0,"name":"crucible","level":30,"time":"2025-03-18T15:16:26.166094584Z","hostname":"w-01JPMWYMFERKMJPH1PTRHF4EXH","pid":1244,"client":"2","":"downstairs","session_id":"bbb5f647-7f05-4812-bf0a-dc0897cb9fc7"}
4182025-03-18T15:16:27.065Z{"msg":"Full repair list: {ExtentId(1): ExtentFix { source: ClientId(0), dest: [ClientId(2)] }, ExtentId(3): ExtentFix { source: ClientId(0), dest: [ClientId(2)] }, 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)] }}","v":0,"name":"crucible","level":30,"time":"2025-03-18T15:16:26.166118833Z","hostname":"w-01JPMWYMFERKMJPH1PTRHF4EXH","pid":1244,"":"downstairs","":"downstairs","session_id":"bbb5f647-7f05-4812-bf0a-dc0897cb9fc7"}
4192025-03-18T15:16:27.065Z{"msg":"Task list: [ReconcileIO { id: ReconciliationId(0), op: ExtentFlush { repair_id: ReconciliationId(0), extent_id: ExtentId(1), client_id: ClientId(0), flush_number: 1508, gen_number: 33 }, state: ClientData([New, New, New]) }, ReconcileIO { id: ReconciliationId(1), op: ExtentClose { repair_id: ReconciliationId(1), extent_id: ExtentId(1) }, state: ClientData([New, New, New]) }, ReconcileIO { id: ReconciliationId(2), op: ExtentRepair { repair_id: ReconciliationId(2), 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(3), op: ExtentReopen { repair_id: ReconciliationId(3), extent_id: ExtentId(1) }, state: ClientData([New, New, New]) }, ReconcileIO { id: ReconciliationId(4), op: ExtentFlush { repair_id: ReconciliationId(4), extent_id: ExtentId(3), client_id: ClientId(0), flush_number: 1508, gen_number: 33 }, state: ClientData([New, New, New]) }, ReconcileIO { id: ReconciliationId(5), op: ExtentClose { repair_id: ReconciliationId(5), extent_id: ExtentId(3) }, state: ClientData([New, New, New]) }, ReconcileIO { id: ReconciliationId(6), op: ExtentRepair { repair_id: ReconciliationId(6), 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(7), op: ExtentReopen { repair_id: ReconciliationId(7), extent_id: ExtentId(3) }, state: ClientData([New, New, New]) }, ReconcileIO { id: ReconciliationId(8), op: ExtentFlush { repair_id: ReconciliationId(8), extent_id: ExtentId(4), client_id: ClientId(0), flush_number: 1508, gen_number: 33 }, state: ClientData([New, New, New]) }, ReconcileIO { id: ReconciliationId(9), op: ExtentClose { repair_id: ReconciliationId(9), extent_id: ExtentId(4) }, state: ClientData([New, New, New]) }, ReconcileIO { id: ReconciliationId(10), op: ExtentRepair { repair_id: ReconciliationId(10), 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(11), op: ExtentReopen { repair_id: ReconciliationId(11), extent_id: ExtentId(4) }, state: ClientData([New, New, New]) }, ReconcileIO { id: ReconciliationId(12), op: ExtentFlush { repair_id: ReconciliationId(12), extent_id: ExtentId(0), client_id: ClientId(0), flush_number: 1508, gen_number: 33 }, state: ClientData([New, New, New]) }, ReconcileIO { id: ReconciliationId(13), op: ExtentClose { repair_id: ReconciliationId(13), extent_id: ExtentId(0) }, state: ClientData([New, New, New]) }, ReconcileIO { id: ReconciliationId(14), op: ExtentRepair { repair_id: ReconciliationId(14), 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(15), op: ExtentReopen { repair_id: ReconciliationId(15), extent_id: ExtentId(0) }, state: ClientData([New, New, New]) }, ReconcileIO { id: ReconciliationId(16), op: ExtentFlush { repair_id: ReconciliationId(16), extent_id: ExtentId(2), client_id: ClientId(0), flush_number: 1508, gen_number: 33 }, state: ClientData([New, New, New]) }, ReconcileIO { id: ReconciliationId(17), op: ExtentClose { repair_id: ReconciliationId(17), extent_id: ExtentId(2) }, state: ClientData([New, New, New]) }, ReconcileIO { id: ReconciliationId(18), op: ExtentRepair { repair_id: ReconciliationId(18), 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(19), op: ExtentReopen { repair_id: ReconciliationId(19), extent_id: ExtentId(2) }, state: ClientData([New, New, New]) }]","v":0,"name":"crucible","level":30,"time":"2025-03-18T15:16:26.166216156Z","hostname":"w-01JPMWYMFERKMJPH1PTRHF4EXH","pid":1244,"":"downstairs","":"downstairs","session_id":"bbb5f647-7f05-4812-bf0a-dc0897cb9fc7"}
4202025-03-18T15:16:27.065Z{"msg":"starting reconciliation 55f14b42-18a5-42af-94b8-711c086dd001: found 20 extents that need repair","v":0,"name":"crucible","level":30,"time":"2025-03-18T15:16:26.166234755Z","hostname":"w-01JPMWYMFERKMJPH1PTRHF4EXH","pid":1244,"":"downstairs","":"downstairs","session_id":"bbb5f647-7f05-4812-bf0a-dc0897cb9fc7"}
4212025-03-18T15:16:27.065Z{"msg":"sending reconcile request ReconciliationId(2)","v":0,"name":"crucible","level":30,"time":"2025-03-18T15:16:26.166247994Z","hostname":"w-01JPMWYMFERKMJPH1PTRHF4EXH","pid":1244,"client":"2","":"downstairs","session_id":"bbb5f647-7f05-4812-bf0a-dc0897cb9fc7"}
4222025-03-18T15:16:27.073Z{"msg":"sending reconcile request ReconciliationId(6)","v":0,"name":"crucible","level":30,"time":"2025-03-18T15:16:26.176878789Z","hostname":"w-01JPMWYMFERKMJPH1PTRHF4EXH","pid":1244,"client":"2","":"downstairs","session_id":"bbb5f647-7f05-4812-bf0a-dc0897cb9fc7"}
4232025-03-18T15:16:27.077Z{"msg":"sending reconcile request ReconciliationId(10)","v":0,"name":"crucible","level":30,"time":"2025-03-18T15:16:26.180798053Z","hostname":"w-01JPMWYMFERKMJPH1PTRHF4EXH","pid":1244,"client":"2","":"downstairs","session_id":"bbb5f647-7f05-4812-bf0a-dc0897cb9fc7"}
4242025-03-18T15:16:27.081Z{"msg":"sending reconcile request ReconciliationId(14)","v":0,"name":"crucible","level":30,"time":"2025-03-18T15:16:26.184539467Z","hostname":"w-01JPMWYMFERKMJPH1PTRHF4EXH","pid":1244,"client":"2","":"downstairs","session_id":"bbb5f647-7f05-4812-bf0a-dc0897cb9fc7"}
4252025-03-18T15:16:27.084Z{"msg":"sending reconcile request ReconciliationId(18)","v":0,"name":"crucible","level":30,"time":"2025-03-18T15:16:26.188337329Z","hostname":"w-01JPMWYMFERKMJPH1PTRHF4EXH","pid":1244,"client":"2","":"downstairs","session_id":"bbb5f647-7f05-4812-bf0a-dc0897cb9fc7"}
4262025-03-18T15:16:27.087Z{"msg":"done with reconciliation","v":0,"name":"crucible","level":30,"time":"2025-03-18T15:16:26.191380452Z","hostname":"w-01JPMWYMFERKMJPH1PTRHF4EXH","pid":1244,"":"downstairs","":"downstairs","session_id":"bbb5f647-7f05-4812-bf0a-dc0897cb9fc7"}
4272025-03-18T15:16:27.088Z{"msg":"Transition from Reconcile to Active","v":0,"name":"crucible","level":30,"time":"2025-03-18T15:16:26.191419419Z","hostname":"w-01JPMWYMFERKMJPH1PTRHF4EXH","pid":1244,"client":"0","":"downstairs","session_id":"bbb5f647-7f05-4812-bf0a-dc0897cb9fc7"}
4282025-03-18T15:16:27.088Z{"msg":"Transition from Reconcile to Active","v":0,"name":"crucible","level":30,"time":"2025-03-18T15:16:26.191436608Z","hostname":"w-01JPMWYMFERKMJPH1PTRHF4EXH","pid":1244,"client":"1","":"downstairs","session_id":"bbb5f647-7f05-4812-bf0a-dc0897cb9fc7"}
4292025-03-18T15:16:27.088Z{"msg":"Transition from Reconcile to Active","v":0,"name":"crucible","level":30,"time":"2025-03-18T15:16:26.191458646Z","hostname":"w-01JPMWYMFERKMJPH1PTRHF4EXH","pid":1244,"client":"2","":"downstairs","session_id":"bbb5f647-7f05-4812-bf0a-dc0897cb9fc7"}
4302025-03-18T15:16:27.088Z{"msg":"All required reconciliation work is completed","v":0,"name":"crucible","level":30,"time":"2025-03-18T15:16:26.191475785Z","hostname":"w-01JPMWYMFERKMJPH1PTRHF4EXH","pid":1244,"session_id":"bbb5f647-7f05-4812-bf0a-dc0897cb9fc7"}
4312025-03-18T15:16:27.088Z{"msg":"Set Downstairs and Upstairs active after reconciliation","v":0,"name":"crucible","level":30,"time":"2025-03-18T15:16:26.191505423Z","hostname":"w-01JPMWYMFERKMJPH1PTRHF4EXH","pid":1244,"session_id":"bbb5f647-7f05-4812-bf0a-dc0897cb9fc7"}
4322025-03-18T15:16:27.088Z{"msg":"The guest has finished waiting for activation with:33","v":0,"name":"crucible","level":30,"time":"2025-03-18T15:16:26.191522362Z","hostname":"w-01JPMWYMFERKMJPH1PTRHF4EXH","pid":1244}
4332025-03-18T15:16:27.088Z{"msg":"e67d0a20-c5b0-45e1-9d2d-da14715fee67 is now active with session: bbb5f647-7f05-4812-bf0a-dc0897cb9fc7","v":0,"name":"crucible","level":30,"time":"2025-03-18T15:16:26.191534531Z","hostname":"w-01JPMWYMFERKMJPH1PTRHF4EXH","pid":1244,"session_id":"bbb5f647-7f05-4812-bf0a-dc0897cb9fc7"}
4342025-03-18T15:16:27.091Z{"msg":"Activated sub_volume e67d0a20-c5b0-45e1-9d2d-da14715fee67","v":0,"name":"crucible","level":30,"time":"2025-03-18T15:16:26.191680431Z","hostname":"w-01JPMWYMFERKMJPH1PTRHF4EXH","pid":1244}
4352025-03-18T15:16:27.091ZWait for a query_work_queue command to finish before sending IO
4362025-03-18T15:16:27.091ZDisk: sv:1 bs:4096 ts:204800 tb:50 max_io:50 or 204800
4372025-03-18T15:16:27.091ZLoading write count information from file "/var/tmp/test_up-build/verify_file"
4382025-03-18T15:16:27.091ZRead and Verify all blocks (0..50 range:true)
4392025-03-18T15:16:27.128ZWrote out file "/var/tmp/test_up-build/verify_file"
4402025-03-18T15:16:27.128ZVerify test completed
4412025-03-18T15:16:27.132ZWrote out file "/var/tmp/test_up-build/verify_file"
4422025-03-18T15:16:27.132ZCLIENT: Tests done. All submitted work has been ACK'd
4432025-03-18T15:16:27.132Z----------------------------------------------------------------
4442025-03-18T15:16:27.132Z Crucible gen:33 GIO:true work queues: Upstairs:0 downstairs:1
4452025-03-18T15:16:27.132ZStates: Active Active Active
4462025-03-18T15:16:27.132ZJOBID ACK TYPE BKS/EXT DS:0 DS:1 DS:2 REPLAY
4472025-03-18T15:16:27.132Z 1000 Acked Read 50 Done Done Done false
4482025-03-18T15:16:27.132Z STATES DS:0 DS:1 DS:2 TOTAL
4492025-03-18T15:16:27.132Z Sent 0 0 0 0
4502025-03-18T15:16:27.132Z Done 1 1 1 3
4512025-03-18T15:16:27.132Z Skipped 0 0 0 0
4522025-03-18T15:16:27.132Z Error 0 0 0 0
4532025-03-18T15:16:27.132ZLast Flush: None None None
4542025-03-18T15:16:27.132ZDownstairs last five completed:
4552025-03-18T15:16:27.132ZUpstairs last five completed: 1000
4562025-03-18T15:16:27.132ZCLIENT: Up:0 ds:1 act:3
4572025-03-18T15:16:31.131Z----------------------------------------------------------------
4582025-03-18T15:16:31.131Z Crucible gen:33 GIO:true work queues: Upstairs:0 downstairs:0
4592025-03-18T15:16:31.131ZDownstairs last five completed: 1001 1000
4602025-03-18T15:16:31.131ZUpstairs last five completed: 1001 1000
4612025-03-18T15:16:31.131ZCLIENT: Up:0 ds:0 act:3
4622025-03-18T15:16:31.131ZCLIENT: All crucible jobs finished, exiting program
4632025-03-18T15:16:31.134Z{"msg":"Guest handle has been dropped","v":0,"name":"crucible","level":40,"time":"2025-03-18T15:16:30.234272151Z","hostname":"w-01JPMWYMFERKMJPH1PTRHF4EXH","pid":1244}
4642025-03-18T15:16:31.138ZRepair part 2 passed
4652025-03-18T15:16:31.138Z/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
4662025-03-18T15:16:31.156ZEXT BLOCKS GEN0 GEN1 GEN2 FL0 FL1 FL2 D0 D1 D2 DIFF
4672025-03-18T15:16:31.156Z 0 000-009 32 32 32 1507 1507 1507 F F F
4682025-03-18T15:16:31.156Z 1 010-019 32 32 32 1507 1507 1507 F F F
4692025-03-18T15:16:31.156Z 2 020-029 32 32 32 1507 1507 1507 F F F
4702025-03-18T15:16:31.156Z 3 030-039 32 32 32 1507 1507 1507 F F F
4712025-03-18T15:16:31.156Z 4 040-049 32 32 32 1507 1507 1507 F F F
4722025-03-18T15:16:31.156ZMax gen: 32, Max flush: 1507
4732025-03-18T15:16:31.161Zdump test passed
4742025-03-18T15:16:31.164Z/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
4752025-03-18T15:16:31.179Z Extent 1
4762025-03-18T15:16:31.179ZGEN 32 32 32
4772025-03-18T15:16:31.182ZFLUSH_ID 1507 1507 1507
4782025-03-18T15:16:31.182ZDIRTY
4792025-03-18T15:16:31.182Z
4802025-03-18T15:16:31.182ZBLOCK D0 D1 D2 C0 C1 C2 DIFF
4812025-03-18T15:16:31.183Z010 A A A A A A
4822025-03-18T15:16:31.186Z011 A A A A A A
4832025-03-18T15:16:31.186Z012 A A A A A A
4842025-03-18T15:16:31.186Z013 A A A A A A
4852025-03-18T15:16:31.189Z014 A A A A A A
4862025-03-18T15:16:31.189Z015 A A A A A A
4872025-03-18T15:16:31.191Z016 A A A A A A
4882025-03-18T15:16:31.191Z017 A A A A A A
4892025-03-18T15:16:31.195Z018 A A A A A A
4902025-03-18T15:16:31.195Z019 A A A A A A
4912025-03-18T15:16:31.200Zdump extent test passed
4922025-03-18T15:16:31.203Z/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
4932025-03-18T15:16:31.220ZExtent 2 Block in extent 0 Actual block 20
4942025-03-18T15:16:31.220Z
4952025-03-18T15:16:31.223Z DATA SHA256 VER
4962025-03-18T15:16:31.223Z------ ---------------------------------------------------------------- ---
4972025-03-18T15:16:31.223Z 0 402ca6cfa8658241356017451b2bdaca5cd1cfa9e49066df9dd09e5507e8fabc A
4982025-03-18T15:16:31.226Z 1 402ca6cfa8658241356017451b2bdaca5cd1cfa9e49066df9dd09e5507e8fabc A
4992025-03-18T15:16:31.226Z 2 402ca6cfa8658241356017451b2bdaca5cd1cfa9e49066df9dd09e5507e8fabc A
5002025-03-18T15:16:31.226Z
5012025-03-18T15:16:31.226ZNONCES 0 1 2 DIFF
5022025-03-18T15:16:31.226Z------ ------------------------ ------------------------ ------------------------ -----
5032025-03-18T15:16:31.226Z 0 27f3c101d8591e7e3ef8e2f0 27f3c101d8591e7e3ef8e2f0 27f3c101d8591e7e3ef8e2f0
5042025-03-18T15:16:31.226Z
5052025-03-18T15:16:31.226Z TAGS 0 1 2 DIFF
5062025-03-18T15:16:31.226Z------ -------------------------------- -------------------------------- -------------------------------- -----
5072025-03-18T15:16:31.226Z 0 e5cb2d5670ccb0e5baec4ddd44b662e0 e5cb2d5670ccb0e5baec4ddd44b662e0 e5cb2d5670ccb0e5baec4ddd44b662e0
5082025-03-18T15:16:31.226Z
5092025-03-18T15:16:31.226ZHASHES 0 1 2 DIFF
5102025-03-18T15:16:31.226Z------ ---------------- ---------------- ---------------- -----
5112025-03-18T15:16:31.226Z
5122025-03-18T15:16:31.229Zdump block test passed
5132025-03-18T15:16:31.229ZInitial upstairs tests have completed, stopping all downstairs
5142025-03-18T15:16:36.294ZCreating 4 larger downstairs regions
5152025-03-18T15:16:36.430ZStarting 4 downstairs
5162025-03-18T15:16:41.438Zdsc restarted at PID: 1257
5172025-03-18T15:16:41.686ZNow do the replace-reconcile test
5182025-03-18T15:16:41.749ZUsing 8840 for the replacement port
5192025-03-18T15:19:16.539ZCompleted test: replace-reconcile
5202025-03-18T15:19:16.543ZNow do the replace-before-active test
5212025-03-18T15:22:23.025ZCompleted test: replace-before-active
5222025-03-18T15:22:23.025ZAll tests have completed, stopping all downstairs
5232025-03-18T15:22:23.085Z
5242025-03-18T15:22:23.085ZAll Tests have passed
5252025-03-18T15:22:23.088Z9:37 Test duration
5262025-03-18T15:22:23.088Z
5272025-03-18T15:22:23.088Zreal 9:36.407245806
5282025-03-18T15:22:23.089Zuser 6:26.318776948
5292025-03-18T15:22:23.089Zsys 13.114623867
5302025-03-18T15:22:23.089Ztrap 0.215450419
5312025-03-18T15:22:23.089Ztflt 0.018283010
5322025-03-18T15:22:23.089Zdflt 0.047600957
5332025-03-18T15:22:23.089Zkflt 0.001165218
5342025-03-18T15:22:23.089Zlock 8:26:05.581935250
5352025-03-18T15:22:23.089Zslp 33:24.628271974
5362025-03-18T15:22:23.089Zlat 23.852214650
5372025-03-18T15:22:23.089Zstop 0.142588983
5382025-03-18T15:22:23.089Z+ echo 'test-up-encrypted ends'
5392025-03-18T15:22:23.089Ztest-up-encrypted ends
5402025-03-18T15:22:28.091Zprocess exited: duration 585046 ms, exit code 0
5412025-03-18T15:22:28.091Zexec warning: : stdio descriptors remain open after task exit; waiting 60 seconds for them to close
5422025-03-18T15:23:28.130Zexec warning: : stdout descriptor may be held open by a background process; giving up!
5432025-03-18T15:23:28.130Zexec warning: : stderr descriptor may be held open by a background process; giving up!
 
5442025-03-18T15:23:28.142Zfound 14 output files
5452025-03-18T15:23:28.142Zuploading: /tmp/test_up-build/dsc-out.txt (37781 bytes)
5462025-03-18T15:23:29.159Zuploaded: /tmp/test_up-build/dsc-out.txt
5472025-03-18T15:23:29.168Zuploading: /tmp/test_up-build/test_up_out.txt (7480660 bytes)
5482025-03-18T15:23:30.245Zuploaded: /tmp/test_up-build/test_up_out.txt
5492025-03-18T15:23:30.248Zuploading: /tmp/test_up-build/dsc/downstairs-8810.txt (2480 bytes)
5502025-03-18T15:23:31.258Zuploaded: /tmp/test_up-build/dsc/downstairs-8810.txt
5512025-03-18T15:23:31.261Zuploading: /tmp/test_up-build/dsc/downstairs-8820.txt (144619 bytes)
5522025-03-18T15:23:32.273Zuploaded: /tmp/test_up-build/dsc/downstairs-8820.txt
5532025-03-18T15:23:32.276Zuploading: /tmp/test_up-build/dsc/downstairs-8830.txt (251031 bytes)
5542025-03-18T15:23:33.292Zuploaded: /tmp/test_up-build/dsc/downstairs-8830.txt
5552025-03-18T15:23:33.295Zuploading: /tmp/test_up-build/dsc/downstairs-8840.txt (139423 bytes)
5562025-03-18T15:23:34.312Zuploaded: /tmp/test_up-build/dsc/downstairs-8840.txt
5572025-03-18T15:23:34.315Zuploading: /tmp/debug/df.txt (1270 bytes)
5582025-03-18T15:23:35.322Zuploaded: /tmp/debug/df.txt
5592025-03-18T15:23:35.326Zuploading: /tmp/debug/dtrace.txt (454529 bytes)
5602025-03-18T15:23:36.354Zuploaded: /tmp/debug/dtrace.txt
5612025-03-18T15:23:36.358Zuploading: /tmp/debug/iostat.txt (191354 bytes)
5622025-03-18T15:23:36.372Zupload warning: file "/tmp/debug/iostat.txt" changed size mid upload: 191354 -> 193738
5632025-03-18T15:23:37.380Zuploaded: /tmp/debug/iostat.txt
5642025-03-18T15:23:37.380Zuploading: /tmp/debug/mpstat.txt (466738 bytes)
5652025-03-18T15:23:37.407Zupload warning: file "/tmp/debug/mpstat.txt" changed size mid upload: 466738 -> 473281
5662025-03-18T15:23:38.414Zuploaded: /tmp/debug/mpstat.txt
5672025-03-18T15:23:38.415Zuploading: /tmp/debug/paging.txt (82816 bytes)
5682025-03-18T15:23:38.425Zupload warning: file "/tmp/debug/paging.txt" changed size mid upload: 82816 -> 84104
5692025-03-18T15:23:39.433Zuploaded: /tmp/debug/paging.txt
5702025-03-18T15:23:39.433Zuploading: /tmp/debug/prstat.txt (897319 bytes)
5712025-03-18T15:23:39.475Zupload warning: file "/tmp/debug/prstat.txt" changed size mid upload: 897319 -> 911547
5722025-03-18T15:23:40.482Zuploaded: /tmp/debug/prstat.txt
5732025-03-18T15:23:40.485Zuploading: /tmp/debug/psrinfo.txt (1528 bytes)
5742025-03-18T15:23:41.494Zuploaded: /tmp/debug/psrinfo.txt
5752025-03-18T15:23:41.498Zuploading: /tmp/debug/upstairs-info.txt (66660 bytes)
5762025-03-18T15:23:42.510Zuploaded: /tmp/debug/upstairs-info.txt