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-8820.txt" Make output file at "/tmp/dsc/downstairs-8810.txt" Starting downstairs at port 8830 [8810][0] initial start wait reports Starting Make output file at "/tmp/dsc/downstairs-8830.txt" [8820][1] initial start wait reports Starting [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) [8820][1] initial start wait reports Running All downstairs are running Mar 18 05:03:25.708 INFO listening, local_addr: 127.0.0.1:9998 Control access at:127.0.0.1:9998 Mar 18 05:03:30.748 INFO accepted connection, remote_addr: 127.0.0.1:50641, 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:30.748 INFO request completed, latency_us: 106, response_code: 204, uri: /disablerestart/all, method: POST, req_id: ee2bf531-2ad8-420e-b936-4eb9ec5305df, remote_addr: 127.0.0.1:50641, local_addr: 127.0.0.1:9998 [8820] Disable keep_running [8830] Disable keep_running [8810] Disable keep_running Mar 18 05:05:04.994 INFO accepted connection, remote_addr: 127.0.0.1:43260, 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:05:04.994 INFO request completed, latency_us: 53, [8810] Disable keep_running response_code[8810] Got stop action so:false kr:false : 204, uri[8830] Disable keep_running :[8820] Disable keep_running /shutdown, method: POST, req_id: 0a38d33a-c62b-418e-9688-85dbc6718389, remote_addr: 127.0.0.1:43260, local_addr: 127.0.0.1:9998 [8830] Got stop action so:false kr:false [8820] Got stop action so:false kr:false [8810] Exited with: ExitStatus(unix_wait_status(9)) [8820] Exited with: ExitStatus(unix_wait_status(9)) [8810][0] reports Exit [8820][1] reports Exit [8830] Exited with: ExitStatus(unix_wait_status(9)) [8830][2] reports Exit 1} {"msg":"Crucible Version: BuildInfo {\n version: \"0.0.1\",\n git_sha: \"7ce02df48de2b1dbc251235166766a7d2d332248\",\n git_commit_timestamp: \"2025-03-18T04:42:36.000000000Z\",\n git_branch: \"renovate/bytes-1.x-lockfile\",\n rustc_semver: \"1.84.0\",\n rustc_channel: \"stable\",\n rustc_host_triple: \"x86_64-unknown-illumos\",\n rustc_commit_sha: \"9fc6b43126469e3858e2fe86cafb4f0fd5068869\",\n cargo_triple: \"x86_64-unknown-illumos\",\n debug: false,\n opt_level: 3,\n}","v":0,"name":"crucible","level":30,"time":"2025-03-18T05:03:30.801547027Z","hostname":"w-01JPKT246GS6ZY38CTHYM8NDAA","pid":1511} {"msg":"Upstairs <-> Downstairs Message Version: 13","v":0,"name":"crucible","level":30,"time":"2025-03-18T05:03:30.801551416Z","hostname":"w-01JPKT246GS6ZY38CTHYM8NDAA","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-03-18T05:03:30.801555496Z","hostname":"w-01JPKT246GS6ZY38CTHYM8NDAA","pid":1511} {"msg":"Crucible 8e6971c4-5795-42a7-a3e5-d5696c7cc502 has session id: f41fea57-5c46-4336-9a83-86dda3b8625c","v":0,"name":"crucible","level":30,"time":"2025-03-18T05:03:30.801883047Z","hostname":"w-01JPKT246GS6ZY38CTHYM8NDAA","pid":1511,"session_id":"f41fea57-5c46-4336-9a83-86dda3b8625c"} {"msg":"Upstairs opts: Upstairs UUID: 8e6971c4-5795-42a7-a3e5-d5696c7cc502, 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:30.801945597Z","hostname":"w-01JPKT246GS6ZY38CTHYM8NDAA","pid":1511,"session_id":"f41fea57-5c46-4336-9a83-86dda3b8625c"} {"msg":"Crucible stats registered with UUID: 8e6971c4-5795-42a7-a3e5-d5696c7cc502","v":0,"name":"crucible","level":30,"time":"2025-03-18T05:03:30.801955627Z","hostname":"w-01JPKT246GS6ZY38CTHYM8NDAA","pid":1511,"session_id":"f41fea57-5c46-4336-9a83-86dda3b8625c"} {"msg":"could not find Downstairs address for Nexus","v":0,"name":"crucible","level":40,"time":"2025-03-18T05:03:30.801959597Z","hostname":"w-01JPKT246GS6ZY38CTHYM8NDAA","pid":1511,"session_id":"f41fea57-5c46-4336-9a83-86dda3b8625c"} {"msg":"Downstairs in volume = 3","v":0,"name":"crucible","level":30,"time":"2025-03-18T05:03:30.802210948Z","hostname":"w-01JPKT246GS6ZY38CTHYM8NDAA","pid":1511,"task":"crutest"} {"msg":"The guest has requested activation with gen:1","v":0,"name":"crucible","level":30,"time":"2025-03-18T05:03:30.802238098Z","hostname":"w-01JPKT246GS6ZY38CTHYM8NDAA","pid":1511} {"msg":"8e6971c4-5795-42a7-a3e5-d5696c7cc502 active request set","v":0,"name":"crucible","level":30,"time":"2025-03-18T05:03:30.802251688Z","hostname":"w-01JPKT246GS6ZY38CTHYM8NDAA","pid":1511,"session_id":"f41fea57-5c46-4336-9a83-86dda3b8625c"} {"msg":"sending connect oneshot to client","v":0,"name":"crucible","level":30,"time":"2025-03-18T05:03:30.802260098Z","hostname":"w-01JPKT246GS6ZY38CTHYM8NDAA","pid":1511,"client":"0","":"downstairs","session_id":"f41fea57-5c46-4336-9a83-86dda3b8625c"} {"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:30.802269528Z","hostname":"w-01JPKT246GS6ZY38CTHYM8NDAA","pid":1511,"client":"0","":"downstairs","session_id":"f41fea57-5c46-4336-9a83-86dda3b8625c"} {"msg":"sending connect oneshot to client","v":0,"name":"crucible","level":30,"time":"2025-03-18T05:03:30.802277058Z","hostname":"w-01JPKT246GS6ZY38CTHYM8NDAA","pid":1511,"client":"1","":"downstairs","session_id":"f41fea57-5c46-4336-9a83-86dda3b8625c"} {"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:30.802286108Z","hostname":"w-01JPKT246GS6ZY38CTHYM8NDAA","pid":1511,"client":"1","":"downstairs","session_id":"f41fea57-5c46-4336-9a83-86dda3b8625c"} {"msg":"sending connect oneshot to client","v":0,"name":"crucible","level":30,"time":"2025-03-18T05:03:30.802294848Z","hostname":"w-01JPKT246GS6ZY38CTHYM8NDAA","pid":1511,"client":"2","":"downstairs","session_id":"f41fea57-5c46-4336-9a83-86dda3b8625c"} {"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:30.802303608Z","hostname":"w-01JPKT246GS6ZY38CTHYM8NDAA","pid":1511,"client":"2","":"downstairs","session_id":"f41fea57-5c46-4336-9a83-86dda3b8625c"} {"msg":"connecting to 127.0.0.1:8830","v":0,"name":"crucible","level":30,"time":"2025-03-18T05:03:30.802312458Z","hostname":"w-01JPKT246GS6ZY38CTHYM8NDAA","pid":1511,"":"io task","client":"2","":"downstairs","session_id":"f41fea57-5c46-4336-9a83-86dda3b8625c"} {"msg":"connecting to 127.0.0.1:8810","v":0,"name":"crucible","level":30,"time":"2025-03-18T05:03:30.802322608Z","hostname":"w-01JPKT246GS6ZY38CTHYM8NDAA","pid":1511,"":"io task","client":"0","":"downstairs","session_id":"f41fea57-5c46-4336-9a83-86dda3b8625c"} {"msg":"connecting to 127.0.0.1:8820","v":0,"name":"crucible","level":30,"time":"2025-03-18T05:03:30.802334008Z","hostname":"w-01JPKT246GS6ZY38CTHYM8NDAA","pid":1511,"":"io task","client":"1","":"downstairs","session_id":"f41fea57-5c46-4336-9a83-86dda3b8625c"} {"msg":"ds_connection connected from Ok(127.0.0.1:62999)","v":0,"name":"crucible","level":30,"time":"2025-03-18T05:03:30.802463289Z","hostname":"w-01JPKT246GS6ZY38CTHYM8NDAA","pid":1511,"":"io task","client":"0","":"downstairs","session_id":"f41fea57-5c46-4336-9a83-86dda3b8625c"} {"msg":"ds_connection connected from Ok(127.0.0.1:47565)","v":0,"name":"crucible","level":30,"time":"2025-03-18T05:03:30.802519249Z","hostname":"w-01JPKT246GS6ZY38CTHYM8NDAA","pid":1511,"":"io task","client":"2","":"downstairs","session_id":"f41fea57-5c46-4336-9a83-86dda3b8625c"} {"msg":"ds_connection connected from Ok(127.0.0.1:56806)","v":0,"name":"crucible","level":30,"time":"2025-03-18T05:03:30.802537699Z","hostname":"w-01JPKT246GS6ZY38CTHYM8NDAA","pid":1511,"":"io task","client":"1","":"downstairs","session_id":"f41fea57-5c46-4336-9a83-86dda3b8625c"} {"msg":"version negotiation from state Connecting { state: WaitForPromote, mode: New }","v":0,"name":"crucible","level":30,"time":"2025-03-18T05:03:30.802779419Z","hostname":"w-01JPKT246GS6ZY38CTHYM8NDAA","pid":1511,"client":"0","":"downstairs","session_id":"f41fea57-5c46-4336-9a83-86dda3b8625c"} {"msg":"version negotiation from state Connecting { state: WaitForPromote, mode: New }","v":0,"name":"crucible","level":30,"time":"2025-03-18T05:03:30.802820159Z","hostname":"w-01JPKT246GS6ZY38CTHYM8NDAA","pid":1511,"client":"1","":"downstairs","session_id":"f41fea57-5c46-4336-9a83-86dda3b8625c"} {"msg":"version negotiation from state Connecting { state: WaitForPromote, mode: New }","v":0,"name":"crucible","level":30,"time":"2025-03-18T05:03:30.802838249Z","hostname":"w-01JPKT246GS6ZY38CTHYM8NDAA","pid":1511,"client":"2","":"downstairs","session_id":"f41fea57-5c46-4336-9a83-86dda3b8625c"} {"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:30.80301104Z","hostname":"w-01JPKT246GS6ZY38CTHYM8NDAA","pid":1511,"client":"1","":"downstairs","session_id":"f41fea57-5c46-4336-9a83-86dda3b8625c"} {"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:30.80302568Z","hostname":"w-01JPKT246GS6ZY38CTHYM8NDAA","pid":1511,"client":"2","":"downstairs","session_id":"f41fea57-5c46-4336-9a83-86dda3b8625c"} {"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:30.80305768Z","hostname":"w-01JPKT246GS6ZY38CTHYM8NDAA","pid":1511,"client":"0","":"downstairs","session_id":"f41fea57-5c46-4336-9a83-86dda3b8625c"} {"msg":"Waiting for more clients to be ready","v":0,"name":"crucible","level":30,"time":"2025-03-18T05:03:30.809256614Z","hostname":"w-01JPKT246GS6ZY38CTHYM8NDAA","pid":1511,"session_id":"f41fea57-5c46-4336-9a83-86dda3b8625c"} {"msg":"Waiting for more clients to be ready","v":0,"name":"crucible","level":30,"time":"2025-03-18T05:03:30.811120248Z","hostname":"w-01JPKT246GS6ZY38CTHYM8NDAA","pid":1511,"session_id":"f41fea57-5c46-4336-9a83-86dda3b8625c"} {"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:30.811259438Z","hostname":"w-01JPKT246GS6ZY38CTHYM8NDAA","pid":1511,"":"downstairs","":"downstairs","session_id":"f41fea57-5c46-4336-9a83-86dda3b8625c"} {"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:30.811265918Z","hostname":"w-01JPKT246GS6ZY38CTHYM8NDAA","pid":1511,"":"downstairs","":"downstairs","session_id":"f41fea57-5c46-4336-9a83-86dda3b8625c"} {"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:30.811270458Z","hostname":"w-01JPKT246GS6ZY38CTHYM8NDAA","pid":1511,"":"downstairs","":"downstairs","session_id":"f41fea57-5c46-4336-9a83-86dda3b8625c"} {"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:30.811274548Z","hostname":"w-01JPKT246GS6ZY38CTHYM8NDAA","pid":1511,"":"downstairs","":"downstairs","session_id":"f41fea57-5c46-4336-9a83-86dda3b8625c"} {"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:30.811281438Z","hostname":"w-01JPKT246GS6ZY38CTHYM8NDAA","pid":1511,"":"downstairs","":"downstairs","session_id":"f41fea57-5c46-4336-9a83-86dda3b8625c"} {"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:30.811285698Z","hostname":"w-01JPKT246GS6ZY38CTHYM8NDAA","pid":1511,"":"downstairs","":"downstairs","session_id":"f41fea57-5c46-4336-9a83-86dda3b8625c"} {"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:30.811289998Z","hostname":"w-01JPKT246GS6ZY38CTHYM8NDAA","pid":1511,"":"downstairs","":"downstairs","session_id":"f41fea57-5c46-4336-9a83-86dda3b8625c"} {"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:30.811294358Z","hostname":"w-01JPKT246GS6ZY38CTHYM8NDAA","pid":1511,"":"downstairs","":"downstairs","session_id":"f41fea57-5c46-4336-9a83-86dda3b8625c"} {"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:30.811298448Z","hostname":"w-01JPKT246GS6ZY38CTHYM8NDAA","pid":1511,"":"downstairs","":"downstairs","session_id":"f41fea57-5c46-4336-9a83-86dda3b8625c"} {"msg":"Max found gen is 1","v":0,"name":"crucible","level":30,"time":"2025-03-18T05:03:30.811302468Z","hostname":"w-01JPKT246GS6ZY38CTHYM8NDAA","pid":1511,"":"downstairs","":"downstairs","session_id":"f41fea57-5c46-4336-9a83-86dda3b8625c"} {"msg":"Generation requested: 1 >= found:1","v":0,"name":"crucible","level":30,"time":"2025-03-18T05:03:30.811306508Z","hostname":"w-01JPKT246GS6ZY38CTHYM8NDAA","pid":1511,"":"downstairs","":"downstairs","session_id":"f41fea57-5c46-4336-9a83-86dda3b8625c"} {"msg":"Next flush: 1","v":0,"name":"crucible","level":30,"time":"2025-03-18T05:03:30.811310498Z","hostname":"w-01JPKT246GS6ZY38CTHYM8NDAA","pid":1511,"":"downstairs","":"downstairs","session_id":"f41fea57-5c46-4336-9a83-86dda3b8625c"} {"msg":"All extents match","v":0,"name":"crucible","level":30,"time":"2025-03-18T05:03:30.811314458Z","hostname":"w-01JPKT246GS6ZY38CTHYM8NDAA","pid":1511,"":"downstairs","":"downstairs","session_id":"f41fea57-5c46-4336-9a83-86dda3b8625c"} {"msg":"No downstairs reconciliation required","v":0,"name":"crucible","level":30,"time":"2025-03-18T05:03:30.811318448Z","hostname":"w-01JPKT246GS6ZY38CTHYM8NDAA","pid":1511,"session_id":"f41fea57-5c46-4336-9a83-86dda3b8625c"} {"msg":"Transition from WaitQuorum to Active","v":0,"name":"crucible","level":30,"time":"2025-03-18T05:03:30.811321968Z","hostname":"w-01JPKT246GS6ZY38CTHYM8NDAA","pid":1511,"client":"0","":"downstairs","session_id":"f41fea57-5c46-4336-9a83-86dda3b8625c"} {"msg":"Transition from WaitQuorum to Active","v":0,"name":"crucible","level":30,"time":"2025-03-18T05:03:30.811326038Z","hostname":"w-01JPKT246GS6ZY38CTHYM8NDAA","pid":1511,"client":"1","":"downstairs","session_id":"f41fea57-5c46-4336-9a83-86dda3b8625c"} {"msg":"Transition from WaitQuorum to Active","v":0,"name":"crucible","level":30,"time":"2025-03-18T05:03:30.811330068Z","hostname":"w-01JPKT246GS6ZY38CTHYM8NDAA","pid":1511,"client":"2","":"downstairs","session_id":"f41fea57-5c46-4336-9a83-86dda3b8625c"} {"msg":"All required reconciliation work is completed","v":0,"name":"crucible","level":30,"time":"2025-03-18T05:03:30.811334038Z","hostname":"w-01JPKT246GS6ZY38CTHYM8NDAA","pid":1511,"session_id":"f41fea57-5c46-4336-9a83-86dda3b8625c"} {"msg":"Set Downstairs and Upstairs active after reconciliation","v":0,"name":"crucible","level":30,"time":"2025-03-18T05:03:30.811337538Z","hostname":"w-01JPKT246GS6ZY38CTHYM8NDAA","pid":1511,"session_id":"f41fea57-5c46-4336-9a83-86dda3b8625c"} {"msg":"8e6971c4-5795-42a7-a3e5-d5696c7cc502 is now active with session: f41fea57-5c46-4336-9a83-86dda3b8625c","v":0,"name":"crucible","level":30,"time":"2025-03-18T05:03:30.811341148Z","hostname":"w-01JPKT246GS6ZY38CTHYM8NDAA","pid":1511,"session_id":"f41fea57-5c46-4336-9a83-86dda3b8625c"} {"msg":"Set Active after no reconciliation","v":0,"name":"crucible","level":30,"time":"2025-03-18T05:03:30.811346298Z","hostname":"w-01JPKT246GS6ZY38CTHYM8NDAA","pid":1511,"session_id":"f41fea57-5c46-4336-9a83-86dda3b8625c"} {"msg":"The guest has finished waiting for activation with:1","v":0,"name":"crucible","level":30,"time":"2025-03-18T05:03:30.811354628Z","hostname":"w-01JPKT246GS6ZY38CTHYM8NDAA","pid":1511} {"msg":"Activated sub_volume 8e6971c4-5795-42a7-a3e5-d5696c7cc502","v":0,"name":"crucible","level":30,"time":"2025-03-18T05:03:30.811465089Z","hostname":"w-01JPKT246GS6ZY38CTHYM8NDAA","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:5 States: Active Active Active JOBID ACK TYPE BKS/EXT DS:0 DS:1 DS:2 REPLAY 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 Write 256 Done Done Done false 104782 Acked Flush 0 Done Done Sent false STATES DS:0 DS:1 DS:2 TOTAL Sent 0 0 1 1 Done 5 5 4 14 Skipped 0 0 0 0 Error 0 0 0 0 Last Flush: Some(JobId(104782)) Some(JobId(104782)) None Downstairs last five completed: 104777 104776 104775 104774 104773 Upstairs last five completed: 104782 104777 104781 104780 104779 CLIENT: Up:0 ds:5 act:3 ---------------------------------------------------------------- Crucible gen:1 GIO:true work queues: Upstairs:0 downstairs:0 Downstairs last five completed: 104782 104781 104780 104779 104778 Upstairs last five completed: 104782 104777 104781 104780 104779 CLIENT: Up:0 ds:0 act:3 CLIENT: All crucible jobs finished, exiting program