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 Make output file at "/tmp/dsc/downstairs-8810.txt" Starting downstairs at port 8820 [8810][0] initial start wait reports Starting Make output file at "/tmp/dsc/downstairs-8820.txt" [8820][1] initial start wait reports Starting Starting downstairs at port 8830 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(1504) [8810][0] initial start wait reports Running Downstairs /var/tmp/dsc/8830 port 8830 PID:Some(1505) [8830][2] initial start wait reports Running Mar 18 05:03:19.977 INFO listening, local_addr: 127.0.0.1:9998 Downstairs /var/tmp/dsc/8820 port 8820 PID:Some(1506) [8820][1] initial start wait reports Running All downstairs are running Control access at:127.0.0.1:9998 Mar 18 05:03:25.016 INFO accepted connection, remote_addr: 127.0.0.1:47833, local_addr: 127.0.0.1:9998 Main task has work to do, go find it got dsc DisableRestartAll disable restart on all: 3 Mar 18 05:03:25.016 INFO request completed, latency_us: 107, response_code: 204, uri: /disablerestart/all, method: POST, req_id:[8810] Disable keep_running [8830] Disable keep_running 0518fbaf-696e-44b5-ab03-182cb6daa4be, remote_addr: 127.0.0.1:47833, local_addr: 127.0.0.[8820] Disable keep_running 1:9998 Mar 18 05:04:57.658 INFO accepted connection, remote_addr: 127.0.0.1:33692, local_addr: 127.0.0.1:9998 Main task has work to do, go find it got dsc Shutdown Shutdown Shut it down Mar 18 05:04:57.659 INFO request completed, latency_us: 51, response_code: 204, uri: /shutdown, method: POST, req_id: e6efc749-516b-4f4d-93ff-9cb1685160e4, remote_addr: 127.0[8810] Disable keep_running [8810] Got stop action so:false kr:false .0.1:33692, local_addr: 127.0.[8830] Disable keep_running 0[8820] Disable keep_running .[8830] Got stop action so:false kr:false 1[8820] Got stop action so:false kr:false :9998 [8820] Exited with: ExitStatus(unix_wait_status(9)) [8820][1] reports Exit [8810] Exited with: ExitStatus(unix_wait_status(9)) [8810][0] reports Exit [8830] Exited with: ExitStatus(unix_wait_status(9)) [8830][2] reports Exit 9} {"msg":"Crucible Version: BuildInfo {\n version: \"0.0.1\",\n git_sha: \"045990dac130b2f233c4a41d8bf452c550cf571c\",\n git_commit_timestamp: \"2025-03-18T04:42:28.000000000Z\",\n git_branch: \"main\",\n rustc_semver: \"1.84.0\",\n rustc_channel: \"stable\",\n rustc_host_triple: \"x86_64-unknown-illumos\",\n rustc_commit_sha: \"9fc6b43126469e3858e2fe86cafb4f0fd5068869\",\n cargo_triple: \"x86_64-unknown-illumos\",\n debug: false,\n opt_level: 3,\n}","v":0,"name":"crucible","level":30,"time":"2025-03-18T05:03:25.069162054Z","hostname":"w-01JPKT256K7WEVA231RFZ585D8","pid":1509} {"msg":"Upstairs <-> Downstairs Message Version: 13","v":0,"name":"crucible","level":30,"time":"2025-03-18T05:03:25.069167233Z","hostname":"w-01JPKT256K7WEVA231RFZ585D8","pid":1509} {"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-03-18T05:03:25.069174022Z","hostname":"w-01JPKT256K7WEVA231RFZ585D8","pid":1509} {"msg":"Crucible 89989e17-69cf-4aa1-8ef5-b28d03adccf7 has session id: 7ddb4d72-2587-4a0a-98a5-3eca5533fcf4","v":0,"name":"crucible","level":30,"time":"2025-03-18T05:03:25.069600354Z","hostname":"w-01JPKT256K7WEVA231RFZ585D8","pid":1509,"session_id":"7ddb4d72-2587-4a0a-98a5-3eca5533fcf4"} {"msg":"Upstairs opts: Upstairs UUID: 89989e17-69cf-4aa1-8ef5-b28d03adccf7, 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-03-18T05:03:25.069655747Z","hostname":"w-01JPKT256K7WEVA231RFZ585D8","pid":1509,"session_id":"7ddb4d72-2587-4a0a-98a5-3eca5533fcf4"} {"msg":"Crucible stats registered with UUID: 89989e17-69cf-4aa1-8ef5-b28d03adccf7","v":0,"name":"crucible","level":30,"time":"2025-03-18T05:03:25.069665835Z","hostname":"w-01JPKT256K7WEVA231RFZ585D8","pid":1509,"session_id":"7ddb4d72-2587-4a0a-98a5-3eca5533fcf4"} {"msg":"could not find Downstairs address for Nexus","v":0,"name":"crucible","level":40,"time":"2025-03-18T05:03:25.069669765Z","hostname":"w-01JPKT256K7WEVA231RFZ585D8","pid":1509,"session_id":"7ddb4d72-2587-4a0a-98a5-3eca5533fcf4"} {"msg":"Downstairs in volume = 3","v":0,"name":"crucible","level":30,"time":"2025-03-18T05:03:25.069842261Z","hostname":"w-01JPKT256K7WEVA231RFZ585D8","pid":1509,"task":"crutest"} {"msg":"The guest has requested activation with gen:1","v":0,"name":"crucible","level":30,"time":"2025-03-18T05:03:25.069862488Z","hostname":"w-01JPKT256K7WEVA231RFZ585D8","pid":1509} {"msg":"89989e17-69cf-4aa1-8ef5-b28d03adccf7 active request set","v":0,"name":"crucible","level":30,"time":"2025-03-18T05:03:25.069898414Z","hostname":"w-01JPKT256K7WEVA231RFZ585D8","pid":1509,"session_id":"7ddb4d72-2587-4a0a-98a5-3eca5533fcf4"} {"msg":"sending connect oneshot to client","v":0,"name":"crucible","level":30,"time":"2025-03-18T05:03:25.069903243Z","hostname":"w-01JPKT256K7WEVA231RFZ585D8","pid":1509,"client":"0","":"downstairs","session_id":"7ddb4d72-2587-4a0a-98a5-3eca5533fcf4"} {"msg":"client set_active_request while in Connecting { state: Start { auto_promote: true }, mode: New }; waiting...","v":0,"name":"crucible","level":30,"time":"2025-03-18T05:03:25.069912781Z","hostname":"w-01JPKT256K7WEVA231RFZ585D8","pid":1509,"client":"0","":"downstairs","session_id":"7ddb4d72-2587-4a0a-98a5-3eca5533fcf4"} {"msg":"sending connect oneshot to client","v":0,"name":"crucible","level":30,"time":"2025-03-18T05:03:25.069917401Z","hostname":"w-01JPKT256K7WEVA231RFZ585D8","pid":1509,"client":"1","":"downstairs","session_id":"7ddb4d72-2587-4a0a-98a5-3eca5533fcf4"} {"msg":"client set_active_request while in Connecting { state: Start { auto_promote: true }, mode: New }; waiting...","v":0,"name":"crucible","level":30,"time":"2025-03-18T05:03:25.06992169Z","hostname":"w-01JPKT256K7WEVA231RFZ585D8","pid":1509,"client":"1","":"downstairs","session_id":"7ddb4d72-2587-4a0a-98a5-3eca5533fcf4"} {"msg":"sending connect oneshot to client","v":0,"name":"crucible","level":30,"time":"2025-03-18T05:03:25.069927619Z","hostname":"w-01JPKT256K7WEVA231RFZ585D8","pid":1509,"client":"2","":"downstairs","session_id":"7ddb4d72-2587-4a0a-98a5-3eca5533fcf4"} {"msg":"client set_active_request while in Connecting { state: Start { auto_promote: true }, mode: New }; waiting...","v":0,"name":"crucible","level":30,"time":"2025-03-18T05:03:25.069931879Z","hostname":"w-01JPKT256K7WEVA231RFZ585D8","pid":1509,"client":"2","":"downstairs","session_id":"7ddb4d72-2587-4a0a-98a5-3eca5533fcf4"} {"msg":"connecting to 127.0.0.1:8830","v":0,"name":"crucible","level":30,"time":"2025-03-18T05:03:25.069936898Z","hostname":"w-01JPKT256K7WEVA231RFZ585D8","pid":1509,"":"io task","client":"2","":"downstairs","session_id":"7ddb4d72-2587-4a0a-98a5-3eca5533fcf4"} {"msg":"connecting to 127.0.0.1:8810","v":0,"name":"crucible","level":30,"time":"2025-03-18T05:03:25.069988781Z","hostname":"w-01JPKT256K7WEVA231RFZ585D8","pid":1509,"":"io task","client":"0","":"downstairs","session_id":"7ddb4d72-2587-4a0a-98a5-3eca5533fcf4"} {"msg":"connecting to 127.0.0.1:8820","v":0,"name":"crucible","level":30,"time":"2025-03-18T05:03:25.070002569Z","hostname":"w-01JPKT256K7WEVA231RFZ585D8","pid":1509,"":"io task","client":"1","":"downstairs","session_id":"7ddb4d72-2587-4a0a-98a5-3eca5533fcf4"} {"msg":"ds_connection connected from Ok(127.0.0.1:49696)","v":0,"name":"crucible","level":30,"time":"2025-03-18T05:03:25.070058192Z","hostname":"w-01JPKT256K7WEVA231RFZ585D8","pid":1509,"":"io task","client":"2","":"downstairs","session_id":"7ddb4d72-2587-4a0a-98a5-3eca5533fcf4"} {"msg":"ds_connection connected from Ok(127.0.0.1:60404)","v":0,"name":"crucible","level":30,"time":"2025-03-18T05:03:25.070078619Z","hostname":"w-01JPKT256K7WEVA231RFZ585D8","pid":1509,"":"io task","client":"0","":"downstairs","session_id":"7ddb4d72-2587-4a0a-98a5-3eca5533fcf4"} {"msg":"ds_connection connected from Ok(127.0.0.1:47571)","v":0,"name":"crucible","level":30,"time":"2025-03-18T05:03:25.070086608Z","hostname":"w-01JPKT256K7WEVA231RFZ585D8","pid":1509,"":"io task","client":"1","":"downstairs","session_id":"7ddb4d72-2587-4a0a-98a5-3eca5533fcf4"} {"msg":"version negotiation from state Connecting { state: WaitForPromote, mode: New }","v":0,"name":"crucible","level":30,"time":"2025-03-18T05:03:25.070414743Z","hostname":"w-01JPKT256K7WEVA231RFZ585D8","pid":1509,"client":"0","":"downstairs","session_id":"7ddb4d72-2587-4a0a-98a5-3eca5533fcf4"} {"msg":"version negotiation from state Connecting { state: WaitForPromote, mode: New }","v":0,"name":"crucible","level":30,"time":"2025-03-18T05:03:25.070426862Z","hostname":"w-01JPKT256K7WEVA231RFZ585D8","pid":1509,"client":"2","":"downstairs","session_id":"7ddb4d72-2587-4a0a-98a5-3eca5533fcf4"} {"msg":"version negotiation from state Connecting { state: WaitForPromote, mode: New }","v":0,"name":"crucible","level":30,"time":"2025-03-18T05:03:25.070506201Z","hostname":"w-01JPKT256K7WEVA231RFZ585D8","pid":1509,"client":"1","":"downstairs","session_id":"7ddb4d72-2587-4a0a-98a5-3eca5533fcf4"} {"msg":"downstairs client at Some(127.0.0.1:8810) has region UUID 12345678-0000-0000-0000-000000008810","v":0,"name":"crucible","level":30,"time":"2025-03-18T05:03:25.070624445Z","hostname":"w-01JPKT256K7WEVA231RFZ585D8","pid":1509,"client":"0","":"downstairs","session_id":"7ddb4d72-2587-4a0a-98a5-3eca5533fcf4"} {"msg":"downstairs client at Some(127.0.0.1:8830) has region UUID 12345678-0000-0000-0000-000000008830","v":0,"name":"crucible","level":30,"time":"2025-03-18T05:03:25.070635113Z","hostname":"w-01JPKT256K7WEVA231RFZ585D8","pid":1509,"client":"2","":"downstairs","session_id":"7ddb4d72-2587-4a0a-98a5-3eca5533fcf4"} {"msg":"downstairs client at Some(127.0.0.1:8820) has region UUID 12345678-0000-0000-0000-000000008820","v":0,"name":"crucible","level":30,"time":"2025-03-18T05:03:25.070642882Z","hostname":"w-01JPKT256K7WEVA231RFZ585D8","pid":1509,"client":"1","":"downstairs","session_id":"7ddb4d72-2587-4a0a-98a5-3eca5533fcf4"} {"msg":"Waiting for more clients to be ready","v":0,"name":"crucible","level":30,"time":"2025-03-18T05:03:25.077080247Z","hostname":"w-01JPKT256K7WEVA231RFZ585D8","pid":1509,"session_id":"7ddb4d72-2587-4a0a-98a5-3eca5533fcf4"} {"msg":"Waiting for more clients to be ready","v":0,"name":"crucible","level":30,"time":"2025-03-18T05:03:25.078391659Z","hostname":"w-01JPKT256K7WEVA231RFZ585D8","pid":1509,"session_id":"7ddb4d72-2587-4a0a-98a5-3eca5533fcf4"} {"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-03-18T05:03:25.078777816Z","hostname":"w-01JPKT256K7WEVA231RFZ585D8","pid":1509,"":"downstairs","":"downstairs","session_id":"7ddb4d72-2587-4a0a-98a5-3eca5533fcf4"} {"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-03-18T05:03:25.078786055Z","hostname":"w-01JPKT256K7WEVA231RFZ585D8","pid":1509,"":"downstairs","":"downstairs","session_id":"7ddb4d72-2587-4a0a-98a5-3eca5533fcf4"} {"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-03-18T05:03:25.078790455Z","hostname":"w-01JPKT256K7WEVA231RFZ585D8","pid":1509,"":"downstairs","":"downstairs","session_id":"7ddb4d72-2587-4a0a-98a5-3eca5533fcf4"} {"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-03-18T05:03:25.078794584Z","hostname":"w-01JPKT256K7WEVA231RFZ585D8","pid":1509,"":"downstairs","":"downstairs","session_id":"7ddb4d72-2587-4a0a-98a5-3eca5533fcf4"} {"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-03-18T05:03:25.078798604Z","hostname":"w-01JPKT256K7WEVA231RFZ585D8","pid":1509,"":"downstairs","":"downstairs","session_id":"7ddb4d72-2587-4a0a-98a5-3eca5533fcf4"} {"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-03-18T05:03:25.078805913Z","hostname":"w-01JPKT256K7WEVA231RFZ585D8","pid":1509,"":"downstairs","":"downstairs","session_id":"7ddb4d72-2587-4a0a-98a5-3eca5533fcf4"} {"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-03-18T05:03:25.078810192Z","hostname":"w-01JPKT256K7WEVA231RFZ585D8","pid":1509,"":"downstairs","":"downstairs","session_id":"7ddb4d72-2587-4a0a-98a5-3eca5533fcf4"} {"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-03-18T05:03:25.078814262Z","hostname":"w-01JPKT256K7WEVA231RFZ585D8","pid":1509,"":"downstairs","":"downstairs","session_id":"7ddb4d72-2587-4a0a-98a5-3eca5533fcf4"} {"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-03-18T05:03:25.078818311Z","hostname":"w-01JPKT256K7WEVA231RFZ585D8","pid":1509,"":"downstairs","":"downstairs","session_id":"7ddb4d72-2587-4a0a-98a5-3eca5533fcf4"} {"msg":"Max found gen is 1","v":0,"name":"crucible","level":30,"time":"2025-03-18T05:03:25.078822441Z","hostname":"w-01JPKT256K7WEVA231RFZ585D8","pid":1509,"":"downstairs","":"downstairs","session_id":"7ddb4d72-2587-4a0a-98a5-3eca5533fcf4"} {"msg":"Generation requested: 1 >= found:1","v":0,"name":"crucible","level":30,"time":"2025-03-18T05:03:25.07882654Z","hostname":"w-01JPKT256K7WEVA231RFZ585D8","pid":1509,"":"downstairs","":"downstairs","session_id":"7ddb4d72-2587-4a0a-98a5-3eca5533fcf4"} {"msg":"Next flush: 1","v":0,"name":"crucible","level":30,"time":"2025-03-18T05:03:25.078830989Z","hostname":"w-01JPKT256K7WEVA231RFZ585D8","pid":1509,"":"downstairs","":"downstairs","session_id":"7ddb4d72-2587-4a0a-98a5-3eca5533fcf4"} {"msg":"All extents match","v":0,"name":"crucible","level":30,"time":"2025-03-18T05:03:25.078835229Z","hostname":"w-01JPKT256K7WEVA231RFZ585D8","pid":1509,"":"downstairs","":"downstairs","session_id":"7ddb4d72-2587-4a0a-98a5-3eca5533fcf4"} {"msg":"No downstairs reconciliation required","v":0,"name":"crucible","level":30,"time":"2025-03-18T05:03:25.078839518Z","hostname":"w-01JPKT256K7WEVA231RFZ585D8","pid":1509,"session_id":"7ddb4d72-2587-4a0a-98a5-3eca5533fcf4"} {"msg":"Transition from WaitQuorum to Active","v":0,"name":"crucible","level":30,"time":"2025-03-18T05:03:25.078843168Z","hostname":"w-01JPKT256K7WEVA231RFZ585D8","pid":1509,"client":"0","":"downstairs","session_id":"7ddb4d72-2587-4a0a-98a5-3eca5533fcf4"} {"msg":"Transition from WaitQuorum to Active","v":0,"name":"crucible","level":30,"time":"2025-03-18T05:03:25.078847497Z","hostname":"w-01JPKT256K7WEVA231RFZ585D8","pid":1509,"client":"1","":"downstairs","session_id":"7ddb4d72-2587-4a0a-98a5-3eca5533fcf4"} {"msg":"Transition from WaitQuorum to Active","v":0,"name":"crucible","level":30,"time":"2025-03-18T05:03:25.078851766Z","hostname":"w-01JPKT256K7WEVA231RFZ585D8","pid":1509,"client":"2","":"downstairs","session_id":"7ddb4d72-2587-4a0a-98a5-3eca5533fcf4"} {"msg":"All required reconciliation work is completed","v":0,"name":"crucible","level":30,"time":"2025-03-18T05:03:25.078856126Z","hostname":"w-01JPKT256K7WEVA231RFZ585D8","pid":1509,"session_id":"7ddb4d72-2587-4a0a-98a5-3eca5533fcf4"} {"msg":"Set Downstairs and Upstairs active after reconciliation","v":0,"name":"crucible","level":30,"time":"2025-03-18T05:03:25.078859765Z","hostname":"w-01JPKT256K7WEVA231RFZ585D8","pid":1509,"session_id":"7ddb4d72-2587-4a0a-98a5-3eca5533fcf4"} {"msg":"89989e17-69cf-4aa1-8ef5-b28d03adccf7 is now active with session: 7ddb4d72-2587-4a0a-98a5-3eca5533fcf4","v":0,"name":"crucible","level":30,"time":"2025-03-18T05:03:25.078863415Z","hostname":"w-01JPKT256K7WEVA231RFZ585D8","pid":1509,"session_id":"7ddb4d72-2587-4a0a-98a5-3eca5533fcf4"} {"msg":"Set Active after no reconciliation","v":0,"name":"crucible","level":30,"time":"2025-03-18T05:03:25.078868994Z","hostname":"w-01JPKT256K7WEVA231RFZ585D8","pid":1509,"session_id":"7ddb4d72-2587-4a0a-98a5-3eca5533fcf4"} {"msg":"The guest has finished waiting for activation with:1","v":0,"name":"crucible","level":30,"time":"2025-03-18T05:03:25.078872634Z","hostname":"w-01JPKT256K7WEVA231RFZ585D8","pid":1509} {"msg":"Activated sub_volume 89989e17-69cf-4aa1-8ef5-b28d03adccf7","v":0,"name":"crucible","level":30,"time":"2025-03-18T05:03:25.078933015Z","hostname":"w-01JPKT256K7WEVA231RFZ585D8","pid":1509} 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:14 States: Active Active Active JOBID ACK TYPE BKS/EXT DS:0 DS:1 DS:2 REPLAY 104768 Acked Write 256 Done Done Done false 104769 Acked Write 256 Done Done Done false 104770 Acked Write 256 Done Done Done false 104771 Acked Write 256 Done Done Done false 104772 Acked Write 256 Done Done Done false 104773 Acked Write 256 Done Done Done false 104774 Acked Write 256 Done Done Done false 104775 Acked Write 256 Done Done Done false 104776 Acked Write 256 Done Done Done false 104777 Acked Write 256 Done Done Done false 104778 Acked Write 256 Done Done Done false 104779 Acked Write 256 Done Done Done false 104780 Acked Write 256 Done Done Done false 104781 Acked Flush 0 Done Done Sent false STATES DS:0 DS:1 DS:2 TOTAL Sent 0 0 1 1 Done 14 14 13 41 Skipped 0 0 0 0 Error 0 0 0 0 Last Flush: Some(JobId(104781)) Some(JobId(104781)) None Downstairs last five completed: 104767 104766 104765 104764 104763 Upstairs last five completed: 104781 104767 104780 104779 104778 CLIENT: Up:0 ds:14 act:3 ---------------------------------------------------------------- Crucible gen:1 GIO:true work queues: Upstairs:0 downstairs:0 Downstairs last five completed: 104781 104780 104779 104778 104777 Upstairs last five completed: 104781 104767 104780 104779 104778 CLIENT: Up:0 ds:0 act:3 CLIENT: All crucible jobs finished, exiting program