Using existing output directory "/tmp/dsc" Update our region info with: Some(RegionExtentInfo { block_size: 4096, blocks_per_extent: 16384, extent_count: 1600 }) start ds: 8810 start ds: 8820 start ds: 8830 start access at:127.0.0.1:9998 Starting downstairs at port 8810 Starting downstairs at port 8820 Make output file at "/tmp/dsc/downstairs-8810.txt" Make output file at "/tmp/dsc/downstairs-8820.txt" [8810][0] initial start wait reports Starting Starting downstairs at port 8830 [8820][1] initial start wait reports Starting Make output file at "/tmp/dsc/downstairs-8830.txt" [8830][2] initial start wait reports Starting Downstairs /var/tmp/dsc/8810 port 8810 PID:Some(1506) [8810][0] initial start wait reports Running Downstairs /var/tmp/dsc/8830 port 8830 PID:Some(1507) [8830][2] initial start wait reports Running Downstairs /var/tmp/dsc/8820 port 8820 PID:Some(1508) May 27 21:17:16.633 [8820][1] initial start wait reports Running All downstairs are running INFO listening, local_addr: 127.0.0.1:9998 Control access at:127.0.0.1:9998 May 27 21:17:21.680 INFO accepted connection, remote_addr: 127.0.0.1:33583, local_addr: 127.0.0.1:9998 Main task has work to do, go find it got dsc DisableRestartAll May 27 21:17:21.681 INFO request completed, latency_us: 144, response_code: 204, uri: disable restart on all: 3 /disablerestart/all, method: POST, req_id: 30e543f1-791a-40f5-9178-2ebaf4177db5, remote_addr: 127.0.0.1:33583, local_addr: 127.0.0.1:9998 [8810] Disable keep_running [8830] Disable keep_running [8820] Disable keep_running May 27 21:18:49.484 INFO accepted connection, remote_addr: 127.0.0.1:47575, local_addr: 127.0.0.1:9998 Main task has work to do, go find it got dsc Shutdown Shutdown Shut it down May 27 21:18:49.484 INFO request completed, latency_us:[8810] Disable keep_running [8810] Got stop action so:false kr:false 75, response_code: 204, uri: /shutdown, method: POST, req_id: 1f2476de-074c-4473-9ec2-cc879deda52e, remote_addr: 127.0.0.1:47575, local_addr: 127.0.0.1:9998 [8820] Disable keep_running [8830] Disable keep_running [8830] Got stop action so:false kr:false [8820] Got stop action so:false kr:false [8810] Exited with: ExitStatus(unix_wait_status(9)) [8810][0] reports Exit [8820] Exited with: ExitStatus(unix_wait_status(9)) [8820][1] reports Exit [8830] Exited with: ExitStatus(unix_wait_status(9)) [8830][2] reports Exit :"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: false,\n opt_level: 3,\n}","v":0,"name":"crucible","level":30,"time":"2025-05-27T21:17:21.748656241Z","hostname":"bmat-EVT22200007-00006f71","pid":1511} {"msg":"Upstairs <-> Downstairs Message Version: 13","v":0,"name":"crucible","level":30,"time":"2025-05-27T21:17:21.748664076Z","hostname":"bmat-EVT22200007-00006f71","pid":1511} {"msg":"Using region definition RegionDefinition { block_size: 4096, extent_size: Block { value: 16384, shift: 12 }, extent_count: 1600, 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:17:21.748671672Z","hostname":"bmat-EVT22200007-00006f71","pid":1511} {"msg":"Crucible 9c99e1b0-6d96-4238-835d-837af3712f18 has session id: 336d6622-672b-409a-8633-aa2f0d7df6cf","v":0,"name":"crucible","level":30,"time":"2025-05-27T21:17:21.749398869Z","hostname":"bmat-EVT22200007-00006f71","pid":1511,"session_id":"336d6622-672b-409a-8633-aa2f0d7df6cf"} {"msg":"Upstairs opts: Upstairs UUID: 9c99e1b0-6d96-4238-835d-837af3712f18, 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:17:21.749431925Z","hostname":"bmat-EVT22200007-00006f71","pid":1511,"session_id":"336d6622-672b-409a-8633-aa2f0d7df6cf"} {"msg":"Crucible stats registered with UUID: 9c99e1b0-6d96-4238-835d-837af3712f18","v":0,"name":"crucible","level":30,"time":"2025-05-27T21:17:21.749445092Z","hostname":"bmat-EVT22200007-00006f71","pid":1511,"session_id":"336d6622-672b-409a-8633-aa2f0d7df6cf"} {"msg":"could not find Downstairs address for Nexus","v":0,"name":"crucible","level":40,"time":"2025-05-27T21:17:21.749450252Z","hostname":"bmat-EVT22200007-00006f71","pid":1511,"session_id":"336d6622-672b-409a-8633-aa2f0d7df6cf"} {"msg":"Downstairs in volume = 3","v":0,"name":"crucible","level":30,"time":"2025-05-27T21:17:21.749682607Z","hostname":"bmat-EVT22200007-00006f71","pid":1511,"task":"crutest"} {"msg":"The guest has requested activation with gen:1","v":0,"name":"crucible","level":30,"time":"2025-05-27T21:17:21.749917198Z","hostname":"bmat-EVT22200007-00006f71","pid":1511} {"msg":"9c99e1b0-6d96-4238-835d-837af3712f18 active request set","v":0,"name":"crucible","level":30,"time":"2025-05-27T21:17:21.749943069Z","hostname":"bmat-EVT22200007-00006f71","pid":1511,"session_id":"336d6622-672b-409a-8633-aa2f0d7df6cf"} {"msg":"sending connect oneshot to client","v":0,"name":"crucible","level":30,"time":"2025-05-27T21:17:21.749950073Z","hostname":"bmat-EVT22200007-00006f71","pid":1511,"client":"0","":"downstairs","session_id":"336d6622-672b-409a-8633-aa2f0d7df6cf"} {"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:17:21.750111828Z","hostname":"bmat-EVT22200007-00006f71","pid":1511,"client":"0","":"downstairs","session_id":"336d6622-672b-409a-8633-aa2f0d7df6cf"} {"msg":"sending connect oneshot to client","v":0,"name":"crucible","level":30,"time":"2025-05-27T21:17:21.750122008Z","hostname":"bmat-EVT22200007-00006f71","pid":1511,"client":"1","":"downstairs","session_id":"336d6622-672b-409a-8633-aa2f0d7df6cf"} {"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:17:21.75012809Z","hostname":"bmat-EVT22200007-00006f71","pid":1511,"client":"1","":"downstairs","session_id":"336d6622-672b-409a-8633-aa2f0d7df6cf"} {"msg":"sending connect oneshot to client","v":0,"name":"crucible","level":30,"time":"2025-05-27T21:17:21.750134503Z","hostname":"bmat-EVT22200007-00006f71","pid":1511,"client":"2","":"downstairs","session_id":"336d6622-672b-409a-8633-aa2f0d7df6cf"} {"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:17:21.750140194Z","hostname":"bmat-EVT22200007-00006f71","pid":1511,"client":"2","":"downstairs","session_id":"336d6622-672b-409a-8633-aa2f0d7df6cf"} {"msg":"connecting to 127.0.0.1:8830","v":0,"name":"crucible","level":30,"time":"2025-05-27T21:17:21.750146146Z","hostname":"bmat-EVT22200007-00006f71","pid":1511,"":"io task","client":"2","":"downstairs","session_id":"336d6622-672b-409a-8633-aa2f0d7df6cf"} {"msg":"connecting to 127.0.0.1:8810","v":0,"name":"crucible","level":30,"time":"2025-05-27T21:17:21.750152259Z","hostname":"bmat-EVT22200007-00006f71","pid":1511,"":"io task","client":"0","":"downstairs","session_id":"336d6622-672b-409a-8633-aa2f0d7df6cf"} {"msg":"connecting to 127.0.0.1:8820","v":0,"name":"crucible","level":30,"time":"2025-05-27T21:17:21.75015806Z","hostname":"bmat-EVT22200007-00006f71","pid":1511,"":"io task","client":"1","":"downstairs","session_id":"336d6622-672b-409a-8633-aa2f0d7df6cf"} {"msg":"ds_connection connected from Ok(127.0.0.1:45249)","v":0,"name":"crucible","level":30,"time":"2025-05-27T21:17:21.750164052Z","hostname":"bmat-EVT22200007-00006f71","pid":1511,"":"io task","client":"2","":"downstairs","session_id":"336d6622-672b-409a-8633-aa2f0d7df6cf"} {"msg":"ds_connection connected from Ok(127.0.0.1:56872)","v":0,"name":"crucible","level":30,"time":"2025-05-27T21:17:21.750176868Z","hostname":"bmat-EVT22200007-00006f71","pid":1511,"":"io task","client":"0","":"downstairs","session_id":"336d6622-672b-409a-8633-aa2f0d7df6cf"} {"msg":"ds_connection connected from Ok(127.0.0.1:43959)","v":0,"name":"crucible","level":30,"time":"2025-05-27T21:17:21.75018292Z","hostname":"bmat-EVT22200007-00006f71","pid":1511,"":"io task","client":"1","":"downstairs","session_id":"336d6622-672b-409a-8633-aa2f0d7df6cf"} {"msg":"version negotiation from state Connecting { state: WaitForPromote, mode: New }","v":0,"name":"crucible","level":30,"time":"2025-05-27T21:17:21.75052738Z","hostname":"bmat-EVT22200007-00006f71","pid":1511,"client":"2","":"downstairs","session_id":"336d6622-672b-409a-8633-aa2f0d7df6cf"} {"msg":"version negotiation from state Connecting { state: WaitForPromote, mode: New }","v":0,"name":"crucible","level":30,"time":"2025-05-27T21:17:21.750538152Z","hostname":"bmat-EVT22200007-00006f71","pid":1511,"client":"0","":"downstairs","session_id":"336d6622-672b-409a-8633-aa2f0d7df6cf"} {"msg":"version negotiation from state Connecting { state: WaitForPromote, mode: New }","v":0,"name":"crucible","level":30,"time":"2025-05-27T21:17:21.750585286Z","hostname":"bmat-EVT22200007-00006f71","pid":1511,"client":"1","":"downstairs","session_id":"336d6622-672b-409a-8633-aa2f0d7df6cf"} {"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:17:21.750794325Z","hostname":"bmat-EVT22200007-00006f71","pid":1511,"client":"2","":"downstairs","session_id":"336d6622-672b-409a-8633-aa2f0d7df6cf"} {"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:17:21.750802502Z","hostname":"bmat-EVT22200007-00006f71","pid":1511,"client":"0","":"downstairs","session_id":"336d6622-672b-409a-8633-aa2f0d7df6cf"} {"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:17:21.750815808Z","hostname":"bmat-EVT22200007-00006f71","pid":1511,"client":"1","":"downstairs","session_id":"336d6622-672b-409a-8633-aa2f0d7df6cf"} {"msg":"Waiting for more clients to be ready","v":0,"name":"crucible","level":30,"time":"2025-05-27T21:17:21.760043299Z","hostname":"bmat-EVT22200007-00006f71","pid":1511,"session_id":"336d6622-672b-409a-8633-aa2f0d7df6cf"} {"msg":"Waiting for more clients to be ready","v":0,"name":"crucible","level":30,"time":"2025-05-27T21:17:21.76040802Z","hostname":"bmat-EVT22200007-00006f71","pid":1511,"session_id":"336d6622-672b-409a-8633-aa2f0d7df6cf"} {"msg":"[0]R flush_numbers[0..12]: [0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0]","v":0,"name":"crucible","level":30,"time":"2025-05-27T21:17:21.760979605Z","hostname":"bmat-EVT22200007-00006f71","pid":1511,"":"downstairs","":"downstairs","session_id":"336d6622-672b-409a-8633-aa2f0d7df6cf"} {"msg":"[0]R generation[0..12]: [0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0]","v":0,"name":"crucible","level":30,"time":"2025-05-27T21:17:21.760988383Z","hostname":"bmat-EVT22200007-00006f71","pid":1511,"":"downstairs","":"downstairs","session_id":"336d6622-672b-409a-8633-aa2f0d7df6cf"} {"msg":"[0]R dirty[0..12]: [false, false, false, false, false, false, false, false, false, false, false, false]","v":0,"name":"crucible","level":30,"time":"2025-05-27T21:17:21.760994124Z","hostname":"bmat-EVT22200007-00006f71","pid":1511,"":"downstairs","":"downstairs","session_id":"336d6622-672b-409a-8633-aa2f0d7df6cf"} {"msg":"[1]R flush_numbers[0..12]: [0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0]","v":0,"name":"crucible","level":30,"time":"2025-05-27T21:17:21.760999856Z","hostname":"bmat-EVT22200007-00006f71","pid":1511,"":"downstairs","":"downstairs","session_id":"336d6622-672b-409a-8633-aa2f0d7df6cf"} {"msg":"[1]R generation[0..12]: [0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0]","v":0,"name":"crucible","level":30,"time":"2025-05-27T21:17:21.761005307Z","hostname":"bmat-EVT22200007-00006f71","pid":1511,"":"downstairs","":"downstairs","session_id":"336d6622-672b-409a-8633-aa2f0d7df6cf"} {"msg":"[1]R dirty[0..12]: [false, false, false, false, false, false, false, false, false, false, false, false]","v":0,"name":"crucible","level":30,"time":"2025-05-27T21:17:21.761015788Z","hostname":"bmat-EVT22200007-00006f71","pid":1511,"":"downstairs","":"downstairs","session_id":"336d6622-672b-409a-8633-aa2f0d7df6cf"} {"msg":"[2]R flush_numbers[0..12]: [0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0]","v":0,"name":"crucible","level":30,"time":"2025-05-27T21:17:21.76102212Z","hostname":"bmat-EVT22200007-00006f71","pid":1511,"":"downstairs","":"downstairs","session_id":"336d6622-672b-409a-8633-aa2f0d7df6cf"} {"msg":"[2]R generation[0..12]: [0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0]","v":0,"name":"crucible","level":30,"time":"2025-05-27T21:17:21.761027722Z","hostname":"bmat-EVT22200007-00006f71","pid":1511,"":"downstairs","":"downstairs","session_id":"336d6622-672b-409a-8633-aa2f0d7df6cf"} {"msg":"[2]R dirty[0..12]: [false, false, false, false, false, false, false, false, false, false, false, false]","v":0,"name":"crucible","level":30,"time":"2025-05-27T21:17:21.761034135Z","hostname":"bmat-EVT22200007-00006f71","pid":1511,"":"downstairs","":"downstairs","session_id":"336d6622-672b-409a-8633-aa2f0d7df6cf"} {"msg":"Max found gen is 1","v":0,"name":"crucible","level":30,"time":"2025-05-27T21:17:21.761039726Z","hostname":"bmat-EVT22200007-00006f71","pid":1511,"":"downstairs","":"downstairs","session_id":"336d6622-672b-409a-8633-aa2f0d7df6cf"} {"msg":"Generation requested: 1 >= found:1","v":0,"name":"crucible","level":30,"time":"2025-05-27T21:17:21.761044966Z","hostname":"bmat-EVT22200007-00006f71","pid":1511,"":"downstairs","":"downstairs","session_id":"336d6622-672b-409a-8633-aa2f0d7df6cf"} {"msg":"Next flush: 1","v":0,"name":"crucible","level":30,"time":"2025-05-27T21:17:21.761050317Z","hostname":"bmat-EVT22200007-00006f71","pid":1511,"":"downstairs","":"downstairs","session_id":"336d6622-672b-409a-8633-aa2f0d7df6cf"} {"msg":"All extents match","v":0,"name":"crucible","level":30,"time":"2025-05-27T21:17:21.761055547Z","hostname":"bmat-EVT22200007-00006f71","pid":1511,"":"downstairs","":"downstairs","session_id":"336d6622-672b-409a-8633-aa2f0d7df6cf"} {"msg":"No downstairs reconciliation required","v":0,"name":"crucible","level":30,"time":"2025-05-27T21:17:21.761060868Z","hostname":"bmat-EVT22200007-00006f71","pid":1511,"session_id":"336d6622-672b-409a-8633-aa2f0d7df6cf"} {"msg":"Transition from WaitQuorum to Active","v":0,"name":"crucible","level":30,"time":"2025-05-27T21:17:21.761065548Z","hostname":"bmat-EVT22200007-00006f71","pid":1511,"client":"0","":"downstairs","session_id":"336d6622-672b-409a-8633-aa2f0d7df6cf"} {"msg":"Transition from WaitQuorum to Active","v":0,"name":"crucible","level":30,"time":"2025-05-27T21:17:21.76107177Z","hostname":"bmat-EVT22200007-00006f71","pid":1511,"client":"1","":"downstairs","session_id":"336d6622-672b-409a-8633-aa2f0d7df6cf"} {"msg":"Transition from WaitQuorum to Active","v":0,"name":"crucible","level":30,"time":"2025-05-27T21:17:21.761078473Z","hostname":"bmat-EVT22200007-00006f71","pid":1511,"client":"2","":"downstairs","session_id":"336d6622-672b-409a-8633-aa2f0d7df6cf"} {"msg":"All required reconciliation work is completed","v":0,"name":"crucible","level":30,"time":"2025-05-27T21:17:21.761084045Z","hostname":"bmat-EVT22200007-00006f71","pid":1511,"session_id":"336d6622-672b-409a-8633-aa2f0d7df6cf"} {"msg":"Set Downstairs and Upstairs active after reconciliation","v":0,"name":"crucible","level":30,"time":"2025-05-27T21:17:21.761088604Z","hostname":"bmat-EVT22200007-00006f71","pid":1511,"session_id":"336d6622-672b-409a-8633-aa2f0d7df6cf"} {"msg":"9c99e1b0-6d96-4238-835d-837af3712f18 is now active with session: 336d6622-672b-409a-8633-aa2f0d7df6cf","v":0,"name":"crucible","level":30,"time":"2025-05-27T21:17:21.761093313Z","hostname":"bmat-EVT22200007-00006f71","pid":1511,"session_id":"336d6622-672b-409a-8633-aa2f0d7df6cf"} {"msg":"Set Active after no reconciliation","v":0,"name":"crucible","level":30,"time":"2025-05-27T21:17:21.761101119Z","hostname":"bmat-EVT22200007-00006f71","pid":1511,"session_id":"336d6622-672b-409a-8633-aa2f0d7df6cf"} {"msg":"The guest has finished waiting for activation with:1","v":0,"name":"crucible","level":30,"time":"2025-05-27T21:17:21.761105808Z","hostname":"bmat-EVT22200007-00006f71","pid":1511} {"msg":"Activated sub_volume 9c99e1b0-6d96-4238-835d-837af3712f18","v":0,"name":"crucible","level":30,"time":"2025-05-27T21:17:21.76123157Z","hostname":"bmat-EVT22200007-00006f71","pid":1511} Wait for a query_work_queue command to finish before sending IO Disk: sv:1 bs:4096 ts:107374182400 tb:26214400 max_io:256 or 1048576 Fill test CLIENT: Tests done. All submitted work has been ACK'd ---------------------------------------------------------------- Crucible gen:1 GIO:true work queues: Upstairs:0 downstairs:45 States: Active Active Active JOBID ACK TYPE BKS/EXT DS:0 DS:1 DS:2 REPLAY 104459 Acked Write 256 Done Done Done false 104460 Acked Write 256 Done Done Done false 104461 Acked Write 256 Done Done Done false 104462 Acked Write 256 Done Done Done false 104463 Acked Write 256 Done Done Done false 104464 Acked Write 256 Done Done Done false 104465 Acked Write 256 Done Done Done false 104466 Acked Write 256 Done Done Done false 104467 Acked Write 256 Done Done Done false 104468 Acked Write 256 Done Done Done false 104469 Acked Write 256 Done Done Done false 104470 Acked Write 256 Done Done Done false 104471 Acked Write 256 Done Done Done false 104472 Acked Write 256 Done Done Done false 104473 Acked Write 256 Done Done Done false 104474 Acked Write 256 Done Done Done false 104475 Acked Write 256 Done Done Done false 104476 Acked Write 256 Done Done Done false 104477 Acked Write 256 Done Done Done false 104478 Acked Write 256 Done Done Done false 104479 Acked Write 256 Done Done Done false 104480 Acked Write 256 Done Done Done false 104481 Acked Write 256 Done Done Done false 104482 Acked Write 256 Done Done Done false 104483 Acked Write 256 Done Done Done false 104484 Acked Write 256 Done Done Done false 104485 Acked Write 256 Done Done Done false 104486 Acked Write 256 Done Done Done false 104487 Acked Write 256 Done Done Done false 104488 Acked Write 256 Done Done Done false 104489 Acked Write 256 Done Done Done false 104490 Acked Write 256 Done Done Done false 104491 Acked Write 256 Done Done Done false 104492 Acked Write 256 Done Done Done false 104493 Acked Write 256 Done Done Done false 104494 Acked Write 256 Done Done Done false 104495 Acked Write 256 Done Done Done false 104496 Acked Write 256 Done Done Done false 104497 Acked Write 256 Done Done Done false 104498 Acked Write 256 Done Done Done false 104499 Acked Write 256 Done Done Done false 104500 Acked Write 256 Done Done Done false 104501 Acked Write 256 Done Done Done false 104502 Acked Write 256 Done Done Done false 104503 Acked Flush 0 Sent Done Done false STATES DS:0 DS:1 DS:2 TOTAL Sent 1 0 0 1 Done 44 45 45 134 Skipped 0 0 0 0 Error 0 0 0 0 Last Flush: None Some(JobId(104503)) Some(JobId(104503)) Downstairs last five completed: 104458 104457 104456 104455 104454 Upstairs last five completed: 104503 104458 104502 104501 104500 CLIENT: Up:0 ds:45 act:3 ---------------------------------------------------------------- Crucible gen:1 GIO:true work queues: Upstairs:0 downstairs:0 Downstairs last five completed: 104503 104502 104501 104500 104499 Upstairs last five completed: 104503 104458 104502 104501 104500 CLIENT: Up:0 ds:0 act:3 CLIENT: All crucible jobs finished, exiting program