|
|
|
| 1 | 2025-05-27T21:11:28.995Z | job dependencies complete; ready to run (waiting for 14 m 35 s) |
| 2 | 2025-05-27T21:12:41.207Z | job assigned to worker 01JW9SC4ZQ9YSQWP2B7N5AJD2Z [factory aws, i-02b6aadce43a851f8] (queued for 1 m 12 s) |
| 3 | 2025-05-27T21:12:49.144Z | downloading input: /input/build/work/bins/crucible-downstairs.gz |
| 4 | 2025-05-27T21:12:50.324Z | downloaded input: /input/build/work/bins/crucible-downstairs.gz |
| 5 | 2025-05-27T21:12:50.324Z | downloading input: /input/build/work/bins/crucible-hammer.gz |
| 6 | 2025-05-27T21:12:51.423Z | downloaded input: /input/build/work/bins/crucible-hammer.gz |
| 7 | 2025-05-27T21:12:51.423Z | downloading input: /input/build/work/bins/crutest.gz |
| 8 | 2025-05-27T21:12:52.613Z | downloaded input: /input/build/work/bins/crutest.gz |
| 9 | 2025-05-27T21:12:52.613Z | downloading input: /input/build/work/bins/dsc.gz |
| 10 | 2025-05-27T21:12:53.276Z | downloaded input: /input/build/work/bins/dsc.gz |
| 11 | 2025-05-27T21:12:53.281Z | downloading input: /input/build/work/scripts/perf-downstairs-tick.d |
| 12 | 2025-05-27T21:12:53.301Z | downloaded input: /input/build/work/scripts/perf-downstairs-tick.d |
| 13 | 2025-05-27T21:12:53.301Z | downloading input: /input/build/work/scripts/test_ds.sh |
| 14 | 2025-05-27T21:12:53.326Z | downloaded input: /input/build/work/scripts/test_ds.sh |
| 15 | 2025-05-27T21:12:53.326Z | downloading input: /input/build/work/scripts/test_live_repair.sh |
| 16 | 2025-05-27T21:12:53.347Z | downloaded input: /input/build/work/scripts/test_live_repair.sh |
| 17 | 2025-05-27T21:12:53.347Z | downloading input: /input/build/work/scripts/test_repair.sh |
| 18 | 2025-05-27T21:12:53.367Z | downloaded input: /input/build/work/scripts/test_repair.sh |
| 19 | 2025-05-27T21:12:53.367Z | downloading input: /input/build/work/scripts/test_replay.sh |
| 20 | 2025-05-27T21:12:53.390Z | downloaded input: /input/build/work/scripts/test_replay.sh |
| 21 | 2025-05-27T21:12:53.391Z | downloading input: /input/build/work/scripts/test_up.sh |
| 22 | 2025-05-27T21:12:53.412Z | downloaded input: /input/build/work/scripts/test_up.sh |
| 23 | 2025-05-27T21:12:53.412Z | downloading input: /input/build/work/scripts/upstairs_info.d |
| 24 | 2025-05-27T21:12:53.433Z | downloaded input: /input/build/work/scripts/upstairs_info.d |
| 25 | 2025-05-27T21:12:53.436Z | downloading input: /input/build/tmp/cargo-test-out.log |
| 26 | 2025-05-27T21:12:54.099Z | downloaded input: /input/build/tmp/cargo-test-out.log |
| |
| 27 | 2025-05-27T21:12:54.100Z | starting task 0: "setup" |
| 28 | 2025-05-27T21:12:54.103Z | ++ uname -s |
| 29 | 2025-05-27T21:12:54.106Z | + kern=SunOS |
| 30 | 2025-05-27T21:12:54.107Z | + build_user=build |
| 31 | 2025-05-27T21:12:54.107Z | + build_uid=12345 |
| 32 | 2025-05-27T21:12:54.107Z | + work_dir=/work |
| 33 | 2025-05-27T21:12:54.107Z | + input_dir=/input |
| 34 | 2025-05-27T21:12:54.107Z | + [[ 0 == 12345 ]] |
| 35 | 2025-05-27T21:12:54.107Z | + case "$kern" in |
| 36 | 2025-05-27T21:12:54.107Z | + groupadd -g 12345 build |
| 37 | 2025-05-27T21:12:54.110Z | + useradd -u 12345 -g build -d /home/build -s /bin/bash -c build -P 'Primary Administrator' build |
| 38 | 2025-05-27T21:12:56.116Z | + zfs create -o mountpoint=/work rpool/work |
| 39 | 2025-05-27T21:12:56.314Z | ++ awk '$2 == "/home" { print $3 }' /etc/mnttab |
| 40 | 2025-05-27T21:12:56.317Z | + home_fs=zfs |
| 41 | 2025-05-27T21:12:56.317Z | + [[ zfs == autofs ]] |
| 42 | 2025-05-27T21:12:56.317Z | + mkdir -p /home/build |
| 43 | 2025-05-27T21:12:56.321Z | + chown build:build /home/build /work |
| 44 | 2025-05-27T21:12:58.320Z | + chmod 0700 /home/build /work |
| 45 | 2025-05-27T21:12:58.324Z | process exited: duration 4227 ms, exit code 0 |
| |
| 46 | 2025-05-27T21:12:58.330Z | starting task 1: "authentication" |
| 47 | 2025-05-27T21:12:58.348Z | process exited: duration 18 ms, exit code 0 |
| |
| 48 | 2025-05-27T21:12:58.357Z | starting task 2: "build" |
| 49 | 2025-05-27T21:12:58.361Z | + banner cores |
| 50 | 2025-05-27T21:12:58.364Z | |
| 51 | 2025-05-27T21:12:58.364Z | #### #### ##### ###### #### |
| 52 | 2025-05-27T21:12:58.364Z | # # # # # # # # |
| 53 | 2025-05-27T21:12:58.364Z | # # # # # ##### #### |
| 54 | 2025-05-27T21:12:58.364Z | # # # ##### # # |
| 55 | 2025-05-27T21:12:58.364Z | # # # # # # # # # |
| 56 | 2025-05-27T21:12:58.364Z | #### #### # # ###### #### |
| 57 | 2025-05-27T21:12:58.364Z | |
| 58 | 2025-05-27T21:12:58.364Z | + pfexec coreadm -i /tmp/core.%f.%p -g /tmp/core.%f.%p -e global -e log -e proc-setid -e global-setid |
| 59 | 2025-05-27T21:12:58.372Z | + echo 'input bins dir contains:' |
| 60 | 2025-05-27T21:12:58.372Z | input bins dir contains: |
| 61 | 2025-05-27T21:12:58.375Z | + ls -ltr /input/build/work/bins |
| 62 | 2025-05-27T21:12:58.375Z | total 798184 |
| 63 | 2025-05-27T21:12:58.375Z | -rw-r--r-- 1 root root 116152933 May 27 21:12 crucible-downstairs.gz |
| 64 | 2025-05-27T21:12:58.375Z | -rw-r--r-- 1 root root 109360001 May 27 21:12 crucible-hammer.gz |
| 65 | 2025-05-27T21:12:58.375Z | -rw-r--r-- 1 root root 118453644 May 27 21:12 crutest.gz |
| 66 | 2025-05-27T21:12:58.375Z | -rw-r--r-- 1 root root 64443062 May 27 21:12 dsc.gz |
| 67 | 2025-05-27T21:12:58.375Z | + banner unpack |
| 68 | 2025-05-27T21:12:58.380Z | |
| 69 | 2025-05-27T21:12:58.380Z | # # # # ##### ## #### # # |
| 70 | 2025-05-27T21:12:58.380Z | # # ## # # # # # # # # # |
| 71 | 2025-05-27T21:12:58.380Z | # # # # # # # # # # #### |
| 72 | 2025-05-27T21:12:58.380Z | # # # # # ##### ###### # # # |
| 73 | 2025-05-27T21:12:58.380Z | # # # ## # # # # # # # |
| 74 | 2025-05-27T21:12:58.380Z | #### # # # # # #### # # |
| 75 | 2025-05-27T21:12:58.380Z | |
| 76 | 2025-05-27T21:12:58.380Z | + mkdir -p /var/tmp/bins |
| 77 | 2025-05-27T21:12:58.380Z | + for t in "$input/bins/"*.gz |
| 78 | 2025-05-27T21:12:58.383Z | ++ basename /input/build/work/bins/crucible-downstairs.gz |
| 79 | 2025-05-27T21:12:58.383Z | + b=crucible-downstairs.gz |
| 80 | 2025-05-27T21:12:58.384Z | + b=crucible-downstairs |
| 81 | 2025-05-27T21:12:58.384Z | + gunzip |
| 82 | 2025-05-27T21:13:00.780Z | + chmod +x /var/tmp/bins/crucible-downstairs |
| 83 | 2025-05-27T21:13:00.784Z | + for t in "$input/bins/"*.gz |
| 84 | 2025-05-27T21:13:00.784Z | ++ basename /input/build/work/bins/crucible-hammer.gz |
| 85 | 2025-05-27T21:13:00.787Z | + b=crucible-hammer.gz |
| 86 | 2025-05-27T21:13:00.787Z | + b=crucible-hammer |
| 87 | 2025-05-27T21:13:00.787Z | + gunzip |
| 88 | 2025-05-27T21:13:03.031Z | + chmod +x /var/tmp/bins/crucible-hammer |
| 89 | 2025-05-27T21:13:03.034Z | + for t in "$input/bins/"*.gz |
| 90 | 2025-05-27T21:13:03.034Z | ++ basename /input/build/work/bins/crutest.gz |
| 91 | 2025-05-27T21:13:03.037Z | + b=crutest.gz |
| 92 | 2025-05-27T21:13:03.037Z | + b=crutest |
| 93 | 2025-05-27T21:13:03.037Z | + gunzip |
| 94 | 2025-05-27T21:13:05.558Z | + chmod +x /var/tmp/bins/crutest |
| 95 | 2025-05-27T21:13:05.562Z | + for t in "$input/bins/"*.gz |
| 96 | 2025-05-27T21:13:05.562Z | ++ basename /input/build/work/bins/dsc.gz |
| 97 | 2025-05-27T21:13:05.565Z | + b=dsc.gz |
| 98 | 2025-05-27T21:13:05.565Z | + b=dsc |
| 99 | 2025-05-27T21:13:05.565Z | + gunzip |
| 100 | 2025-05-27T21:13:06.865Z | + chmod +x /var/tmp/bins/dsc |
| 101 | 2025-05-27T21:13:06.868Z | + export BINDIR=/var/tmp/bins |
| 102 | 2025-05-27T21:13:06.868Z | + BINDIR=/var/tmp/bins |
| 103 | 2025-05-27T21:13:06.869Z | + export RUST_BACKTRACE=1 |
| 104 | 2025-05-27T21:13:06.869Z | + RUST_BACKTRACE=1 |
| 105 | 2025-05-27T21:13:06.869Z | + jobpid=1160 |
| 106 | 2025-05-27T21:13:06.869Z | + echo 'Setup debug logging' |
| 107 | 2025-05-27T21:13:06.869Z | Setup debug logging |
| 108 | 2025-05-27T21:13:06.869Z | + mkdir /tmp/debug |
| 109 | 2025-05-27T21:13:06.869Z | + sleep 7200 |
| 110 | 2025-05-27T21:13:06.872Z | + psrinfo -v |
| 111 | 2025-05-27T21:13:06.876Z | + df -h |
| 112 | 2025-05-27T21:13:06.883Z | + prstat -d d -mLc 1 |
| 113 | 2025-05-27T21:13:06.886Z | + iostat -T d -xn 1 |
| 114 | 2025-05-27T21:13:06.886Z | + mpstat -T d 1 |
| 115 | 2025-05-27T21:13:06.886Z | + vmstat -T d -p 1 |
| 116 | 2025-05-27T21:13:06.886Z | + pfexec dtrace -Z -s /input/build/work/scripts/perf-downstairs-tick.d |
| 117 | 2025-05-27T21:13:06.890Z | + banner test_up_unencrypted |
| 118 | 2025-05-27T21:13:06.890Z | + pfexec dtrace -Z -s /input/build/work/scripts/upstairs_info.d |
| 119 | 2025-05-27T21:13:06.890Z | |
| 120 | 2025-05-27T21:13:06.890Z | ##### ###### #### ##### # # ##### # # # # |
| 121 | 2025-05-27T21:13:06.890Z | # # # # # # # # # # ## # |
| 122 | 2025-05-27T21:13:06.890Z | # ##### #### # # # # # # # # # # |
| 123 | 2025-05-27T21:13:06.890Z | # # # # # # ##### # # # # # |
| 124 | 2025-05-27T21:13:06.890Z | # # # # # # # # # # # ## |
| 125 | 2025-05-27T21:13:06.890Z | # ###### #### # ####### #### # ####### #### # # |
| 126 | 2025-05-27T21:13:06.890Z | |
| 127 | 2025-05-27T21:13:06.890Z | + ptime -m bash /input/build/work/scripts/test_up.sh -N unencrypted |
| 128 | 2025-05-27T21:13:06.902Z | /input/build/work |
| 129 | 2025-05-27T21:13:06.914Z | Turn off color for downstairs dump |
| 130 | 2025-05-27T21:13:06.918Z | dsc output goes to /tmp/test_up-build/dsc-out.txt |
| 131 | 2025-05-27T21:13:06.918Z | Creating 3 downstairs regions |
| 132 | 2025-05-27T21:13:07.244Z | Starting 3 downstairs |
| 133 | 2025-05-27T21:13:07.248Z | dsc started at PID: 1205 |
| 134 | 2025-05-27T21:13:12.428Z | Disable automatic restart on all downstairs |
| 135 | 2025-05-27T21:13:12.483Z | |
| 136 | 2025-05-27T21:13:12.483Z | Begin tests, output goes to /tmp/test_up-build/test_up_out.txt |
| 137 | 2025-05-27T21:13:12.486Z | Running test: span |
| 138 | 2025-05-27T21:13:16.636Z | Completed test: span |
| 139 | 2025-05-27T21:13:21.643Z | Running test: big |
| 140 | 2025-05-27T21:13:25.791Z | Completed test: big |
| 141 | 2025-05-27T21:13:30.798Z | Running test: dep |
| 142 | 2025-05-27T21:13:43.791Z | Completed test: dep |
| 143 | 2025-05-27T21:13:48.798Z | Running test: balloon |
| 144 | 2025-05-27T21:13:58.609Z | Completed test: balloon |
| 145 | 2025-05-27T21:14:03.616Z | Running test: deactivate |
| 146 | 2025-05-27T21:14:57.828Z | Completed test: deactivate |
| 147 | 2025-05-27T21:15:02.835Z | Running hammer |
| 148 | 2025-05-27T21:15:05.830Z | Run repair tests |
| 149 | 2025-05-27T21:15:05.834Z | /var/tmp/bins/crutest fill -g 31 -q --dsc 127.0.0.1:9998 --verify-out /var/tmp/test_up-build/verify_file |
| 150 | 2025-05-27T21:15:05.891Z | {"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-05-27T21:15:05.444560887Z","hostname":"w-01JW9SC4ZQ9YSQWP2B7N5AJD2Z","pid":1242,"task":"crutest"} |
| 151 | 2025-05-27T21:15:05.895Z | {"msg":"dsc has 3 regions. This means 1 sub_volumes","v":0,"name":"crucible","level":30,"time":"2025-05-27T21:15:05.44525404Z","hostname":"w-01JW9SC4ZQ9YSQWP2B7N5AJD2Z","pid":1242,"task":"crutest"} |
| 152 | 2025-05-27T21:15:05.895Z | {"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-05-27T21:15:05.446896993Z","hostname":"w-01JW9SC4ZQ9YSQWP2B7N5AJD2Z","pid":1242,"task":"crutest"} |
| 153 | 2025-05-27T21:15:05.895Z | {"msg":"Upstairs starts","v":0,"name":"crucible","level":30,"time":"2025-05-27T21:15:05.447095259Z","hostname":"w-01JW9SC4ZQ9YSQWP2B7N5AJD2Z","pid":1242} |
| 154 | 2025-05-27T21:15:05.895Z | {"msg":"Crucible Version: BuildInfo {\n version: \"0.0.1\",\n git_sha: \"dd892d47062b1dcb23800b8bbb5d2946e1dd1cb7\",\n git_commit_timestamp: \"2025-05-27T20:18:55.000000000Z\",\n git_branch: \"alan/agent-needs-workers\",\n rustc_semver: \"1.86.0\",\n rustc_channel: \"stable\",\n rustc_host_triple: \"x86_64-unknown-illumos\",\n rustc_commit_sha: \"05f9846f893b09a1be1fc8560e33fc3c815cfecb\",\n cargo_triple: \"x86_64-unknown-illumos\",\n debug: true,\n opt_level: 0,\n}","v":0,"name":"crucible","level":30,"time":"2025-05-27T21:15:05.44713255Z","hostname":"w-01JW9SC4ZQ9YSQWP2B7N5AJD2Z","pid":1242} |
| 155 | 2025-05-27T21:15:05.895Z | {"msg":"Upstairs <-> Downstairs Message Version: 13","v":0,"name":"crucible","level":30,"time":"2025-05-27T21:15:05.447146261Z","hostname":"w-01JW9SC4ZQ9YSQWP2B7N5AJD2Z","pid":1242} |
| 156 | 2025-05-27T21:15:05.895Z | {"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: false, database_read_version: 1, database_write_version: 1 }","v":0,"name":"crucible","level":30,"time":"2025-05-27T21:15:05.447167922Z","hostname":"w-01JW9SC4ZQ9YSQWP2B7N5AJD2Z","pid":1242} |
| 157 | 2025-05-27T21:15:05.895Z | {"msg":"Crucible 26c195d1-2259-44b7-a88a-b49b70b46d59 has session id: d3836926-66a5-4536-b404-aa01474a508a","v":0,"name":"crucible","level":30,"time":"2025-05-27T21:15:05.447793602Z","hostname":"w-01JW9SC4ZQ9YSQWP2B7N5AJD2Z","pid":1242,"session_id":"d3836926-66a5-4536-b404-aa01474a508a"} |
| 158 | 2025-05-27T21:15:05.895Z | {"msg":"Upstairs opts: Upstairs UUID: 26c195d1-2259-44b7-a88a-b49b70b46d59, Targets: [127.0.0.1:8810, 127.0.0.1:8820, 127.0.0.1:8830], lossy: false, flush_timeout: None, key populated: false, cert_pem populated: false, key_pem populated: false, root_cert_pem populated: false, Control: None, read_only: false","v":0,"name":"crucible","level":30,"time":"2025-05-27T21:15:05.447847593Z","hostname":"w-01JW9SC4ZQ9YSQWP2B7N5AJD2Z","pid":1242,"session_id":"d3836926-66a5-4536-b404-aa01474a508a"} |
| 159 | 2025-05-27T21:15:05.895Z | {"msg":"Crucible stats registered with UUID: 26c195d1-2259-44b7-a88a-b49b70b46d59","v":0,"name":"crucible","level":30,"time":"2025-05-27T21:15:05.447872774Z","hostname":"w-01JW9SC4ZQ9YSQWP2B7N5AJD2Z","pid":1242,"session_id":"d3836926-66a5-4536-b404-aa01474a508a"} |
| 160 | 2025-05-27T21:15:05.895Z | {"msg":"could not find Downstairs address for Nexus","v":0,"name":"crucible","level":40,"time":"2025-05-27T21:15:05.447910425Z","hostname":"w-01JW9SC4ZQ9YSQWP2B7N5AJD2Z","pid":1242,"session_id":"d3836926-66a5-4536-b404-aa01474a508a"} |
| 161 | 2025-05-27T21:15:05.900Z | {"msg":"Downstairs in volume = 3","v":0,"name":"crucible","level":30,"time":"2025-05-27T21:15:05.448819375Z","hostname":"w-01JW9SC4ZQ9YSQWP2B7N5AJD2Z","pid":1242,"task":"crutest"} |
| 162 | 2025-05-27T21:15:05.900Z | {"msg":"The guest has requested activation with gen:31","v":0,"name":"crucible","level":30,"time":"2025-05-27T21:15:05.448871626Z","hostname":"w-01JW9SC4ZQ9YSQWP2B7N5AJD2Z","pid":1242} |
| 163 | 2025-05-27T21:15:05.900Z | {"msg":"26c195d1-2259-44b7-a88a-b49b70b46d59 active request set","v":0,"name":"crucible","level":30,"time":"2025-05-27T21:15:05.448950669Z","hostname":"w-01JW9SC4ZQ9YSQWP2B7N5AJD2Z","pid":1242,"session_id":"d3836926-66a5-4536-b404-aa01474a508a"} |
| 164 | 2025-05-27T21:15:05.900Z | {"msg":"sending connect oneshot to client","v":0,"name":"crucible","level":30,"time":"2025-05-27T21:15:05.44898318Z","hostname":"w-01JW9SC4ZQ9YSQWP2B7N5AJD2Z","pid":1242,"client":"0","":"downstairs","session_id":"d3836926-66a5-4536-b404-aa01474a508a"} |
| 165 | 2025-05-27T21:15:05.900Z | {"msg":"client set_active_request while in Connecting { state: Start { auto_promote: true }, mode: New }; waiting...","v":0,"name":"crucible","level":30,"time":"2025-05-27T21:15:05.44900717Z","hostname":"w-01JW9SC4ZQ9YSQWP2B7N5AJD2Z","pid":1242,"client":"0","":"downstairs","session_id":"d3836926-66a5-4536-b404-aa01474a508a"} |
| 166 | 2025-05-27T21:15:05.900Z | {"msg":"sending connect oneshot to client","v":0,"name":"crucible","level":30,"time":"2025-05-27T21:15:05.449021451Z","hostname":"w-01JW9SC4ZQ9YSQWP2B7N5AJD2Z","pid":1242,"client":"1","":"downstairs","session_id":"d3836926-66a5-4536-b404-aa01474a508a"} |
| 167 | 2025-05-27T21:15:05.900Z | {"msg":"client set_active_request while in Connecting { state: Start { auto_promote: true }, mode: New }; waiting...","v":0,"name":"crucible","level":30,"time":"2025-05-27T21:15:05.449035382Z","hostname":"w-01JW9SC4ZQ9YSQWP2B7N5AJD2Z","pid":1242,"client":"1","":"downstairs","session_id":"d3836926-66a5-4536-b404-aa01474a508a"} |
| 168 | 2025-05-27T21:15:05.901Z | {"msg":"sending connect oneshot to client","v":0,"name":"crucible","level":30,"time":"2025-05-27T21:15:05.449047772Z","hostname":"w-01JW9SC4ZQ9YSQWP2B7N5AJD2Z","pid":1242,"client":"2","":"downstairs","session_id":"d3836926-66a5-4536-b404-aa01474a508a"} |
| 169 | 2025-05-27T21:15:05.901Z | {"msg":"client set_active_request while in Connecting { state: Start { auto_promote: true }, mode: New }; waiting...","v":0,"name":"crucible","level":30,"time":"2025-05-27T21:15:05.449062392Z","hostname":"w-01JW9SC4ZQ9YSQWP2B7N5AJD2Z","pid":1242,"client":"2","":"downstairs","session_id":"d3836926-66a5-4536-b404-aa01474a508a"} |
| 170 | 2025-05-27T21:15:05.901Z | {"msg":"connecting to 127.0.0.1:8830","v":0,"name":"crucible","level":30,"time":"2025-05-27T21:15:05.449074943Z","hostname":"w-01JW9SC4ZQ9YSQWP2B7N5AJD2Z","pid":1242,"":"io task","client":"2","":"downstairs","session_id":"d3836926-66a5-4536-b404-aa01474a508a"} |
| 171 | 2025-05-27T21:15:05.901Z | {"msg":"connecting to 127.0.0.1:8810","v":0,"name":"crucible","level":30,"time":"2025-05-27T21:15:05.449096084Z","hostname":"w-01JW9SC4ZQ9YSQWP2B7N5AJD2Z","pid":1242,"":"io task","client":"0","":"downstairs","session_id":"d3836926-66a5-4536-b404-aa01474a508a"} |
| 172 | 2025-05-27T21:15:05.901Z | {"msg":"connecting to 127.0.0.1:8820","v":0,"name":"crucible","level":30,"time":"2025-05-27T21:15:05.449132025Z","hostname":"w-01JW9SC4ZQ9YSQWP2B7N5AJD2Z","pid":1242,"":"io task","client":"1","":"downstairs","session_id":"d3836926-66a5-4536-b404-aa01474a508a"} |
| 173 | 2025-05-27T21:15:05.901Z | {"msg":"ds_connection connected from Ok(127.0.0.1:57925)","v":0,"name":"crucible","level":30,"time":"2025-05-27T21:15:05.449159595Z","hostname":"w-01JW9SC4ZQ9YSQWP2B7N5AJD2Z","pid":1242,"":"io task","client":"2","":"downstairs","session_id":"d3836926-66a5-4536-b404-aa01474a508a"} |
| 174 | 2025-05-27T21:15:05.901Z | {"msg":"ds_connection connected from Ok(127.0.0.1:38594)","v":0,"name":"crucible","level":30,"time":"2025-05-27T21:15:05.449193676Z","hostname":"w-01JW9SC4ZQ9YSQWP2B7N5AJD2Z","pid":1242,"":"io task","client":"0","":"downstairs","session_id":"d3836926-66a5-4536-b404-aa01474a508a"} |
| 175 | 2025-05-27T21:15:05.901Z | {"msg":"ds_connection connected from Ok(127.0.0.1:38009)","v":0,"name":"crucible","level":30,"time":"2025-05-27T21:15:05.449470865Z","hostname":"w-01JW9SC4ZQ9YSQWP2B7N5AJD2Z","pid":1242,"":"io task","client":"1","":"downstairs","session_id":"d3836926-66a5-4536-b404-aa01474a508a"} |
| 176 | 2025-05-27T21:15:05.901Z | {"msg":"version negotiation from state Connecting { state: WaitForPromote, mode: New }","v":0,"name":"crucible","level":30,"time":"2025-05-27T21:15:05.449883539Z","hostname":"w-01JW9SC4ZQ9YSQWP2B7N5AJD2Z","pid":1242,"client":"0","":"downstairs","session_id":"d3836926-66a5-4536-b404-aa01474a508a"} |
| 177 | 2025-05-27T21:15:05.901Z | {"msg":"version negotiation from state Connecting { state: WaitForPromote, mode: New }","v":0,"name":"crucible","level":30,"time":"2025-05-27T21:15:05.44992765Z","hostname":"w-01JW9SC4ZQ9YSQWP2B7N5AJD2Z","pid":1242,"client":"1","":"downstairs","session_id":"d3836926-66a5-4536-b404-aa01474a508a"} |
| 178 | 2025-05-27T21:15:05.901Z | {"msg":"version negotiation from state Connecting { state: WaitForPromote, mode: New }","v":0,"name":"crucible","level":30,"time":"2025-05-27T21:15:05.450100926Z","hostname":"w-01JW9SC4ZQ9YSQWP2B7N5AJD2Z","pid":1242,"client":"2","":"downstairs","session_id":"d3836926-66a5-4536-b404-aa01474a508a"} |
| 179 | 2025-05-27T21:15:05.901Z | {"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-05-27T21:15:05.45054326Z","hostname":"w-01JW9SC4ZQ9YSQWP2B7N5AJD2Z","pid":1242,"client":"0","":"downstairs","session_id":"d3836926-66a5-4536-b404-aa01474a508a"} |
| 180 | 2025-05-27T21:15:05.901Z | {"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-05-27T21:15:05.450579201Z","hostname":"w-01JW9SC4ZQ9YSQWP2B7N5AJD2Z","pid":1242,"client":"1","":"downstairs","session_id":"d3836926-66a5-4536-b404-aa01474a508a"} |
| 181 | 2025-05-27T21:15:05.901Z | {"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-05-27T21:15:05.450595342Z","hostname":"w-01JW9SC4ZQ9YSQWP2B7N5AJD2Z","pid":1242,"client":"2","":"downstairs","session_id":"d3836926-66a5-4536-b404-aa01474a508a"} |
| 182 | 2025-05-27T21:15:05.901Z | {"msg":"Waiting for more clients to be ready","v":0,"name":"crucible","level":30,"time":"2025-05-27T21:15:05.450962064Z","hostname":"w-01JW9SC4ZQ9YSQWP2B7N5AJD2Z","pid":1242,"session_id":"d3836926-66a5-4536-b404-aa01474a508a"} |
| 183 | 2025-05-27T21:15:05.901Z | {"msg":"Waiting for more clients to be ready","v":0,"name":"crucible","level":30,"time":"2025-05-27T21:15:05.451002855Z","hostname":"w-01JW9SC4ZQ9YSQWP2B7N5AJD2Z","pid":1242,"session_id":"d3836926-66a5-4536-b404-aa01474a508a"} |
| 184 | 2025-05-27T21:15:05.901Z | {"msg":"[0]R flush_numbers: [1496, 1496, 1496, 1496, 1496]","v":0,"name":"crucible","level":30,"time":"2025-05-27T21:15:05.451059296Z","hostname":"w-01JW9SC4ZQ9YSQWP2B7N5AJD2Z","pid":1242,"":"downstairs","":"downstairs","session_id":"d3836926-66a5-4536-b404-aa01474a508a"} |
| 185 | 2025-05-27T21:15:05.901Z | {"msg":"[0]R generation: [25, 25, 25, 25, 25]","v":0,"name":"crucible","level":30,"time":"2025-05-27T21:15:05.451095878Z","hostname":"w-01JW9SC4ZQ9YSQWP2B7N5AJD2Z","pid":1242,"":"downstairs","":"downstairs","session_id":"d3836926-66a5-4536-b404-aa01474a508a"} |
| 186 | 2025-05-27T21:15:05.901Z | {"msg":"[0]R dirty: [false, false, false, false, false]","v":0,"name":"crucible","level":30,"time":"2025-05-27T21:15:05.451115168Z","hostname":"w-01JW9SC4ZQ9YSQWP2B7N5AJD2Z","pid":1242,"":"downstairs","":"downstairs","session_id":"d3836926-66a5-4536-b404-aa01474a508a"} |
| 187 | 2025-05-27T21:15:05.901Z | {"msg":"[1]R flush_numbers: [1496, 1496, 1496, 1496, 1496]","v":0,"name":"crucible","level":30,"time":"2025-05-27T21:15:05.451150639Z","hostname":"w-01JW9SC4ZQ9YSQWP2B7N5AJD2Z","pid":1242,"":"downstairs","":"downstairs","session_id":"d3836926-66a5-4536-b404-aa01474a508a"} |
| 188 | 2025-05-27T21:15:05.901Z | {"msg":"[1]R generation: [25, 25, 25, 25, 25]","v":0,"name":"crucible","level":30,"time":"2025-05-27T21:15:05.45116653Z","hostname":"w-01JW9SC4ZQ9YSQWP2B7N5AJD2Z","pid":1242,"":"downstairs","":"downstairs","session_id":"d3836926-66a5-4536-b404-aa01474a508a"} |
| 189 | 2025-05-27T21:15:05.901Z | {"msg":"[1]R dirty: [false, false, false, false, false]","v":0,"name":"crucible","level":30,"time":"2025-05-27T21:15:05.451202941Z","hostname":"w-01JW9SC4ZQ9YSQWP2B7N5AJD2Z","pid":1242,"":"downstairs","":"downstairs","session_id":"d3836926-66a5-4536-b404-aa01474a508a"} |
| 190 | 2025-05-27T21:15:05.901Z | {"msg":"[2]R flush_numbers: [1496, 1496, 1496, 1496, 1496]","v":0,"name":"crucible","level":30,"time":"2025-05-27T21:15:05.451223792Z","hostname":"w-01JW9SC4ZQ9YSQWP2B7N5AJD2Z","pid":1242,"":"downstairs","":"downstairs","session_id":"d3836926-66a5-4536-b404-aa01474a508a"} |
| 191 | 2025-05-27T21:15:05.901Z | {"msg":"[2]R generation: [25, 25, 25, 25, 25]","v":0,"name":"crucible","level":30Wait for a query_work_queue command to finish before sending IO |
| 192 | 2025-05-27T21:15:05.901Z | ,"time":"2025-05-27T21:15:05.451255493Z","hostname":"w-01JW9SC4ZQ9YSQWP2B7N5AJD2Z","pid":1242,"":"downstairs","":"downstairs","session_id":"d3836926-66a5-4536-b404-aa01474a508a"} |
| 193 | 2025-05-27T21:15:05.901Z | {"msg":"[2]R dirty: [false, false, false, false, false]","v":0,"name":"crucible","level":30,"time":"2025-05-27T21:15:05.451289754Z","hostname":"w-01JW9SC4ZQ9YSQWP2B7N5AJD2Z","pid":1242,"":"downstairs","":"downstairs","session_id":"d3836926-66a5-4536-b404-aa01474a508a"} |
| 194 | 2025-05-27T21:15:05.901Z | {"msg":"Max found gen is 26","v":0,"name":"crucible","level":30,"time":"2025-05-27T21:15:05.451317385Z","hostname":"w-01JW9SC4ZQ9YSQWP2B7N5AJD2Z","pid":1242,"":"downstairs","":"downstairs","session_id":"d3836926-66a5-4536-b404-aa01474a508a"} |
| 195 | 2025-05-27T21:15:05.901Z | {"msg":"Generation requested: 31 >= found:26","v":0,"name":"crucible","level":30,"time":"2025-05-27T21:15:05.451343636Z","hostname":"w-01JW9SC4ZQ9YSQWP2B7N5AJD2Z","pid":1242,"":"downstairs","":"downstairs","session_id":"d3836926-66a5-4536-b404-aa01474a508a"} |
| 196 | 2025-05-27T21:15:05.901Z | {"msg":"Next flush: 1497","v":0,"name":"crucible","level":30,"time":"2025-05-27T21:15:05.451374067Z","hostname":"w-01JW9SC4ZQ9YSQWP2B7N5AJD2Z","pid":1242,"":"downstairs","":"downstairs","session_id":"d3836926-66a5-4536-b404-aa01474a508a"} |
| 197 | 2025-05-27T21:15:05.901Z | {"msg":"All extents match","v":0,"name":"crucible","level":30,"time":"2025-05-27T21:15:05.451396467Z","hostname":"w-01JW9SC4ZQ9YSQWP2B7N5AJD2Z","pid":1242,"":"downstairs","":"downstairs","session_id":"d3836926-66a5-4536-b404-aa01474a508a"} |
| 198 | 2025-05-27T21:15:05.901Z | {"msg":"No downstairs reconciliation required","v":0,"name":"crucible","level":30,"time":"2025-05-27T21:15:05.451426298Z","hostname":"w-01JW9SC4ZQ9YSQWP2B7N5AJD2Z","pid":1242,"session_id":"d3836926-66a5-4536-b404-aa01474a508a"} |
| 199 | 2025-05-27T21:15:05.901Z | {"msg":"Transition from WaitQuorum to Active","v":0,"name":"crucible","level":30,"time":"2025-05-27T21:15:05.451446189Z","hostname":"w-01JW9SC4ZQ9YSQWP2B7N5AJD2Z","pid":1242,"client":"0","":"downstairs","session_id":"d3836926-66a5-4536-b404-aa01474a508a"} |
| 200 | 2025-05-27T21:15:05.901Z | {"msg":"Transition from WaitQuorum to Active","v":0,"name":"crucible","level":30,"time":"2025-05-27T21:15:05.45147414Z","hostname":"w-01JW9SC4ZQ9YSQWP2B7N5AJD2Z","pid":1242,"client":"1","":"downstairs","session_id":"d3836926-66a5-4536-b404-aa01474a508a"}Disk: sv:1 bs:4096 ts:204800 tb:50 max_io:50 or 204800 |
| 201 | 2025-05-27T21:15:05.901Z | |
| 202 | 2025-05-27T21:15:05.901Z | {"msg":"Transition from WaitQuorum to Active","v":0,"name":"crucible","level":30,"time":"2025-05-27T21:15:05.451500711Z","hostname":"w-01JW9SC4ZQ9YSQWP2B7N5AJD2Z","pid":1242,"client":"2","":"downstairs","session_id":"d3836926-66a5-4536-b404-aa01474a508a"} |
| 203 | 2025-05-27T21:15:05.901Z | {"msg":"Fill test |
| 204 | 2025-05-27T21:15:05.901Z | All required reconciliation work is completed","v":0,"name":"crucible","level":30,"time":"2025-05-27T21:15:05.451528202Z","hostname":"w-01JW9SC4ZQ9YSQWP2B7N5AJD2Z","pid":1242,"session_id":"d3836926-66a5-4536-b404-aa01474a508a"} |
| 205 | 2025-05-27T21:15:05.901Z | {"msg":"Set Downstairs and Upstairs active after reconciliation","v":0,"name":"crucible","level":30,"time":"2025-05-27T21:15:05.451548852Z","hostname":"w-01JW9SC4ZQ9YSQWP2B7N5AJD2Z","pid":1242,"session_id":"d3836926-66a5-4536-b404-aa01474a508a"} |
| 206 | 2025-05-27T21:15:05.901Z | {"msg":"26c195d1-2259-44b7-a88a-b49b70b46d59 is now active with session: d3836926-66a5-4536-b404-aa01474a508a","v":0,"name":"crucible","level":30,"time":"2025-05-27T21:15:05.451577743Z","hostname":"w-01JW9SC4ZQ9YSQWP2B7N5AJD2Z","pid":1242,"session_id":"d3836926-66a5-4536-b404-aa01474a508a"} |
| 207 | 2025-05-27T21:15:05.902Z | {"msg":"Set Active after no reconciliation","v":0,"name":"crucible","level":30,"time":"2025-05-27T21:15:05.451598124Z","hostname":"w-01JW9SC4ZQ9YSQWP2B7N5AJD2Z","pid":1242,"session_id":"d3836926-66a5-4536-b404-aa01474a508a"} |
| 208 | 2025-05-27T21:15:05.902Z | {"msg":"The guest has finished waiting for activation with:31","v":0,"name":"crucible","level":30,"time":"2025-05-27T21:15:05.451623945Z","hostname":"w-01JW9SC4ZQ9YSQWP2B7N5AJD2Z","pid":1242} |
| 209 | 2025-05-27T21:15:05.902Z | {"msg":"Activated sub_volume 26c195d1-2259-44b7-a88a-b49b70b46d59","v":0,"name":"crucible","level":30,"time":"2025-05-27T21:15:05.451642135Z","hostname":"w-01JW9SC4ZQ9YSQWP2B7N5AJD2Z","pid":1242} |
| 210 | 2025-05-27T21:15:05.905Z | Read and Verify all blocks (0..50 range:false) |
| 211 | 2025-05-27T21:15:05.910Z | Wrote out file "/var/tmp/test_up-build/verify_file" |
| 212 | 2025-05-27T21:15:05.910Z | CLIENT: Tests done. All submitted work has been ACK'd |
| 213 | 2025-05-27T21:15:05.913Z | ---------------------------------------------------------------- |
| 214 | 2025-05-27T21:15:05.913Z | Crucible gen:31 GIO:true work queues: Upstairs:0 downstairs:1 |
| 215 | 2025-05-27T21:15:05.913Z | States: Active Active Active |
| 216 | 2025-05-27T21:15:05.913Z | JOBID ACK TYPE BKS/EXT DS:0 DS:1 DS:2 REPLAY |
| 217 | 2025-05-27T21:15:05.913Z | 1002 Acked Read 50 Done Done Done false |
| 218 | 2025-05-27T21:15:05.913Z | STATES DS:0 DS:1 DS:2 TOTAL |
| 219 | 2025-05-27T21:15:05.913Z | Sent 0 0 0 0 |
| 220 | 2025-05-27T21:15:05.913Z | Done 1 1 1 3 |
| 221 | 2025-05-27T21:15:05.913Z | Skipped 0 0 0 0 |
| 222 | 2025-05-27T21:15:05.914Z | Error 0 0 0 0 |
| 223 | 2025-05-27T21:15:05.914Z | Last Flush: Some(JobId(1001)) Some(JobId(1001)) Some(JobId(1001)) |
| 224 | 2025-05-27T21:15:05.914Z | Downstairs last five completed: 1001 1000 |
| 225 | 2025-05-27T21:15:05.914Z | Upstairs last five completed: 1002 1001 1000 |
| 226 | 2025-05-27T21:15:05.914Z | CLIENT: Up:0 ds:1 act:3 |
| 227 | 2025-05-27T21:15:09.912Z | ---------------------------------------------------------------- |
| 228 | 2025-05-27T21:15:09.912Z | Crucible gen:31 GIO:true work queues: Upstairs:0 downstairs:0 |
| 229 | 2025-05-27T21:15:09.912Z | Downstairs last five completed: 1003 1002 1001 1000 |
| 230 | 2025-05-27T21:15:09.912Z | Upstairs last five completed: 1003 1002 1001 1000 |
| 231 | 2025-05-27T21:15:09.912Z | CLIENT: Up:0 ds:0 act:3 |
| 232 | 2025-05-27T21:15:09.912Z | CLIENT: All crucible jobs finished, exiting program |
| 233 | 2025-05-27T21:15:09.915Z | {"msg":"Guest handle has been dropped","v":0,"name":"crucible","level":40,"time":"2025-05-27T21:15:09.46462685Z","hostname":"w-01JW9SC4ZQ9YSQWP2B7N5AJD2Z","pid":1242} |
| 234 | 2025-05-27T21:15:09.921Z | Repair setup passed |
| 235 | 2025-05-27T21:15:09.925Z | Copy the region for /var/tmp/test_up-build/8830 |
| 236 | 2025-05-27T21:15:09.928Z | cp -r /var/tmp/test_up-build/8830 /var/tmp/test_up-build/previous |
| 237 | 2025-05-27T21:15:09.932Z | /var/tmp/bins/crutest fill -g 32 -q --dsc 127.0.0.1:9998 --verify-out /var/tmp/test_up-build/verify_file --verify-in /var/tmp/test_up-build/verify_file |
| 238 | 2025-05-27T21:15:09.986Z | {"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-05-27T21:15:09.539402465Z","hostname":"w-01JW9SC4ZQ9YSQWP2B7N5AJD2Z","pid":1248,"task":"crutest"} |
| 239 | 2025-05-27T21:15:09.990Z | {"msg":"dsc has 3 regions. This means 1 sub_volumes","v":0,"name":"crucible","level":30,"time":"2025-05-27T21:15:09.539913111Z","hostname":"w-01JW9SC4ZQ9YSQWP2B7N5AJD2Z","pid":1248,"task":"crutest"} |
| 240 | 2025-05-27T21:15:09.990Z | {"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-05-27T21:15:09.541621566Z","hostname":"w-01JW9SC4ZQ9YSQWP2B7N5AJD2Z","pid":1248,"task":"crutest"} |
| 241 | 2025-05-27T21:15:09.990Z | {"msg":"Upstairs starts","v":0,"name":"crucible","level":30,"time":"2025-05-27T21:15:09.541817492Z","hostname":"w-01JW9SC4ZQ9YSQWP2B7N5AJD2Z","pid":1248} |
| 242 | 2025-05-27T21:15:09.990Z | {"msg":"Crucible Version: BuildInfo {\n version: \"0.0.1\",\n git_sha: \"dd892d47062b1dcb23800b8bbb5d2946e1dd1cb7\",\n git_commit_timestamp: \"2025-05-27T20:18:55.000000000Z\",\n git_branch: \"alan/agent-needs-workers\",\n rustc_semver: \"1.86.0\",\n rustc_channel: \"stable\",\n rustc_host_triple: \"x86_64-unknown-illumos\",\n rustc_commit_sha: \"05f9846f893b09a1be1fc8560e33fc3c815cfecb\",\n cargo_triple: \"x86_64-unknown-illumos\",\n debug: true,\n opt_level: 0,\n}","v":0,"name":"crucible","level":30,"time":"2025-05-27T21:15:09.541862604Z","hostname":"w-01JW9SC4ZQ9YSQWP2B7N5AJD2Z","pid":1248} |
| 243 | 2025-05-27T21:15:09.990Z | {"msg":"Upstairs <-> Downstairs Message Version: 13","v":0,"name":"crucible","level":30,"time":"2025-05-27T21:15:09.541888085Z","hostname":"w-01JW9SC4ZQ9YSQWP2B7N5AJD2Z","pid":1248} |
| 244 | 2025-05-27T21:15:09.990Z | {"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: false, database_read_version: 1, database_write_version: 1 }","v":0,"name":"crucible","level":30,"time":"2025-05-27T21:15:09.541906085Z","hostname":"w-01JW9SC4ZQ9YSQWP2B7N5AJD2Z","pid":1248} |
| 245 | 2025-05-27T21:15:09.990Z | {"msg":"Crucible 0f071452-6c15-4edb-b0b3-a7f53aff5bec has session id: 39e62802-e600-4c10-8860-1445b53200fe","v":0,"name":"crucible","level":30,"time":"2025-05-27T21:15:09.542602148Z","hostname":"w-01JW9SC4ZQ9YSQWP2B7N5AJD2Z","pid":1248,"session_id":"39e62802-e600-4c10-8860-1445b53200fe"} |
| 246 | 2025-05-27T21:15:09.990Z | {"msg":"Upstairs opts: Upstairs UUID: 0f071452-6c15-4edb-b0b3-a7f53aff5bec, Targets: [127.0.0.1:8810, 127.0.0.1:8820, 127.0.0.1:8830], lossy: false, flush_timeout: None, key populated: false, cert_pem populated: false, key_pem populated: false, root_cert_pem populated: false, Control: None, read_only: false","v":0,"name":"crucible","level":30,"time":"2025-05-27T21:15:09.542655189Z","hostname":"w-01JW9SC4ZQ9YSQWP2B7N5AJD2Z","pid":1248,"session_id":"39e62802-e600-4c10-8860-1445b53200fe"} |
| 247 | 2025-05-27T21:15:09.990Z | {"msg":"Crucible stats registered with UUID: 0f071452-6c15-4edb-b0b3-a7f53aff5bec","v":0,"name":"crucible","level":30,"time":"2025-05-27T21:15:09.54267541Z","hostname":"w-01JW9SC4ZQ9YSQWP2B7N5AJD2Z","pid":1248,"session_id":"39e62802-e600-4c10-8860-1445b53200fe"} |
| 248 | 2025-05-27T21:15:09.990Z | {"msg":"could not find Downstairs address for Nexus","v":0,"name":"crucible","level":40,"time":"2025-05-27T21:15:09.542695781Z","hostname":"w-01JW9SC4ZQ9YSQWP2B7N5AJD2Z","pid":1248,"session_id":"39e62802-e600-4c10-8860-1445b53200fe"} |
| 249 | 2025-05-27T21:15:09.996Z | {"msg":"Downstairs in volume = 3","v":0,"name":"crucible","level":30,"time":"2025-05-27T21:15:09.543538988Z","hostname":"w-01JW9SC4ZQ9YSQWP2B7N5AJD2Z","pid":1248,"task":"crutest"} |
| 250 | 2025-05-27T21:15:09.996Z | {"msg":"The guest has requested activation with gen:32","v":0,"name":"crucible","level":30,"time":"2025-05-27T21:15:09.543575989Z","hostname":"w-01JW9SC4ZQ9YSQWP2B7N5AJD2Z","pid":1248} |
| 251 | 2025-05-27T21:15:09.996Z | {"msg":"0f071452-6c15-4edb-b0b3-a7f53aff5bec active request set","v":0,"name":"crucible","level":30,"time":"2025-05-27T21:15:09.543669712Z","hostname":"w-01JW9SC4ZQ9YSQWP2B7N5AJD2Z","pid":1248,"session_id":"39e62802-e600-4c10-8860-1445b53200fe"} |
| 252 | 2025-05-27T21:15:09.996Z | {"msg":"sending connect oneshot to client","v":0,"name":"crucible","level":30,"time":"2025-05-27T21:15:09.543714213Z","hostname":"w-01JW9SC4ZQ9YSQWP2B7N5AJD2Z","pid":1248,"client":"0","":"downstairs","session_id":"39e62802-e600-4c10-8860-1445b53200fe"} |
| 253 | 2025-05-27T21:15:09.996Z | {"msg":"client set_active_request while in Connecting { state: Start { auto_promote: true }, mode: New }; waiting...","v":0,"name":"crucible","level":30,"time":"2025-05-27T21:15:09.543766445Z","hostname":"w-01JW9SC4ZQ9YSQWP2B7N5AJD2Z","pid":1248,"client":"0","":"downstairs","session_id":"39e62802-e600-4c10-8860-1445b53200fe"} |
| 254 | 2025-05-27T21:15:09.996Z | {"msg":"sending connect oneshot to client","v":0,"name":"crucible","level":30,"time":"2025-05-27T21:15:09.543800796Z","hostname":"w-01JW9SC4ZQ9YSQWP2B7N5AJD2Z","pid":1248,"client":"1","":"downstairs","session_id":"39e62802-e600-4c10-8860-1445b53200fe"} |
| 255 | 2025-05-27T21:15:09.996Z | {"msg":"client set_active_request while in Connecting { state: Start { auto_promote: true }, mode: New }; waiting...","v":0,"name":"crucible","level":30,"time":"2025-05-27T21:15:09.543843067Z","hostname":"w-01JW9SC4ZQ9YSQWP2B7N5AJD2Z","pid":1248,"client":"1","":"downstairs","session_id":"39e62802-e600-4c10-8860-1445b53200fe"} |
| 256 | 2025-05-27T21:15:09.997Z | {"msg":"sending connect oneshot to client","v":0,"name":"crucible","level":30,"time":"2025-05-27T21:15:09.543874979Z","hostname":"w-01JW9SC4ZQ9YSQWP2B7N5AJD2Z","pid":1248,"client":"2","":"downstairs","session_id":"39e62802-e600-4c10-8860-1445b53200fe"} |
| 257 | 2025-05-27T21:15:09.997Z | {"msg":"client set_active_request while in Connecting { state: Start { auto_promote: true }, mode: New }; waiting...","v":0,"name":"crucible","level":30,"time":"2025-05-27T21:15:09.54391263Z","hostname":"w-01JW9SC4ZQ9YSQWP2B7N5AJD2Z","pid":1248,"client":"2","":"downstairs","session_id":"39e62802-e600-4c10-8860-1445b53200fe"} |
| 258 | 2025-05-27T21:15:09.997Z | {"msg":"connecting to 127.0.0.1:8830","v":0,"name":"crucible","level":30,"time":"2025-05-27T21:15:09.544129107Z","hostname":"w-01JW9SC4ZQ9YSQWP2B7N5AJD2Z","pid":1248,"":"io task","client":"2","":"downstairs","session_id":"39e62802-e600-4c10-8860-1445b53200fe"} |
| 259 | 2025-05-27T21:15:09.997Z | {"msg":"connecting to 127.0.0.1:8810","v":0,"name":"crucible","level":30,"time":"2025-05-27T21:15:09.544179978Z","hostname":"w-01JW9SC4ZQ9YSQWP2B7N5AJD2Z","pid":1248,"":"io task","client":"0","":"downstairs","session_id":"39e62802-e600-4c10-8860-1445b53200fe"} |
| 260 | 2025-05-27T21:15:09.997Z | {"msg":"connecting to 127.0.0.1:8820","v":0,"name":"crucible","level":30,"time":"2025-05-27T21:15:09.544207379Z","hostname":"w-01JW9SC4ZQ9YSQWP2B7N5AJD2Z","pid":1248,"":"io task","client":"1","":"downstairs","session_id":"39e62802-e600-4c10-8860-1445b53200fe"} |
| 261 | 2025-05-27T21:15:09.997Z | {"msg":"ds_connection connected from Ok(127.0.0.1:56892)","v":0,"name":"crucible","level":30,"time":"2025-05-27T21:15:09.54424722Z","hostname":"w-01JW9SC4ZQ9YSQWP2B7N5AJD2Z","pid":1248,"":"io task","client":"2","":"downstairs","session_id":"39e62802-e600-4c10-8860-1445b53200fe"} |
| 262 | 2025-05-27T21:15:09.997Z | {"msg":"ds_connection connected from Ok(127.0.0.1:39186)","v":0,"name":"crucible","level":30,"time":"2025-05-27T21:15:09.544276032Z","hostname":"w-01JW9SC4ZQ9YSQWP2B7N5AJD2Z","pid":1248,"":"io task","client":"1","":"downstairs","session_id":"39e62802-e600-4c10-8860-1445b53200fe"} |
| 263 | 2025-05-27T21:15:09.997Z | {"msg":"ds_connection connected from Ok(127.0.0.1:37869)","v":0,"name":"crucible","level":30,"time":"2025-05-27T21:15:09.544311693Z","hostname":"w-01JW9SC4ZQ9YSQWP2B7N5AJD2Z","pid":1248,"":"io task","client":"0","":"downstairs","session_id":"39e62802-e600-4c10-8860-1445b53200fe"} |
| 264 | 2025-05-27T21:15:09.997Z | {"msg":"version negotiation from state Connecting { state: WaitForPromote, mode: New }","v":0,"name":"crucible","level":30,"time":"2025-05-27T21:15:09.544670264Z","hostname":"w-01JW9SC4ZQ9YSQWP2B7N5AJD2Z","pid":1248,"client":"2","":"downstairs","session_id":"39e62802-e600-4c10-8860-1445b53200fe"} |
| 265 | 2025-05-27T21:15:09.997Z | {"msg":"version negotiation from state Connecting { state: WaitForPromote, mode: New }","v":0,"name":"crucible","level":30,"time":"2025-05-27T21:15:09.544709975Z","hostname":"w-01JW9SC4ZQ9YSQWP2B7N5AJD2Z","pid":1248,"client":"0","":"downstairs","session_id":"39e62802-e600-4c10-8860-1445b53200fe"} |
| 266 | 2025-05-27T21:15:09.997Z | {"msg":"version negotiation from state Connecting { state: WaitForPromote, mode: New }","v":0,"name":"crucible","level":30,"time":"2025-05-27T21:15:09.544734846Z","hostname":"w-01JW9SC4ZQ9YSQWP2B7N5AJD2Z","pid":1248,"client":"1","":"downstairs","session_id":"39e62802-e600-4c10-8860-1445b53200fe"} |
| 267 | 2025-05-27T21:15:09.997Z | {"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-05-27T21:15:09.545405348Z","hostname":"w-01JW9SC4ZQ9YSQWP2B7N5AJD2Z","pid":1248,"client":"1","":"downstairs","session_id":"39e62802-e600-4c10-8860-1445b53200fe"} |
| 268 | 2025-05-27T21:15:09.997Z | {"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-05-27T21:15:09.545441979Z","hostname":"w-01JW9SC4ZQ9YSQWP2B7N5AJD2Z","pid":1248,"client":"2","":"downstairs","session_id":"39e62802-e600-4c10-8860-1445b53200fe"} |
| 269 | 2025-05-27T21:15:09.997Z | {"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-05-27T21:15:09.54545739Z","hostname":"w-01JW9SC4ZQ9YSQWP2B7N5AJD2Z","pid":1248,"client":"0","":"downstairs","session_id":"39e62802-e600-4c10-8860-1445b53200fe"} |
| 270 | 2025-05-27T21:15:09.997Z | {"msg":"Waiting for more clients to be ready","v":0,"name":"crucible","level":30,"time":"2025-05-27T21:15:09.545854122Z","hostname":"w-01JW9SC4ZQ9YSQWP2B7N5AJD2Z","pid":1248,"session_id":"39e62802-e600-4c10-8860-1445b53200fe"} |
| 271 | 2025-05-27T21:15:09.997Z | {"msg":"Waiting for more clients to be ready","v":0,"name":"crucible","level":30,"time":"2025-05-27T21:15:09.545899064Z","hostname":"w-01JW9SC4ZQ9YSQWP2B7N5AJD2Z","pid":1248,"session_id":"39e62802-e600-4c10-8860-1445b53200fe"} |
| 272 | 2025-05-27T21:15:09.997Z | {"msg":"[0]R flush_numbers: [1497, 1497, 1497, 1497, 1497]","v":0,"name":"crucible","level":30,"time":"2025-05-27T21:15:09.545918644Z","hostname":"w-01JW9SC4ZQ9YSQWP2B7N5AJD2Z","pid":1248,"":"downstairs","":"downstairs","session_id":"39e62802-e600-4c10-8860-1445b53200fe"} |
| 273 | 2025-05-27T21:15:09.997Z | {"msg":"[0]R generation: [31, 31, 31, 31, 31]","v":0,"name":"crucible","level":30,"time":"2025-05-27T21:15:09.545942215Z","hostname":"w-01JW9SC4ZQ9YSQWP2B7N5AJD2Z","pid":1248,"":"downstairs","":"downstairs","session_id":"39e62802-e600-4c10-8860-1445b53200fe"} |
| 274 | 2025-05-27T21:15:09.997Z | {"msg":"[0]R dirty: [false, false, false, false, false]","v":0,"name":"crucible","level":30,"time":"2025-05-27T21:15:09.545955815Z","hostname":"w-01JW9SC4ZQ9YSQWP2B7N5AJD2Z","pid":1248,"":"downstairs","":"downstairs","session_id":"39e62802-e600-4c10-8860-1445b53200fe"} |
| 275 | 2025-05-27T21:15:09.997Z | {"msg":"[1]R flush_numbers: [1497, 1497, 1497, 1497, 1497]","v":0,"name":"crucible","level":30,"time":"2025-05-27T21:15:09.545976996Z","hostname":"w-01JW9SC4ZQ9YSQWP2B7N5AJD2Z","pid":1248,"":"downstairs","":"downstairs","session_id":"39e62802-e600-4c10-8860-1445b53200fe"} |
| 276 | 2025-05-27T21:15:09.997Z | {"msg":"[1]R generation: [31, 31, 31, 31, 31]","v":0,"name":"crucible","level":30,"time":"2025-05-27T21:15:09.545991347Z","hostname":"w-01JW9SC4ZQ9YSQWP2B7N5AJD2Z","pid":1248,"":"downstairs","":"downstairs","session_id":"39e62802-e600-4c10-8860-1445b53200fe"} |
| 277 | 2025-05-27T21:15:09.997Z | {"msg":"[1]R dirty: [false, false, false, false, false]","v":0,"name":"crucible","level":30,"time":"2025-05-27T21:15:09.546014887Z","hostname":"w-01JW9SC4ZQ9YSQWP2B7N5AJD2Z","pid":1248,"":"downstairs","":"downstairs","session_id":"39e62802-e600-4c10-8860-1445b53200fe"} |
| 278 | 2025-05-27T21:15:09.997Z | {"msg":"[2]R flush_numbers: [1497, 1497, 1497, 1497, 1497]","v":0,"name":"crucible","level":30,"time":"2025-05-27T21:15:09.546052049Z","hostname":"w-01JW9SC4ZQ9YSQWP2B7N5AJD2Z","pid":1248,"":"downstairs","":"downstairs","session_id":"39e62802-e600-4c10-8860-1445b53200fe"} |
| 279 | 2025-05-27T21:15:09.997Z | {"msg":"[2]R generation: [31, 31, 31, 31, 31]","v":0,"name":"crucible","level":30,"time":"2025-05-27T21:15:09.546071619Z","hostname":"w-01JW9SC4ZQ9YSQWP2B7N5AJD2Z","pid":1248,"":"downstairs","":"downstairs","session_id":"39e62802-e600-4c10-8860-1445b53200fe"} |
| 280 | 2025-05-27T21:15:09.997Z | {"msg":"[2]R dirty: [false, false, false, false, false]","v":0,"name":"crucible","level":30,"time":"2025-05-27T21:15:09.54609712Z","hostname":"w-01JW9SC4ZQ9YSQWP2B7N5AJD2Z","pid":1248,"":"downstairs","":"downstairs","session_id":"39e62802-e600-4c10-8860-1445b53200fe"} |
| 281 | 2025-05-27T21:15:09.997Z | {"msg":"Max found gen is 32","v":0,"name":"crucible","level":30,"time":"2025-05-27T21:15:09.546119221Z","hostname":"w-01JW9SC4ZQ9YSQWP2B7N5AJD2Z","pid":1248,"":"downstairs","":"downstairs","session_id":"39e62802-e600-4c10-8860-1445b53200fe"} |
| 282 | 2025-05-27T21:15:09.997Z | {"msg":"Generation requested: 32 >= found:32","v":0,"name":"crucible","level":30,"time":"2025-05-27T21:15:09.546153282Z","hostname":"w-01JW9SC4ZQ9YSQWP2B7N5AJD2Z","pid":1248,"":"downstairs","":"downstairs","session_id":"39e62802-e600-4c10-8860-1445b53200fe"} |
| 283 | 2025-05-27T21:15:09.997Z | Wait for a query_work_queue command to finish before sending IO |
| 284 | 2025-05-27T21:15:09.997Z | {"msg":"Next flush: 1498","v":0,"name":"crucible","level":30,"time":"2025-05-27T21:15:09.546192773Z","hostname":"w-01JW9SC4ZQ9YSQWP2B7N5AJD2Z","pid":1248,"":"downstairs","":"downstairs","session_id":"39e62802-e600-4c10-8860-1445b53200fe"} |
| 285 | 2025-05-27T21:15:09.997Z | {"msg":"All extents match","v":0,"name":"crucible","level":30,"time":"2025-05-27T21:15:09.546232084Z","hostname":"w-01JW9SC4ZQ9YSQWP2B7N5AJD2Z","pid":1248,"":"downstairs","":"downstairs","session_id":"39e62802-e600-4c10-8860-1445b53200fe"} |
| 286 | 2025-05-27T21:15:09.997Z | {"msg":"No downstairs reconciliation required","v":0,"name":"crucible","level":30,"time":"2025-05-27T21:15:09.546250135Z","hostname":"w-01JW9SC4ZQ9YSQWP2B7N5AJD2Z","pid":1248,"session_id":"39e62802-e600-4c10-8860-1445b53200fe"} |
| 287 | 2025-05-27T21:15:09.997Z | {"msg":"Transition from WaitQuorum to Active","v":0,"name":"crucible","level":30,"time":"2025-05-27T21:15:09.546269356Z","hostname":"w-01JW9SC4ZQ9YSQWP2B7N5AJD2Z","pid":1248,"client":"0","":"downstairs","session_id":"39e62802-e600-4c10-8860-1445b53200fe"} |
| 288 | 2025-05-27T21:15:09.997Z | {"msg":"Transition from WaitQuorum to Active","v":0,"name":"crucible","level":30,"time":"2025-05-27T21:15:09.546290956Z","hostname":"w-01JW9SC4ZQ9YSQWP2B7N5AJD2Z","pid":1248,"client":"1","":"downstairs","session_id":"39e62802-e600-4c10-8860-1445b53200fe"} |
| 289 | 2025-05-27T21:15:09.997Z | {"msg":"Transition from WaitQuorum to Active","v":0,"name":"crucible","level":30,"time":"2025-05-27T21:15:09.546325567Z","hostname":"w-01JW9SC4ZQ9YSQWP2B7N5AJD2Z","pid":1248,"client":"2","":"downstairs","session_id":"39e62802-e600-4c10-8860-1445b53200fe"} |
| 290 | 2025-05-27T21:15:09.997Z | {"msg":"All required reconciliation work is completed","v":0,"name":"crucible","level":30,"time":"2025-05-27T21:15:09.546354248Z","hostname":"w-01JW9SC4ZQ9YSQWP2B7N5AJD2Z","pid":1248,"session_id":"39e62802-e600-4c10-8860-1445b53200fe"} |
| 291 | 2025-05-27T21:15:09.997Z | {"msg":"Set Downstairs and Upstairs active after reconciliation","v":0,"name":"crucible","level":30,"time":"2025-05-27T21:15:09.546368269Z","hostname":"w-01JW9SC4ZQ9YSQWP2B7N5AJD2Z","pid":1248,"session_id":"39e62802-e600-4c10-8860-1445b53200fe"} |
| 292 | 2025-05-27T21:15:09.997Z | {"msg":"0f071452-6c15-4edb-b0b3-a7f53aff5bec is now active with session: 39e62802-e600-4c10-8860-1445b53200fe","v":0,"name":"crucible","level":30,"time":"2025-05-27T21:15:09.54640046Z","hostname":"w-01JW9SC4ZQ9YSQWP2B7N5AJD2Z","pid":1248,"session_id":"39e62802-e600-4c10-8860-1445b53200fe"} |
| 293 | 2025-05-27T21:15:09.997Z | {"msg":"Set Active after no reconciliation","v":0,"name":"crucible","level":30,"time":"2025-05-27T21:15:09.546431541Z","hostname":"w-01JW9SC4ZQ9YSQWP2B7N5AJD2Z","pid":1248,"session_id":"39e62802-e600-4c10-8860-1445b53200fe"} |
| 294 | 2025-05-27T21:15:09.997Z | {"msg":"The guest has finished waiting for activation with:32","v":0,"name":"crucible","level":30,"time":"2025-05-27T21:15:09.546458162Z","hostname":"w-01JW9SC4ZQ9YSQWP2B7N5AJD2Z","pid":1248} |
| 295 | 2025-05-27T21:15:09.997Z | {"msg":"Activated sub_volume 0f071452-6c15-4edb-b0b3-a7f53aff5bec","v":0,"name":"crucible","level":30,"time":"2025-05-27T21:15:09.546476042Z","hostname":"w-01JW9SC4ZQ9YSQWP2B7N5AJD2Z","pid":1248} |
| 296 | 2025-05-27T21:15:09.998Z | Disk: sv:1 bs:4096 ts:204800 tb:50 max_io:50 or 204800 |
| 297 | 2025-05-27T21:15:09.998Z | Loading write count information from file "/var/tmp/test_up-build/verify_file" |
| 298 | 2025-05-27T21:15:09.998Z | Fill test |
| 299 | 2025-05-27T21:15:10.001Z | Read and Verify all blocks (0..50 range:false) |
| 300 | 2025-05-27T21:15:10.005Z | Wrote out file "/var/tmp/test_up-build/verify_file" |
| 301 | 2025-05-27T21:15:10.005Z | CLIENT: Tests done. All submitted work has been ACK'd |
| 302 | 2025-05-27T21:15:10.005Z | ---------------------------------------------------------------- |
| 303 | 2025-05-27T21:15:10.005Z | Crucible gen:32 GIO:true work queues: Upstairs:0 downstairs:1 |
| 304 | 2025-05-27T21:15:10.005Z | States: Active Active Active |
| 305 | 2025-05-27T21:15:10.005Z | JOBID ACK TYPE BKS/EXT DS:0 DS:1 DS:2 REPLAY |
| 306 | 2025-05-27T21:15:10.005Z | 1002 Acked Read 50 Done Done Done false |
| 307 | 2025-05-27T21:15:10.005Z | STATES DS:0 DS:1 DS:2 TOTAL |
| 308 | 2025-05-27T21:15:10.005Z | Sent 0 0 0 0 |
| 309 | 2025-05-27T21:15:10.005Z | Done 1 1 1 3 |
| 310 | 2025-05-27T21:15:10.005Z | Skipped 0 0 0 0 |
| 311 | 2025-05-27T21:15:10.005Z | Error 0 0 0 0 |
| 312 | 2025-05-27T21:15:10.005Z | Last Flush: Some(JobId(1001)) Some(JobId(1001)) Some(JobId(1001)) |
| 313 | 2025-05-27T21:15:10.005Z | Downstairs last five completed: 1001 1000 |
| 314 | 2025-05-27T21:15:10.005Z | Upstairs last five completed: 1002 1001 1000 |
| 315 | 2025-05-27T21:15:10.005Z | CLIENT: Up:0 ds:1 act:3 |
| 316 | 2025-05-27T21:15:14.006Z | ---------------------------------------------------------------- |
| 317 | 2025-05-27T21:15:14.006Z | Crucible gen:32 GIO:true work queues: Upstairs:0 downstairs:0 |
| 318 | 2025-05-27T21:15:14.006Z | Downstairs last five completed: 1003 1002 1001 1000 |
| 319 | 2025-05-27T21:15:14.006Z | Upstairs last five completed: 1003 1002 1001 1000 |
| 320 | 2025-05-27T21:15:14.006Z | CLIENT: Up:0 ds:0 act:3 |
| 321 | 2025-05-27T21:15:14.006Z | CLIENT: All crucible jobs finished, exiting program |
| 322 | 2025-05-27T21:15:14.010Z | {"msg":"Guest handle has been dropped","v":0,"name":"crucible","level":40,"time":"2025-05-27T21:15:13.559412555Z","hostname":"w-01JW9SC4ZQ9YSQWP2B7N5AJD2Z","pid":1248} |
| 323 | 2025-05-27T21:15:14.013Z | Repair part 1 passed |
| 324 | 2025-05-27T21:15:14.013Z | |
| 325 | 2025-05-27T21:15:14.013Z | Kill the current downstairs |
| 326 | 2025-05-27T21:15:14.183Z | Downstairs 2 stopped |
| 327 | 2025-05-27T21:15:14.183Z | mv /var/tmp/test_up-build/8830 /var/tmp/test_up-build/new |
| 328 | 2025-05-27T21:15:14.187Z | Now put back the original so we have a mismatch |
| 329 | 2025-05-27T21:15:14.187Z | mv /var/tmp/test_up-build/previous /var/tmp/test_up-build/8830 |
| 330 | 2025-05-27T21:15:14.190Z | Restart downstairs with old directory |
| 331 | 2025-05-27T21:15:14.245Z | /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 |
| 332 | 2025-05-27T21:15:14.262Z | EXT BLOCKS GEN0 GEN1 GEN2 FL0 FL1 FL2 D0 D1 D2 DIFF |
| 333 | 2025-05-27T21:15:14.266Z | 0 000-009 32 32 31 1498 1498 1497 F F F <--- |
| 334 | 2025-05-27T21:15:14.266Z | 1 010-019 32 32 31 1498 1498 1497 F F F <--- |
| 335 | 2025-05-27T21:15:14.266Z | 2 020-029 32 32 31 1498 1498 1497 F F F <--- |
| 336 | 2025-05-27T21:15:14.266Z | 3 030-039 32 32 31 1498 1498 1497 F F F <--- |
| 337 | 2025-05-27T21:15:14.266Z | 4 040-049 32 32 31 1498 1498 1497 F F F <--- |
| 338 | 2025-05-27T21:15:14.266Z | Max gen: 32, Max flush: 1498 |
| 339 | 2025-05-27T21:15:14.480Z | Error: Difference in extent metadata found! |
| 340 | 2025-05-27T21:15:14.480Z | |
| 341 | 2025-05-27T21:15:14.480Z | Stack backtrace: |
| 342 | 2025-05-27T21:15:14.480Z | 0: anyhow::error::<impl anyhow::Error>::msg |
| 343 | 2025-05-27T21:15:14.480Z | at /home/build/.cargo/registry/src/index.crates.io-1949cf8c6b5b557f/anyhow-1.0.97/src/backtrace.rs:27:14 |
| 344 | 2025-05-27T21:15:14.480Z | 1: anyhow::__private::format_err |
| 345 | 2025-05-27T21:15:14.480Z | at /home/build/.cargo/registry/src/index.crates.io-1949cf8c6b5b557f/anyhow-1.0.97/src/lib.rs:692:13 |
| 346 | 2025-05-27T21:15:14.499Z | dump test found error as expected |
| 347 | 2025-05-27T21:15:14.499Z | |
| 348 | 2025-05-27T21:15:14.499Z | |
| 349 | 2025-05-27T21:15:14.505Z | /var/tmp/bins/crutest verify --range -g 33 -q --dsc 127.0.0.1:9998 --verify-out /var/tmp/test_up-build/verify_file --verify-in /var/tmp/test_up-build/verify_file |
| 350 | 2025-05-27T21:15:14.557Z | {"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-05-27T21:15:14.109866975Z","hostname":"w-01JW9SC4ZQ9YSQWP2B7N5AJD2Z","pid":1256,"task":"crutest"} |
| 351 | 2025-05-27T21:15:14.571Z | {"msg":"dsc has 3 regions. This means 1 sub_volumes","v":0,"name":"crucible","level":30,"time":"2025-05-27T21:15:14.110421493Z","hostname":"w-01JW9SC4ZQ9YSQWP2B7N5AJD2Z","pid":1256,"task":"crutest"} |
| 352 | 2025-05-27T21:15:14.571Z | {"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-05-27T21:15:14.112090687Z","hostname":"w-01JW9SC4ZQ9YSQWP2B7N5AJD2Z","pid":1256,"task":"crutest"} |
| 353 | 2025-05-27T21:15:14.571Z | {"msg":"Upstairs starts","v":0,"name":"crucible","level":30,"time":"2025-05-27T21:15:14.112307734Z","hostname":"w-01JW9SC4ZQ9YSQWP2B7N5AJD2Z","pid":1256} |
| 354 | 2025-05-27T21:15:14.571Z | {"msg":"Crucible Version: BuildInfo {\n version: \"0.0.1\",\n git_sha: \"dd892d47062b1dcb23800b8bbb5d2946e1dd1cb7\",\n git_commit_timestamp: \"2025-05-27T20:18:55.000000000Z\",\n git_branch: \"alan/agent-needs-workers\",\n rustc_semver: \"1.86.0\",\n rustc_channel: \"stable\",\n rustc_host_triple: \"x86_64-unknown-illumos\",\n rustc_commit_sha: \"05f9846f893b09a1be1fc8560e33fc3c815cfecb\",\n cargo_triple: \"x86_64-unknown-illumos\",\n debug: true,\n opt_level: 0,\n}","v":0,"name":"crucible","level":30,"time":"2025-05-27T21:15:14.112386496Z","hostname":"w-01JW9SC4ZQ9YSQWP2B7N5AJD2Z","pid":1256} |
| 355 | 2025-05-27T21:15:14.571Z | {"msg":"Upstairs <-> Downstairs Message Version: 13","v":0,"name":"crucible","level":30,"time":"2025-05-27T21:15:14.112425888Z","hostname":"w-01JW9SC4ZQ9YSQWP2B7N5AJD2Z","pid":1256} |
| 356 | 2025-05-27T21:15:14.571Z | {"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: false, database_read_version: 1, database_write_version: 1 }","v":0,"name":"crucible","level":30,"time":"2025-05-27T21:15:14.112451238Z","hostname":"w-01JW9SC4ZQ9YSQWP2B7N5AJD2Z","pid":1256} |
| 357 | 2025-05-27T21:15:14.571Z | {"msg":"Crucible af9477eb-51d6-42dc-840b-b237a825ab89 has session id: 274033b9-91b0-4d8e-8ffd-2a0e1e3871ec","v":0,"name":"crucible","level":30,"time":"2025-05-27T21:15:14.112974675Z","hostname":"w-01JW9SC4ZQ9YSQWP2B7N5AJD2Z","pid":1256,"session_id":"274033b9-91b0-4d8e-8ffd-2a0e1e3871ec"} |
| 358 | 2025-05-27T21:15:14.571Z | {"msg":"Upstairs opts: Upstairs UUID: af9477eb-51d6-42dc-840b-b237a825ab89, Targets: [127.0.0.1:8810, 127.0.0.1:8820, 127.0.0.1:8830], lossy: false, flush_timeout: None, key populated: false, cert_pem populated: false, key_pem populated: false, root_cert_pem populated: false, Control: None, read_only: false","v":0,"name":"crucible","level":30,"time":"2025-05-27T21:15:14.113049717Z","hostname":"w-01JW9SC4ZQ9YSQWP2B7N5AJD2Z","pid":1256,"session_id":"274033b9-91b0-4d8e-8ffd-2a0e1e3871ec"} |
| 359 | 2025-05-27T21:15:14.571Z | {"msg":"Crucible stats registered with UUID: af9477eb-51d6-42dc-840b-b237a825ab89","v":0,"name":"crucible","level":30,"time":"2025-05-27T21:15:14.113080669Z","hostname":"w-01JW9SC4ZQ9YSQWP2B7N5AJD2Z","pid":1256,"session_id":"274033b9-91b0-4d8e-8ffd-2a0e1e3871ec"} |
| 360 | 2025-05-27T21:15:14.572Z | {"msg":"could not find Downstairs address for Nexus","v":0,"name":"crucible","level":40,"time":"2025-05-27T21:15:14.113098439Z","hostname":"w-01JW9SC4ZQ9YSQWP2B7N5AJD2Z","pid":1256,"session_id":"274033b9-91b0-4d8e-8ffd-2a0e1e3871ec"} |
| 361 | 2025-05-27T21:15:14.575Z | {"msg":"Downstairs in volume = 3","v":0,"name":"crucible","level":30,"time":"2025-05-27T21:15:14.113954126Z","hostname":"w-01JW9SC4ZQ9YSQWP2B7N5AJD2Z","pid":1256,"task":"crutest"} |
| 362 | 2025-05-27T21:15:14.576Z | {"msg":"The guest has requested activation with gen:33","v":0,"name":"crucible","level":30,"time":"2025-05-27T21:15:14.114010368Z","hostname":"w-01JW9SC4ZQ9YSQWP2B7N5AJD2Z","pid":1256} |
| 363 | 2025-05-27T21:15:14.576Z | {"msg":"af9477eb-51d6-42dc-840b-b237a825ab89 active request set","v":0,"name":"crucible","level":30,"time":"2025-05-27T21:15:14.114145413Z","hostname":"w-01JW9SC4ZQ9YSQWP2B7N5AJD2Z","pid":1256,"session_id":"274033b9-91b0-4d8e-8ffd-2a0e1e3871ec"} |
| 364 | 2025-05-27T21:15:14.576Z | {"msg":"sending connect oneshot to client","v":0,"name":"crucible","level":30,"time":"2025-05-27T21:15:14.114185344Z","hostname":"w-01JW9SC4ZQ9YSQWP2B7N5AJD2Z","pid":1256,"client":"0","":"downstairs","session_id":"274033b9-91b0-4d8e-8ffd-2a0e1e3871ec"} |
| 365 | 2025-05-27T21:15:14.576Z | {"msg":"client set_active_request while in Connecting { state: Start { auto_promote: true }, mode: New }; waiting...","v":0,"name":"crucible","level":30,"time":"2025-05-27T21:15:14.114247086Z","hostname":"w-01JW9SC4ZQ9YSQWP2B7N5AJD2Z","pid":1256,"client":"0","":"downstairs","session_id":"274033b9-91b0-4d8e-8ffd-2a0e1e3871ec"} |
| 366 | 2025-05-27T21:15:14.576Z | {"msg":"sending connect oneshot to client","v":0,"name":"crucible","level":30,"time":"2025-05-27T21:15:14.114276117Z","hostname":"w-01JW9SC4ZQ9YSQWP2B7N5AJD2Z","pid":1256,"client":"1","":"downstairs","session_id":"274033b9-91b0-4d8e-8ffd-2a0e1e3871ec"} |
| 367 | 2025-05-27T21:15:14.576Z | {"msg":"client set_active_request while in Connecting { state: Start { auto_promote: true }, mode: New }; waiting...","v":0,"name":"crucible","level":30,"time":"2025-05-27T21:15:14.114315758Z","hostname":"w-01JW9SC4ZQ9YSQWP2B7N5AJD2Z","pid":1256,"client":"1","":"downstairs","session_id":"274033b9-91b0-4d8e-8ffd-2a0e1e3871ec"} |
| 368 | 2025-05-27T21:15:14.576Z | {"msg":"sending connect oneshot to client","v":0,"name":"crucible","level":30,"time":"2025-05-27T21:15:14.114340429Z","hostname":"w-01JW9SC4ZQ9YSQWP2B7N5AJD2Z","pid":1256,"client":"2","":"downstairs","session_id":"274033b9-91b0-4d8e-8ffd-2a0e1e3871ec"} |
| 369 | 2025-05-27T21:15:14.576Z | {"msg":"client set_active_request while in Connecting { state: Start { auto_promote: true }, mode: New }; waiting...","v":0,"name":"crucible","level":30,"time":"2025-05-27T21:15:14.11437495Z","hostname":"w-01JW9SC4ZQ9YSQWP2B7N5AJD2Z","pid":1256,"client":"2","":"downstairs","session_id":"274033b9-91b0-4d8e-8ffd-2a0e1e3871ec"} |
| 370 | 2025-05-27T21:15:14.576Z | {"msg":"connecting to 127.0.0.1:8830","v":0,"name":"crucible","level":30,"time":"2025-05-27T21:15:14.114405511Z","hostname":"w-01JW9SC4ZQ9YSQWP2B7N5AJD2Z","pid":1256,"":"io task","client":"2","":"downstairs","session_id":"274033b9-91b0-4d8e-8ffd-2a0e1e3871ec"} |
| 371 | 2025-05-27T21:15:14.576Z | {"msg":"connecting to 127.0.0.1:8810","v":0,"name":"crucible","level":30,"time":"2025-05-27T21:15:14.114429432Z","hostname":"w-01JW9SC4ZQ9YSQWP2B7N5AJD2Z","pid":1256,"":"io task","client":"0","":"downstairs","session_id":"274033b9-91b0-4d8e-8ffd-2a0e1e3871ec"} |
| 372 | 2025-05-27T21:15:14.576Z | {"msg":"connecting to 127.0.0.1:8820","v":0,"name":"crucible","level":30,"time":"2025-05-27T21:15:14.114467823Z","hostname":"w-01JW9SC4ZQ9YSQWP2B7N5AJD2Z","pid":1256,"":"io task","client":"1","":"downstairs","session_id":"274033b9-91b0-4d8e-8ffd-2a0e1e3871ec"} |
| 373 | 2025-05-27T21:15:14.576Z | {"msg":"ds_connection connected from Ok(127.0.0.1:56456)","v":0,"name":"crucible","level":30,"time":"2025-05-27T21:15:14.114516375Z","hostname":"w-01JW9SC4ZQ9YSQWP2B7N5AJD2Z","pid":1256,"":"io task","client":"0","":"downstairs","session_id":"274033b9-91b0-4d8e-8ffd-2a0e1e3871ec"} |
| 374 | 2025-05-27T21:15:14.576Z | {"msg":"ds_connection connected from Ok(127.0.0.1:34278)","v":0,"name":"crucible","level":30,"time":"2025-05-27T21:15:14.114553956Z","hostname":"w-01JW9SC4ZQ9YSQWP2B7N5AJD2Z","pid":1256,"":"io task","client":"1","":"downstairs","session_id":"274033b9-91b0-4d8e-8ffd-2a0e1e3871ec"} |
| 375 | 2025-05-27T21:15:14.576Z | {"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-05-27T21:15:14.114581787Z","hostname":"w-01JW9SC4ZQ9YSQWP2B7N5AJD2Z","pid":1256,"":"io task","client":"2","":"downstairs","session_id":"274033b9-91b0-4d8e-8ffd-2a0e1e3871ec"} |
| 376 | 2025-05-27T21:15:14.576Z | {"msg":"client task is sending Done(ConnectionFailed(Os { code: 146, kind: ConnectionRefused, message: \"Connection refused\" }))","v":0,"name":"crucible","level":40,"time":"2025-05-27T21:15:14.11469457Z","hostname":"w-01JW9SC4ZQ9YSQWP2B7N5AJD2Z","pid":1256,"":"io task","client":"2","":"downstairs","session_id":"274033b9-91b0-4d8e-8ffd-2a0e1e3871ec"} |
| 377 | 2025-05-27T21:15:14.576Z | {"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-05-27T21:15:14.114744382Z","hostname":"w-01JW9SC4ZQ9YSQWP2B7N5AJD2Z","pid":1256,"session_id":"274033b9-91b0-4d8e-8ffd-2a0e1e3871ec"} |
| 378 | 2025-05-27T21:15:14.576Z | {"msg":"client task is exiting","v":0,"name":"crucible","level":30,"time":"2025-05-27T21:15:14.114767693Z","hostname":"w-01JW9SC4ZQ9YSQWP2B7N5AJD2Z","pid":1256,"":"io task","client":"2","":"downstairs","session_id":"274033b9-91b0-4d8e-8ffd-2a0e1e3871ec"} |
| 379 | 2025-05-27T21:15:14.576Z | {"msg":"version negotiation from state Connecting { state: WaitForPromote, mode: New }","v":0,"name":"crucible","level":30,"time":"2025-05-27T21:15:14.115031371Z","hostname":"w-01JW9SC4ZQ9YSQWP2B7N5AJD2Z","pid":1256,"client":"0","":"downstairs","session_id":"274033b9-91b0-4d8e-8ffd-2a0e1e3871ec"} |
| 380 | 2025-05-27T21:15:14.576Z | {"msg":"version negotiation from state Connecting { state: WaitForPromote, mode: New }","v":0,"name":"crucible","level":30,"time":"2025-05-27T21:15:14.115084503Z","hostname":"w-01JW9SC4ZQ9YSQWP2B7N5AJD2Z","pid":1256,"client":"1","":"downstairs","session_id":"274033b9-91b0-4d8e-8ffd-2a0e1e3871ec"} |
| 381 | 2025-05-27T21:15:14.576Z | {"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-05-27T21:15:14.115693473Z","hostname":"w-01JW9SC4ZQ9YSQWP2B7N5AJD2Z","pid":1256,"client":"0","":"downstairs","session_id":"274033b9-91b0-4d8e-8ffd-2a0e1e3871ec"} |
| 382 | 2025-05-27T21:15:14.576Z | {"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-05-27T21:15:14.115763315Z","hostname":"w-01JW9SC4ZQ9YSQWP2B7N5AJD2Z","pid":1256,"client":"1","":"downstairs","session_id":"274033b9-91b0-4d8e-8ffd-2a0e1e3871ec"} |
| 383 | 2025-05-27T21:15:14.576Z | {"msg":"Waiting for more clients to be ready","v":0,"name":"crucible","level":30,"time":"2025-05-27T21:15:14.116065345Z","hostname":"w-01JW9SC4ZQ9YSQWP2B7N5AJD2Z","pid":1256,"session_id":"274033b9-91b0-4d8e-8ffd-2a0e1e3871ec"} |
| 384 | 2025-05-27T21:15:14.576Z | {"msg":"Waiting for more clients to be ready","v":0,"name":"crucible","level":30,"time":"2025-05-27T21:15:14.116145297Z","hostname":"w-01JW9SC4ZQ9YSQWP2B7N5AJD2Z","pid":1256,"session_id":"274033b9-91b0-4d8e-8ffd-2a0e1e3871ec"} |
| 385 | 2025-05-27T21:15:24.564Z | {"msg":"connecting to 127.0.0.1:8830","v":0,"name":"crucible","level":30,"time":"2025-05-27T21:15:24.116363471Z","hostname":"w-01JW9SC4ZQ9YSQWP2B7N5AJD2Z","pid":1256,"":"io task","client":"2","":"downstairs","session_id":"274033b9-91b0-4d8e-8ffd-2a0e1e3871ec"} |
| 386 | 2025-05-27T21:15:24.569Z | {"msg":"ds_connection connected from Ok(127.0.0.1:41162)","v":0,"name":"crucible","level":30,"time":"2025-05-27T21:15:24.116739954Z","hostname":"w-01JW9SC4ZQ9YSQWP2B7N5AJD2Z","pid":1256,"":"io task","client":"2","":"downstairs","session_id":"274033b9-91b0-4d8e-8ffd-2a0e1e3871ec"} |
| 387 | 2025-05-27T21:15:24.569Z | {"msg":"version negotiation from state Connecting { state: WaitForPromote, mode: New }","v":0,"name":"crucible","level":30,"time":"2025-05-27T21:15:24.117639483Z","hostname":"w-01JW9SC4ZQ9YSQWP2B7N5AJD2Z","pid":1256,"client":"2","":"downstairs","session_id":"274033b9-91b0-4d8e-8ffd-2a0e1e3871ec"} |
| 388 | 2025-05-27T21:15:24.569Z | {"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-05-27T21:15:24.11817519Z","hostname":"w-01JW9SC4ZQ9YSQWP2B7N5AJD2Z","pid":1256,"client":"2","":"downstairs","session_id":"274033b9-91b0-4d8e-8ffd-2a0e1e3871ec"} |
| 389 | 2025-05-27T21:15:24.569Z | {"msg":"[0]R flush_numbers: [1498, 1498, 1498, 1498, 1498]","v":0,"name":"crucible","level":30,"time":"2025-05-27T21:15:24.118582113Z","hostname":"w-01JW9SC4ZQ9YSQWP2B7N5AJD2Z","pid":1256,"":"downstairs","":"downstairs","session_id":"274033b9-91b0-4d8e-8ffd-2a0e1e3871ec"} |
| 390 | 2025-05-27T21:15:24.569Z | {"msg":"[0]R generation: [32, 32, 32, 32, 32]","v":0,"name":"crucible","level":30,"time":"2025-05-27T21:15:24.118616674Z","hostname":"w-01JW9SC4ZQ9YSQWP2B7N5AJD2Z","pid":1256,"":"downstairs","":"downstairs","session_id":"274033b9-91b0-4d8e-8ffd-2a0e1e3871ec"} |
| 391 | 2025-05-27T21:15:24.569Z | {"msg":"[0]R dirty: [false, false, false, false, false]","v":0,"name":"crucible","level":30,"time":"2025-05-27T21:15:24.118634415Z","hostname":"w-01JW9SC4ZQ9YSQWP2B7N5AJD2Z","pid":1256,"":"downstairs","":"downstairs","session_id":"274033b9-91b0-4d8e-8ffd-2a0e1e3871ec"} |
| 392 | 2025-05-27T21:15:24.569Z | {"msg":"[1]R flush_numbers: [1498, 1498, 1498, 1498, 1498]","v":0,"name":"crucible","level":30,"time":"2025-05-27T21:15:24.118659775Z","hostname":"w-01JW9SC4ZQ9YSQWP2B7N5AJD2Z","pid":1256,"":"downstairs","":"downstairs","session_id":"274033b9-91b0-4d8e-8ffd-2a0e1e3871ec"} |
| 393 | 2025-05-27T21:15:24.570Z | {"msg":"[1]R generation: [32, 32, 32, 32, 32]","v":0,"name":"crucible","level":30,"time":"2025-05-27T21:15:24.118683626Z","hostname":"w-01JW9SC4ZQ9YSQWP2B7N5AJD2Z","pid":1256,"":"downstairs","":"downstairs","session_id":"274033b9-91b0-4d8e-8ffd-2a0e1e3871ec"} |
| 394 | 2025-05-27T21:15:24.570Z | {"msg":"[1]R dirty: [false, false, false, false, false]","v":0,"name":"crucible","level":30,"time":"2025-05-27T21:15:24.118700127Z","hostname":"w-01JW9SC4ZQ9YSQWP2B7N5AJD2Z","pid":1256,"":"downstairs","":"downstairs","session_id":"274033b9-91b0-4d8e-8ffd-2a0e1e3871ec"} |
| 395 | 2025-05-27T21:15:24.570Z | {"msg":"[2]R flush_numbers: [1497, 1497, 1497, 1497, 1497]","v":0,"name":"crucible","level":30,"time":"2025-05-27T21:15:24.118724027Z","hostname":"w-01JW9SC4ZQ9YSQWP2B7N5AJD2Z","pid":1256,"":"downstairs","":"downstairs","session_id":"274033b9-91b0-4d8e-8ffd-2a0e1e3871ec"} |
| 396 | 2025-05-27T21:15:24.570Z | {"msg":"[2]R generation: [31, 31, 31, 31, 31]","v":0,"name":"crucible","level":30,"time":"2025-05-27T21:15:24.118740328Z","hostname":"w-01JW9SC4ZQ9YSQWP2B7N5AJD2Z","pid":1256,"":"downstairs","":"downstairs","session_id":"274033b9-91b0-4d8e-8ffd-2a0e1e3871ec"} |
| 397 | 2025-05-27T21:15:24.570Z | {"msg":"[2]R dirty: [false, false, false, false, false]","v":0,"name":"crucible","level":30,"time":"2025-05-27T21:15:24.118764389Z","hostname":"w-01JW9SC4ZQ9YSQWP2B7N5AJD2Z","pid":1256,"":"downstairs","":"downstairs","session_id":"274033b9-91b0-4d8e-8ffd-2a0e1e3871ec"} |
| 398 | 2025-05-27T21:15:24.570Z | {"msg":"Max found gen is 33","v":0,"name":"crucible","level":30,"time":"2025-05-27T21:15:24.118779929Z","hostname":"w-01JW9SC4ZQ9YSQWP2B7N5AJD2Z","pid":1256,"":"downstairs","":"downstairs","session_id":"274033b9-91b0-4d8e-8ffd-2a0e1e3871ec"} |
| 399 | 2025-05-27T21:15:24.570Z | {"msg":"Generation requested: 33 >= found:33","v":0,"name":"crucible","level":30,"time":"2025-05-27T21:15:24.11880399Z","hostname":"w-01JW9SC4ZQ9YSQWP2B7N5AJD2Z","pid":1256,"":"downstairs","":"downstairs","session_id":"274033b9-91b0-4d8e-8ffd-2a0e1e3871ec"} |
| 400 | 2025-05-27T21:15:24.570Z | {"msg":"Next flush: 1499","v":0,"name":"crucible","level":30,"time":"2025-05-27T21:15:24.11881927Z","hostname":"w-01JW9SC4ZQ9YSQWP2B7N5AJD2Z","pid":1256,"":"downstairs","":"downstairs","session_id":"274033b9-91b0-4d8e-8ffd-2a0e1e3871ec"} |
| 401 | 2025-05-27T21:15:24.570Z | {"msg":"extent 0 needs reconciliation: ExtentMetadata { gen: 32, flush: 1498, dirty: false } ExtentMetadata { gen: 32, flush: 1498, dirty: false } ExtentMetadata { gen: 31, flush: 1497, dirty: false }","v":0,"name":"crucible","level":30,"time":"2025-05-27T21:15:24.118845201Z","hostname":"w-01JW9SC4ZQ9YSQWP2B7N5AJD2Z","pid":1256,"":"mend","":"downstairs","":"downstairs","session_id":"274033b9-91b0-4d8e-8ffd-2a0e1e3871ec"} |
| 402 | 2025-05-27T21:15:24.570Z | {"msg":"extent:0 [ExtentMetadata { gen: 32, flush: 1498, dirty: false }, ExtentMetadata { gen: 32, flush: 1498, dirty: false }, ExtentMetadata { gen: 31, flush: 1497, dirty: false }] => 0","v":0,"name":"crucible","level":30,"time":"2025-05-27T21:15:24.118864952Z","hostname":"w-01JW9SC4ZQ9YSQWP2B7N5AJD2Z","pid":1256,"":"mend","":"downstairs","":"downstairs","session_id":"274033b9-91b0-4d8e-8ffd-2a0e1e3871ec"} |
| 403 | 2025-05-27T21:15:24.570Z | {"msg":"found dest for source 0 for extent at index 0 => [ClientId(2)]","v":0,"name":"crucible","level":30,"time":"2025-05-27T21:15:24.118881483Z","hostname":"w-01JW9SC4ZQ9YSQWP2B7N5AJD2Z","pid":1256,"":"mend","":"downstairs","":"downstairs","session_id":"274033b9-91b0-4d8e-8ffd-2a0e1e3871ec"} |
| 404 | 2025-05-27T21:15:24.570Z | {"msg":"extent 1 needs reconciliation: ExtentMetadata { gen: 32, flush: 1498, dirty: false } ExtentMetadata { gen: 32, flush: 1498, dirty: false } ExtentMetadata { gen: 31, flush: 1497, dirty: false }","v":0,"name":"crucible","level":30,"time":"2025-05-27T21:15:24.118946365Z","hostname":"w-01JW9SC4ZQ9YSQWP2B7N5AJD2Z","pid":1256,"":"mend","":"downstairs","":"downstairs","session_id":"274033b9-91b0-4d8e-8ffd-2a0e1e3871ec"} |
| 405 | 2025-05-27T21:15:24.570Z | {"msg":"extent:0 [ExtentMetadata { gen: 32, flush: 1498, dirty: false }, ExtentMetadata { gen: 32, flush: 1498, dirty: false }, ExtentMetadata { gen: 31, flush: 1497, dirty: false }] => 0","v":0,"name":"crucible","level":30,"time":"2025-05-27T21:15:24.118968785Z","hostname":"w-01JW9SC4ZQ9YSQWP2B7N5AJD2Z","pid":1256,"":"mend","":"downstairs","":"downstairs","session_id":"274033b9-91b0-4d8e-8ffd-2a0e1e3871ec"} |
| 406 | 2025-05-27T21:15:24.570Z | {"msg":"found dest for source 0 for extent at index 1 => [ClientId(2)]","v":0,"name":"crucible","level":30,"time":"2025-05-27T21:15:24.118985566Z","hostname":"w-01JW9SC4ZQ9YSQWP2B7N5AJD2Z","pid":1256,"":"mend","":"downstairs","":"downstairs","session_id":"274033b9-91b0-4d8e-8ffd-2a0e1e3871ec"} |
| 407 | 2025-05-27T21:15:24.570Z | {"msg":"extent 2 needs reconciliation: ExtentMetadata { gen: 32, flush: 1498, dirty: false } ExtentMetadata { gen: 32, flush: 1498, dirty: false } ExtentMetadata { gen: 31, flush: 1497, dirty: false }","v":0,"name":"crucible","level":30,"time":"2025-05-27T21:15:24.119003507Z","hostname":"w-01JW9SC4ZQ9YSQWP2B7N5AJD2Z","pid":1256,"":"mend","":"downstairs","":"downstairs","session_id":"274033b9-91b0-4d8e-8ffd-2a0e1e3871ec"} |
| 408 | 2025-05-27T21:15:24.570Z | {"msg":"extent:0 [ExtentMetadata { gen: 32, flush: 1498, dirty: false }, ExtentMetadata { gen: 32, flush: 1498, dirty: false }, ExtentMetadata { gen: 31, flush: 1497, dirty: false }] => 0","v":0,"name":"crucible","level":30,"time":"2025-05-27T21:15:24.119031577Z","hostname":"w-01JW9SC4ZQ9YSQWP2B7N5AJD2Z","pid":1256,"":"mend","":"downstairs","":"downstairs","session_id":"274033b9-91b0-4d8e-8ffd-2a0e1e3871ec"} |
| 409 | 2025-05-27T21:15:24.570Z | {"msg":"found dest for source 0 for extent at index 2 => [ClientId(2)]","v":0,"name":"crucible","level":30,"time":"2025-05-27T21:15:24.119050008Z","hostname":"w-01JW9SC4ZQ9YSQWP2B7N5AJD2Z","pid":1256,"":"mend","":"downstairs","":"downstairs","session_id":"274033b9-91b0-4d8e-8ffd-2a0e1e3871ec"} |
| 410 | 2025-05-27T21:15:24.570Z | {"msg":"extent 3 needs reconciliation: ExtentMetadata { gen: 32, flush: 1498, dirty: false } ExtentMetadata { gen: 32, flush: 1498, dirty: false } ExtentMetadata { gen: 31, flush: 1497, dirty: false }","v":0,"name":"crucible","level":30,"time":"2025-05-27T21:15:24.119076929Z","hostname":"w-01JW9SC4ZQ9YSQWP2B7N5AJD2Z","pid":1256,"":"mend","":"downstairs","":"downstairs","session_id":"274033b9-91b0-4d8e-8ffd-2a0e1e3871ec"} |
| 411 | 2025-05-27T21:15:24.570Z | {"msg":"extent:0 [ExtentMetadata { gen: 32, flush: 1498, dirty: false }, ExtentMetadata { gen: 32, flush: 1498, dirty: false }, ExtentMetadata { gen: 31, flush: 1497, dirty: false }] => 0","v":0,"name":"crucible","level":30,"time":"2025-05-27T21:15:24.11910391Z","hostname":"w-01JW9SC4ZQ9YSQWP2B7N5AJD2Z","pid":1256,"":"mend","":"downstairs","":"downstairs","session_id":"274033b9-91b0-4d8e-8ffd-2a0e1e3871ec"} |
| 412 | 2025-05-27T21:15:24.570Z | {"msg":"found dest for source 0 for extent at index 3 => [ClientId(2)]","v":0,"name":"crucible","level":30,"time":"2025-05-27T21:15:24.11912139Z","hostname":"w-01JW9SC4ZQ9YSQWP2B7N5AJD2Z","pid":1256,"":"mend","":"downstairs","":"downstairs","session_id":"274033b9-91b0-4d8e-8ffd-2a0e1e3871ec"} |
| 413 | 2025-05-27T21:15:24.570Z | {"msg":"extent 4 needs reconciliation: ExtentMetadata { gen: 32, flush: 1498, dirty: false } ExtentMetadata { gen: 32, flush: 1498, dirty: false } ExtentMetadata { gen: 31, flush: 1497, dirty: false }","v":0,"name":"crucible","level":30,"time":"2025-05-27T21:15:24.119147831Z","hostname":"w-01JW9SC4ZQ9YSQWP2B7N5AJD2Z","pid":1256,"":"mend","":"downstairs","":"downstairs","session_id":"274033b9-91b0-4d8e-8ffd-2a0e1e3871ec"} |
| 414 | 2025-05-27T21:15:24.570Z | {"msg":"extent:0 [ExtentMetadata { gen: 32, flush: 1498, dirty: false }, ExtentMetadata { gen: 32, flush: 1498, dirty: false }, ExtentMetadata { gen: 31, flush: 1497, dirty: false }] => 0","v":0,"name":"crucible","level":30,"time":"2025-05-27T21:15:24.119166832Z","hostname":"w-01JW9SC4ZQ9YSQWP2B7N5AJD2Z","pid":1256,"":"mend","":"downstairs","":"downstairs","session_id":"274033b9-91b0-4d8e-8ffd-2a0e1e3871ec"} |
| 415 | 2025-05-27T21:15:24.570Z | {"msg":"found dest for source 0 for extent at index 4 => [ClientId(2)]","v":0,"name":"crucible","level":30,"time":"2025-05-27T21:15:24.119191473Z","hostname":"w-01JW9SC4ZQ9YSQWP2B7N5AJD2Z","pid":1256,"":"mend","":"downstairs","":"downstairs","session_id":"274033b9-91b0-4d8e-8ffd-2a0e1e3871ec"} |
| 416 | 2025-05-27T21:15:24.570Z | {"msg":"Transition from Connecting { state: WaitQuorum, mode: New } to Reconcile","v":0,"name":"crucible","level":30,"time":"2025-05-27T21:15:24.119223094Z","hostname":"w-01JW9SC4ZQ9YSQWP2B7N5AJD2Z","pid":1256,"client":"0","":"downstairs","session_id":"274033b9-91b0-4d8e-8ffd-2a0e1e3871ec"} |
| 417 | 2025-05-27T21:15:24.570Z | {"msg":"Transition from Connecting { state: WaitQuorum, mode: New } to Reconcile","v":0,"name":"crucible","level":30,"time":"2025-05-27T21:15:24.119249694Z","hostname":"w-01JW9SC4ZQ9YSQWP2B7N5AJD2Z","pid":1256,"client":"1","":"downstairs","session_id":"274033b9-91b0-4d8e-8ffd-2a0e1e3871ec"} |
| 418 | 2025-05-27T21:15:24.570Z | {"msg":"Transition from Connecting { state: WaitQuorum, mode: New } to Reconcile","v":0,"name":"crucible","level":30,"time":"2025-05-27T21:15:24.119267025Z","hostname":"w-01JW9SC4ZQ9YSQWP2B7N5AJD2Z","pid":1256,"client":"2","":"downstairs","session_id":"274033b9-91b0-4d8e-8ffd-2a0e1e3871ec"} |
| 419 | 2025-05-27T21:15:24.570Z | {"msg":"Full repair list: {ExtentId(0): 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)] }, ExtentId(4): ExtentFix { source: ClientId(0), dest: [ClientId(2)] }, ExtentId(2): ExtentFix { source: ClientId(0), dest: [ClientId(2)] }}","v":0,"name":"crucible","level":30,"time":"2025-05-27T21:15:24.119295386Z","hostname":"w-01JW9SC4ZQ9YSQWP2B7N5AJD2Z","pid":1256,"":"downstairs","":"downstairs","session_id":"274033b9-91b0-4d8e-8ffd-2a0e1e3871ec"} |
| 420 | 2025-05-27T21:15:24.570Z | {"msg":"Task list: [ReconcileIO { id: ReconciliationId(0), op: ExtentFlush { repair_id: ReconciliationId(0), extent_id: ExtentId(0), client_id: ClientId(0), flush_number: 1499, gen_number: 33 }, state: ClientData([New, New, New]) }, ReconcileIO { id: ReconciliationId(1), op: ExtentClose { repair_id: ReconciliationId(1), extent_id: ExtentId(0) }, state: ClientData([New, New, New]) }, ReconcileIO { id: ReconciliationId(2), op: ExtentRepair { repair_id: ReconciliationId(2), extent_id: ExtentId(0), source_client_id: ClientId(0), source_repair_address: 0.0.0.0:12810, dest_clients: [ClientId(2)] }, state: ClientData([New, New, New]) }, ReconcileIO { id: ReconciliationId(3), op: ExtentReopen { repair_id: ReconciliationId(3), extent_id: ExtentId(0) }, state: ClientData([New, New, New]) }, ReconcileIO { id: ReconciliationId(4), op: ExtentFlush { repair_id: ReconciliationId(4), extent_id: ExtentId(3), client_id: ClientId(0), flush_number: 1499, 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(1), client_id: ClientId(0), flush_number: 1499, gen_number: 33 }, state: ClientData([New, New, New]) }, ReconcileIO { id: ReconciliationId(9), op: ExtentClose { repair_id: ReconciliationId(9), extent_id: ExtentId(1) }, state: ClientData([New, New, New]) }, ReconcileIO { id: ReconciliationId(10), op: ExtentRepair { repair_id: ReconciliationId(10), extent_id: ExtentId(1), source_client_id: ClientId(0), source_repair_address: 0.0.0.0:12810, dest_clients: [ClientId(2)] }, state: ClientData([New, New, New]) }, ReconcileIO { id: ReconciliationId(11), op: ExtentReopen { repair_id: ReconciliationId(11), extent_id: ExtentId(1) }, state: ClientData([New, New, New]) }, ReconcileIO { id: ReconciliationId(12), op: ExtentFlush { repair_id: ReconciliationId(12), extent_id: ExtentId(4), client_id: ClientId(0), flush_number: 1499, gen_number: 33 }, state: ClientData([New, New, New]) }, ReconcileIO { id: ReconciliationId(13), op: ExtentClose { repair_id: ReconciliationId(13), extent_id: ExtentId(4) }, state: ClientData([New, New, New]) }, ReconcileIO { id: ReconciliationId(14), op: ExtentRepair { repair_id: ReconciliationId(14), 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(15), op: ExtentReopen { repair_id: ReconciliationId(15), extent_id: ExtentId(4) }, 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: 1499, 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-05-27T21:15:24.119506352Z","hostname":"w-01JW9SC4ZQ9YSQWP2B7N5AJD2Z","pid":1256,"":"downstairs","":"downstairs","session_id":"274033b9-91b0-4d8e-8ffd-2a0e1e3871ec"} |
| 421 | 2025-05-27T21:15:24.570Z | {"msg":"starting reconciliation 59c4c14a-894b-4be2-94d6-f1cd869e7562: found 20 extents that need repair","v":0,"name":"crucible","level":30,"time":"2025-05-27T21:15:24.119541894Z","hostname":"w-01JW9SC4ZQ9YSQWP2B7N5AJD2Z","pid":1256,"":"downstairs","":"downstairs","session_id":"274033b9-91b0-4d8e-8ffd-2a0e1e3871ec"} |
| 422 | 2025-05-27T21:15:24.570Z | {"msg":"sending reconcile request ReconciliationId(2)","v":0,"name":"crucible","level":30,"time":"2025-05-27T21:15:24.120097912Z","hostname":"w-01JW9SC4ZQ9YSQWP2B7N5AJD2Z","pid":1256,"client":"2","":"downstairs","session_id":"274033b9-91b0-4d8e-8ffd-2a0e1e3871ec"} |
| 423 | 2025-05-27T21:15:24.578Z | {"msg":"sending reconcile request ReconciliationId(6)","v":0,"name":"crucible","level":30,"time":"2025-05-27T21:15:24.130963171Z","hostname":"w-01JW9SC4ZQ9YSQWP2B7N5AJD2Z","pid":1256,"client":"2","":"downstairs","session_id":"274033b9-91b0-4d8e-8ffd-2a0e1e3871ec"} |
| 424 | 2025-05-27T21:15:24.582Z | {"msg":"sending reconcile request ReconciliationId(10)","v":0,"name":"crucible","level":30,"time":"2025-05-27T21:15:24.134761253Z","hostname":"w-01JW9SC4ZQ9YSQWP2B7N5AJD2Z","pid":1256,"client":"2","":"downstairs","session_id":"274033b9-91b0-4d8e-8ffd-2a0e1e3871ec"} |
| 425 | 2025-05-27T21:15:24.585Z | {"msg":"sending reconcile request ReconciliationId(14)","v":0,"name":"crucible","level":30,"time":"2025-05-27T21:15:24.138461632Z","hostname":"w-01JW9SC4ZQ9YSQWP2B7N5AJD2Z","pid":1256,"client":"2","":"downstairs","session_id":"274033b9-91b0-4d8e-8ffd-2a0e1e3871ec"} |
| 426 | 2025-05-27T21:15:24.589Z | {"msg":"sending reconcile request ReconciliationId(18)","v":0,"name":"crucible","level":30,"time":"2025-05-27T21:15:24.142214793Z","hostname":"w-01JW9SC4ZQ9YSQWP2B7N5AJD2Z","pid":1256,"client":"2","":"downstairs","session_id":"274033b9-91b0-4d8e-8ffd-2a0e1e3871ec"} |
| 427 | 2025-05-27T21:15:24.592Z | {"msg":"done with reconciliation","v":0,"name":"crucible","level":30,"time":"2025-05-27T21:15:24.145457007Z","hostname":"w-01JW9SC4ZQ9YSQWP2B7N5AJD2Z","pid":1256,"":"downstairs","":"downstairs","session_id":"274033b9-91b0-4d8e-8ffd-2a0e1e3871ec"} |
| 428 | 2025-05-27T21:15:24.592Z | {"msg":"Transition from Reconcile to Active","v":0,"name":"crucible","level":30,"time":"2025-05-27T21:15:24.145493818Z","hostname":"w-01JW9SC4ZQ9YSQWP2B7N5AJD2Z","pid":1256,"client":"0","":"downstairs","session_id":"274033b9-91b0-4d8e-8ffd-2a0e1e3871ec"} |
| 429 | 2025-05-27T21:15:24.592Z | {"msg":"Transition from Reconcile to Active","v":0,"name":"crucible","level":30,"time":"2025-05-27T21:15:24.145509579Z","hostname":"w-01JW9SC4ZQ9YSQWP2B7N5AJD2Z","pid":1256,"client":"1","":"downstairs","session_id":"274033b9-91b0-4d8e-8ffd-2a0e1e3871ec"} |
| 430 | 2025-05-27T21:15:24.592Z | {"msg":"Transition from Reconcile to Active","v":0,"name":"crucible","level":30,"time":"2025-05-27T21:15:24.145523029Z","hostname":"w-01JW9SC4ZQ9YSQWP2B7N5AJD2Z","pid":1256,"client":"2","":"downstairs","session_id":"274033b9-91b0-4d8e-8ffd-2a0e1e3871ec"} |
| 431 | 2025-05-27T21:15:24.592Z | {"msg":"All required reconciliation work is completed","v":0,"name":"crucible","level":30,"time":"2025-05-27T21:15:24.14554418Z","hostname":"w-01JW9SC4ZQ9YSQWP2B7N5AJD2Z","pid":1256,"session_id":"274033b9-91b0-4d8e-8ffd-2a0e1e3871ec"} |
| 432 | 2025-05-27T21:15:24.592Z | {"msg":"Set Downstairs and Upstairs active after reconciliation","v":0,"name":"crucible","level":30,"time":"2025-05-27T21:15:24.1455567Z","hostname":"w-01JW9SC4ZQ9YSQWP2B7N5AJD2Z","pid":1256,"session_id":"274033b9-91b0-4d8e-8ffd-2a0e1e3871ec"} |
| 433 | 2025-05-27T21:15:24.592Z | {"msg":"af9477eb-51d6-42dc-840b-b237a825ab89 is now active with session: 274033b9-91b0-4d8e-8ffd-2a0e1e3871ec","v":0,"name":"crucible","level":30,"time":"2025-05-27T21:15:24.145569271Z","hostname":"w-01JW9SC4ZQ9YSQWP2B7N5AJD2Z","pid":1256,"session_id":"274033b9-91b0-4d8e-8ffd-2a0e1e3871ec"} |
| 434 | 2025-05-27T21:15:24.592Z | {"msg":"The guest has finished waiting for activation with:33","v":0,"name":"crucible","level":30,"time":"2025-05-27T21:15:24.145581521Z","hostname":"w-01JW9SC4ZQ9YSQWP2B7N5AJD2Z","pid":1256} |
| 435 | 2025-05-27T21:15:24.596Z | {"msg":"Activated sub_volume af9477eb-51d6-42dc-840b-b237a825ab89","v":0,"name":"crucible","level":30,"time":"2025-05-27T21:15:24.145647763Z","hostname":"w-01JW9SC4ZQ9YSQWP2B7N5AJD2Z","pid":1256} |
| 436 | 2025-05-27T21:15:24.596Z | Wait for a query_work_queue command to finish before sending IO |
| 437 | 2025-05-27T21:15:24.596Z | Disk: sv:1 bs:4096 ts:204800 tb:50 max_io:50 or 204800 |
| 438 | 2025-05-27T21:15:24.596Z | Loading write count information from file "/var/tmp/test_up-build/verify_file" |
| 439 | 2025-05-27T21:15:24.596Z | Read and Verify all blocks (0..50 range:true) |
| 440 | 2025-05-27T21:15:24.600Z | Wrote out file "/var/tmp/test_up-build/verify_file" |
| 441 | 2025-05-27T21:15:24.600Z | Verify test completed |
| 442 | 2025-05-27T21:15:24.603Z | Wrote out file "/var/tmp/test_up-build/verify_file" |
| 443 | 2025-05-27T21:15:24.603Z | CLIENT: Tests done. All submitted work has been ACK'd |
| 444 | 2025-05-27T21:15:24.603Z | ---------------------------------------------------------------- |
| 445 | 2025-05-27T21:15:24.603Z | Crucible gen:33 GIO:true work queues: Upstairs:0 downstairs:1 |
| 446 | 2025-05-27T21:15:24.603Z | States: Active Active Active |
| 447 | 2025-05-27T21:15:24.603Z | JOBID ACK TYPE BKS/EXT DS:0 DS:1 DS:2 REPLAY |
| 448 | 2025-05-27T21:15:24.603Z | 1000 Acked Read 50 Done Done Done false |
| 449 | 2025-05-27T21:15:24.603Z | STATES DS:0 DS:1 DS:2 TOTAL |
| 450 | 2025-05-27T21:15:24.603Z | Sent 0 0 0 0 |
| 451 | 2025-05-27T21:15:24.603Z | Done 1 1 1 3 |
| 452 | 2025-05-27T21:15:24.603Z | Skipped 0 0 0 0 |
| 453 | 2025-05-27T21:15:24.603Z | Error 0 0 0 0 |
| 454 | 2025-05-27T21:15:24.603Z | Last Flush: None None None |
| 455 | 2025-05-27T21:15:24.603Z | Downstairs last five completed: |
| 456 | 2025-05-27T21:15:24.603Z | Upstairs last five completed: 1000 |
| 457 | 2025-05-27T21:15:24.603Z | CLIENT: Up:0 ds:1 act:3 |
| 458 | 2025-05-27T21:15:28.603Z | ---------------------------------------------------------------- |
| 459 | 2025-05-27T21:15:28.603Z | Crucible gen:33 GIO:true work queues: Upstairs:0 downstairs:0 |
| 460 | 2025-05-27T21:15:28.603Z | Downstairs last five completed: 1001 1000 |
| 461 | 2025-05-27T21:15:28.603Z | Upstairs last five completed: 1001 1000 |
| 462 | 2025-05-27T21:15:28.603Z | CLIENT: Up:0 ds:0 act:3 |
| 463 | 2025-05-27T21:15:28.603Z | CLIENT: All crucible jobs finished, exiting program |
| 464 | 2025-05-27T21:15:28.606Z | {"msg":"Guest handle has been dropped","v":0,"name":"crucible","level":40,"time":"2025-05-27T21:15:28.155871198Z","hostname":"w-01JW9SC4ZQ9YSQWP2B7N5AJD2Z","pid":1256} |
| 465 | 2025-05-27T21:15:28.610Z | Repair part 2 passed |
| 466 | 2025-05-27T21:15:28.610Z | /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 |
| 467 | 2025-05-27T21:15:28.627Z | EXT BLOCKS GEN0 GEN1 GEN2 FL0 FL1 FL2 D0 D1 D2 DIFF |
| 468 | 2025-05-27T21:15:28.627Z | 0 000-009 32 32 32 1498 1498 1498 F F F |
| 469 | 2025-05-27T21:15:28.627Z | 1 010-019 32 32 32 1498 1498 1498 F F F |
| 470 | 2025-05-27T21:15:28.627Z | 2 020-029 32 32 32 1498 1498 1498 F F F |
| 471 | 2025-05-27T21:15:28.627Z | 3 030-039 32 32 32 1498 1498 1498 F F F |
| 472 | 2025-05-27T21:15:28.627Z | 4 040-049 32 32 32 1498 1498 1498 F F F |
| 473 | 2025-05-27T21:15:28.627Z | Max gen: 32, Max flush: 1498 |
| 474 | 2025-05-27T21:15:28.630Z | dump test passed |
| 475 | 2025-05-27T21:15:28.634Z | /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 |
| 476 | 2025-05-27T21:15:28.650Z | Extent 1 |
| 477 | 2025-05-27T21:15:28.653Z | GEN 32 32 32 |
| 478 | 2025-05-27T21:15:28.653Z | FLUSH_ID 1498 1498 1498 |
| 479 | 2025-05-27T21:15:28.653Z | DIRTY |
| 480 | 2025-05-27T21:15:28.653Z | |
| 481 | 2025-05-27T21:15:28.653Z | BLOCK D0 D1 D2 C0 C1 C2 DIFF |
| 482 | 2025-05-27T21:15:28.653Z | 010 A A A A A A |
| 483 | 2025-05-27T21:15:28.653Z | 011 A A A A A A |
| 484 | 2025-05-27T21:15:28.653Z | 012 A A A A A A |
| 485 | 2025-05-27T21:15:28.656Z | 013 A A A A A A |
| 486 | 2025-05-27T21:15:28.656Z | 014 A A A A A A |
| 487 | 2025-05-27T21:15:28.656Z | 015 A A A A A A |
| 488 | 2025-05-27T21:15:28.659Z | 016 A A A A A A |
| 489 | 2025-05-27T21:15:28.660Z | 017 A A A A A A |
| 490 | 2025-05-27T21:15:28.663Z | 018 A A A A A A |
| 491 | 2025-05-27T21:15:28.663Z | 019 A A A A A A |
| 492 | 2025-05-27T21:15:28.666Z | dump extent test passed |
| 493 | 2025-05-27T21:15:28.666Z | /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 |
| 494 | 2025-05-27T21:15:28.682Z | Extent 2 Block in extent 0 Actual block 20 |
| 495 | 2025-05-27T21:15:28.685Z | |
| 496 | 2025-05-27T21:15:28.685Z | DATA SHA256 VER |
| 497 | 2025-05-27T21:15:28.686Z | ------ ---------------------------------------------------------------- --- |
| 498 | 2025-05-27T21:15:28.686Z | 0 ad3d0e88276af7eb1f904413516e1a8c1f9c2fa8b17b86b2d842d08303e90aa2 A |
| 499 | 2025-05-27T21:15:28.686Z | 1 ad3d0e88276af7eb1f904413516e1a8c1f9c2fa8b17b86b2d842d08303e90aa2 A |
| 500 | 2025-05-27T21:15:28.686Z | 2 ad3d0e88276af7eb1f904413516e1a8c1f9c2fa8b17b86b2d842d08303e90aa2 A |
| 501 | 2025-05-27T21:15:28.686Z | |
| 502 | 2025-05-27T21:15:28.686Z | NONCES 0 1 2 DIFF |
| 503 | 2025-05-27T21:15:28.686Z | ------ ------------------------ ------------------------ ------------------------ ----- |
| 504 | 2025-05-27T21:15:28.686Z | |
| 505 | 2025-05-27T21:15:28.686Z | TAGS 0 1 2 DIFF |
| 506 | 2025-05-27T21:15:28.686Z | ------ -------------------------------- -------------------------------- -------------------------------- ----- |
| 507 | 2025-05-27T21:15:28.686Z | |
| 508 | 2025-05-27T21:15:28.686Z | HASHES 0 1 2 DIFF |
| 509 | 2025-05-27T21:15:28.686Z | ------ ---------------- ---------------- ---------------- ----- |
| 510 | 2025-05-27T21:15:28.686Z | 0 42916ab6fa364c70 42916ab6fa364c70 42916ab6fa364c70 |
| 511 | 2025-05-27T21:15:28.686Z | |
| 512 | 2025-05-27T21:15:28.689Z | dump block test passed |
| 513 | 2025-05-27T21:15:28.689Z | Initial upstairs tests have completed, stopping all downstairs |
| 514 | 2025-05-27T21:15:33.757Z | Creating 4 larger downstairs regions |
| 515 | 2025-05-27T21:15:33.963Z | Starting 4 downstairs |
| 516 | 2025-05-27T21:15:38.970Z | dsc restarted at PID: 1269 |
| 517 | 2025-05-27T21:15:39.201Z | Now do the replace-reconcile test |
| 518 | 2025-05-27T21:15:39.260Z | Using 8840 for the replacement port |
| 519 | 2025-05-27T21:18:49.569Z | Completed test: replace-reconcile |
| 520 | 2025-05-27T21:18:49.573Z | Now do the replace-before-active test |
| 521 | 2025-05-27T21:21:47.085Z | Completed test: replace-before-active |
| 522 | 2025-05-27T21:21:47.088Z | All tests have completed, stopping all downstairs |
| 523 | 2025-05-27T21:21:47.143Z | |
| 524 | 2025-05-27T21:21:47.143Z | All Tests have passed |
| 525 | 2025-05-27T21:21:47.147Z | 8:40 Test duration |
| 526 | 2025-05-27T21:21:47.147Z | |
| 527 | 2025-05-27T21:21:47.147Z | real 8:40.237591127 |
| 528 | 2025-05-27T21:21:47.147Z | user 1:51.894825606 |
| 529 | 2025-05-27T21:21:47.147Z | sys 13.394217915 |
| 530 | 2025-05-27T21:21:47.147Z | trap 0.198209873 |
| 531 | 2025-05-27T21:21:47.147Z | tflt 0.016985031 |
| 532 | 2025-05-27T21:21:47.147Z | dflt 0.013435055 |
| 533 | 2025-05-27T21:21:47.147Z | kflt 0.005434007 |
| 534 | 2025-05-27T21:21:47.147Z | lock 5:59:57.911230627 |
| 535 | 2025-05-27T21:21:47.147Z | slp 25:56.743084631 |
| 536 | 2025-05-27T21:21:47.147Z | lat 16.510632820 |
| 537 | 2025-05-27T21:21:47.147Z | stop 0.127733602 |
| 538 | 2025-05-27T21:21:47.147Z | + echo 'test-up-unencrypted ends' |
| 539 | 2025-05-27T21:21:47.147Z | test-up-unencrypted ends |
| 540 | 2025-05-27T21:21:52.150Z | process exited: duration 528776 ms, exit code 0 |
| 541 | 2025-05-27T21:21:52.150Z | exec warning: : stdio descriptors remain open after task exit; waiting 60 seconds for them to close |
| 542 | 2025-05-27T21:22:52.194Z | exec warning: : stdout descriptor may be held open by a background process; giving up! |
| 543 | 2025-05-27T21:22:52.194Z | exec warning: : stderr descriptor may be held open by a background process; giving up! |
| |
| 544 | 2025-05-27T21:22:52.207Z | found 14 output files |
| 545 | 2025-05-27T21:22:52.207Z | uploading: /tmp/test_up-build/dsc-out.txt (41803 bytes) |
| 546 | 2025-05-27T21:22:53.228Z | uploaded: /tmp/test_up-build/dsc-out.txt |
| 547 | 2025-05-27T21:22:53.234Z | uploading: /tmp/test_up-build/test_up_out.txt (16799214 bytes) |
| 548 | 2025-05-27T21:22:54.566Z | uploaded: /tmp/test_up-build/test_up_out.txt |
| 549 | 2025-05-27T21:22:54.571Z | uploading: /tmp/test_up-build/dsc/downstairs-8810.txt (2499 bytes) |
| 550 | 2025-05-27T21:22:55.579Z | uploaded: /tmp/test_up-build/dsc/downstairs-8810.txt |
| 551 | 2025-05-27T21:22:55.579Z | uploading: /tmp/test_up-build/dsc/downstairs-8820.txt (548237 bytes) |
| 552 | 2025-05-27T21:22:56.615Z | uploaded: /tmp/test_up-build/dsc/downstairs-8820.txt |
| 553 | 2025-05-27T21:22:56.618Z | uploading: /tmp/test_up-build/dsc/downstairs-8830.txt (981853 bytes) |
| 554 | 2025-05-27T21:22:57.662Z | uploaded: /tmp/test_up-build/dsc/downstairs-8830.txt |
| 555 | 2025-05-27T21:22:57.666Z | uploading: /tmp/test_up-build/dsc/downstairs-8840.txt (542990 bytes) |
| 556 | 2025-05-27T21:22:58.700Z | uploaded: /tmp/test_up-build/dsc/downstairs-8840.txt |
| 557 | 2025-05-27T21:22:58.703Z | uploading: /tmp/debug/df.txt (1270 bytes) |
| 558 | 2025-05-27T21:22:59.709Z | uploaded: /tmp/debug/df.txt |
| 559 | 2025-05-27T21:22:59.713Z | uploading: /tmp/debug/dtrace.txt (478913 bytes) |
| 560 | 2025-05-27T21:23:00.744Z | uploaded: /tmp/debug/dtrace.txt |
| 561 | 2025-05-27T21:23:00.747Z | uploading: /tmp/debug/iostat.txt (173467 bytes) |
| 562 | 2025-05-27T21:23:00.762Z | upload warning: file "/tmp/debug/iostat.txt" changed size mid upload: 173467 -> 175835 |
| 563 | 2025-05-27T21:23:01.771Z | uploaded: /tmp/debug/iostat.txt |
| 564 | 2025-05-27T21:23:01.774Z | uploading: /tmp/debug/mpstat.txt (424876 bytes) |
| 565 | 2025-05-27T21:23:01.800Z | upload warning: file "/tmp/debug/mpstat.txt" changed size mid upload: 424876 -> 431401 |
| 566 | 2025-05-27T21:23:02.809Z | uploaded: /tmp/debug/mpstat.txt |
| 567 | 2025-05-27T21:23:02.813Z | uploading: /tmp/debug/paging.txt (74368 bytes) |
| 568 | 2025-05-27T21:23:02.821Z | upload warning: file "/tmp/debug/paging.txt" changed size mid upload: 74368 -> 75636 |
| 569 | 2025-05-27T21:23:03.827Z | uploaded: /tmp/debug/paging.txt |
| 570 | 2025-05-27T21:23:03.830Z | uploading: /tmp/debug/prstat.txt (813551 bytes) |
| 571 | 2025-05-27T21:23:03.867Z | upload warning: file "/tmp/debug/prstat.txt" changed size mid upload: 813551 -> 827740 |
| 572 | 2025-05-27T21:23:04.874Z | uploaded: /tmp/debug/prstat.txt |
| 573 | 2025-05-27T21:23:04.878Z | uploading: /tmp/debug/psrinfo.txt (1528 bytes) |
| 574 | 2025-05-27T21:23:05.884Z | uploaded: /tmp/debug/psrinfo.txt |
| 575 | 2025-05-27T21:23:05.888Z | uploading: /tmp/debug/upstairs-info.txt (55440 bytes) |
| 576 | 2025-05-27T21:23:06.900Z | uploaded: /tmp/debug/upstairs-info.txt |