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" [8810][0] initial start wait reports Starting Starting downstairs at port 8820 Make output file at "/tmp/dsc/downstairs-8820.txt" Starting downstairs at port 8830 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(1504) [8810][0] initial start wait reports Running Downstairs /var/tmp/dsc/8820 port 8820 PID:Some(1505) [8820][1] initial start wait reports Running Mar 18 05:02:16.085 INFO listening, local_addr: 127.0.0.1:9998 Downstairs /var/tmp/dsc/8830 port 8830 PID:Some(1506) [8830][2] initial start wait reports Running All downstairs are running Control access at:127.0.0.1:9998 Mar 18 05:02:21.133 INFO accepted connection, remote_addr: 127.0.0.1:48058, local_addr: 127.0.0.1:9998 Main task has work to do, go find it got dsc DisableRestartAll disable restart on all: 3 [8810] Disable keep_running Mar 18 05:02:21.135[8830] Disable keep_running INFO request completed, latency_us: 171, response_code: 204, uri: /disablerestart/all, method: POST, req_id: 66dd8e61-a157-45b7-a8b9-ea3a6fad7024, remote_addr: 127.0.0.1:[8820] Disable keep_running 48058, local_addr: 127.0.0.1:9998 Mar 18 05:03:43.105 INFO accepted connection, remote_addr: 127.0.0.1:63599, local_addr: 127.0.0.1:9998 Main task has work to do, go find it got dsc Shutdown Shutdown Mar 18 05:03:43.105 INFO request completed, latency_us: 94, response_code: 204, uri: Shut it down /shutdown, method: POST, req_id: 1c361529-65ff-44e8-9f0e-b18d6f3262ee, remote_addr: 127.0.0.1:63599, [8820] Disable keep_running local_addr: 127.0.0.1:9998 [8830] Disable keep_running [8820] Got stop action so:false kr:false [8830] Got stop action so:false kr:false [8810] Disable keep_running [8810] Got stop action so:false kr:false [8820] Exited with: ExitStatus(unix_wait_status(9)) [8820][1] reports Exit [8830] Exited with: ExitStatus(unix_wait_status(9)) [8830][2] reports Exit [8810] Exited with: ExitStatus(unix_wait_status(9)) [8810][0] reports Exit :"Crucible Version: BuildInfo {\n version: \"0.0.1\",\n git_sha: \"15e44c06f41a7116c9cfd33f9c32fc1c3d097c63\",\n git_commit_timestamp: \"2025-03-18T04:42:20.000000000Z\",\n git_branch: \"renovate/anyhow-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:02:21.209358082Z","hostname":"bmat-EVT22200007-000056db","pid":1509} {"msg":"Upstairs <-> Downstairs Message Version: 13","v":0,"name":"crucible","level":30,"time":"2025-03-18T05:02:21.209365136Z","hostname":"bmat-EVT22200007-000056db","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:02:21.209371258Z","hostname":"bmat-EVT22200007-000056db","pid":1509} {"msg":"Crucible 519b48f0-321e-46d0-b9ba-e4d9eda11e93 has session id: e054a4d2-a4e6-41de-b1b8-bd43532e832d","v":0,"name":"crucible","level":30,"time":"2025-03-18T05:02:21.210212605Z","hostname":"bmat-EVT22200007-000056db","pid":1509,"session_id":"e054a4d2-a4e6-41de-b1b8-bd43532e832d"} {"msg":"Upstairs opts: Upstairs UUID: 519b48f0-321e-46d0-b9ba-e4d9eda11e93, 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:02:21.210238146Z","hostname":"bmat-EVT22200007-000056db","pid":1509,"session_id":"e054a4d2-a4e6-41de-b1b8-bd43532e832d"} {"msg":"Crucible stats registered with UUID: 519b48f0-321e-46d0-b9ba-e4d9eda11e93","v":0,"name":"crucible","level":30,"time":"2025-03-18T05:02:21.210256563Z","hostname":"bmat-EVT22200007-000056db","pid":1509,"session_id":"e054a4d2-a4e6-41de-b1b8-bd43532e832d"} {"msg":"could not find Downstairs address for Nexus","v":0,"name":"crucible","level":40,"time":"2025-03-18T05:02:21.210261933Z","hostname":"bmat-EVT22200007-000056db","pid":1509,"session_id":"e054a4d2-a4e6-41de-b1b8-bd43532e832d"} {"msg":"Downstairs in volume = 3","v":0,"name":"crucible","level":30,"time":"2025-03-18T05:02:21.210817224Z","hostname":"bmat-EVT22200007-000056db","pid":1509,"task":"crutest"} {"msg":"The guest has requested activation with gen:1","v":0,"name":"crucible","level":30,"time":"2025-03-18T05:02:21.21083524Z","hostname":"bmat-EVT22200007-000056db","pid":1509} {"msg":"519b48f0-321e-46d0-b9ba-e4d9eda11e93 active request set","v":0,"name":"crucible","level":30,"time":"2025-03-18T05:02:21.210924296Z","hostname":"bmat-EVT22200007-000056db","pid":1509,"session_id":"e054a4d2-a4e6-41de-b1b8-bd43532e832d"} {"msg":"sending connect oneshot to client","v":0,"name":"crucible","level":30,"time":"2025-03-18T05:02:21.210936761Z","hostname":"bmat-EVT22200007-000056db","pid":1509,"client":"0","":"downstairs","session_id":"e054a4d2-a4e6-41de-b1b8-bd43532e832d"} {"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:02:21.210987261Z","hostname":"bmat-EVT22200007-000056db","pid":1509,"client":"0","":"downstairs","session_id":"e054a4d2-a4e6-41de-b1b8-bd43532e832d"} {"msg":"sending connect oneshot to client","v":0,"name":"crucible","level":30,"time":"2025-03-18T05:02:21.210995197Z","hostname":"bmat-EVT22200007-000056db","pid":1509,"client":"1","":"downstairs","session_id":"e054a4d2-a4e6-41de-b1b8-bd43532e832d"} {"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:02:21.211001269Z","hostname":"bmat-EVT22200007-000056db","pid":1509,"client":"1","":"downstairs","session_id":"e054a4d2-a4e6-41de-b1b8-bd43532e832d"} {"msg":"sending connect oneshot to client","v":0,"name":"crucible","level":30,"time":"2025-03-18T05:02:21.21100684Z","hostname":"bmat-EVT22200007-000056db","pid":1509,"client":"2","":"downstairs","session_id":"e054a4d2-a4e6-41de-b1b8-bd43532e832d"} {"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:02:21.211012701Z","hostname":"bmat-EVT22200007-000056db","pid":1509,"client":"2","":"downstairs","session_id":"e054a4d2-a4e6-41de-b1b8-bd43532e832d"} {"msg":"connecting to 127.0.0.1:8830","v":0,"name":"crucible","level":30,"time":"2025-03-18T05:02:21.211039835Z","hostname":"bmat-EVT22200007-000056db","pid":1509,"":"io task","client":"2","":"downstairs","session_id":"e054a4d2-a4e6-41de-b1b8-bd43532e832d"} {"msg":"connecting to 127.0.0.1:8810","v":0,"name":"crucible","level":30,"time":"2025-03-18T05:02:21.21104723Z","hostname":"bmat-EVT22200007-000056db","pid":1509,"":"io task","client":"0","":"downstairs","session_id":"e054a4d2-a4e6-41de-b1b8-bd43532e832d"} {"msg":"connecting to 127.0.0.1:8820","v":0,"name":"crucible","level":30,"time":"2025-03-18T05:02:21.211307516Z","hostname":"bmat-EVT22200007-000056db","pid":1509,"":"io task","client":"1","":"downstairs","session_id":"e054a4d2-a4e6-41de-b1b8-bd43532e832d"} {"msg":"ds_connection connected from Ok(127.0.0.1:45837)","v":0,"name":"crucible","level":30,"time":"2025-03-18T05:02:21.211333026Z","hostname":"bmat-EVT22200007-000056db","pid":1509,"":"io task","client":"0","":"downstairs","session_id":"e054a4d2-a4e6-41de-b1b8-bd43532e832d"} {"msg":"ds_connection connected from Ok(127.0.0.1:44438)","v":0,"name":"crucible","level":30,"time":"2025-03-18T05:02:21.211358777Z","hostname":"bmat-EVT22200007-000056db","pid":1509,"":"io task","client":"2","":"downstairs","session_id":"e054a4d2-a4e6-41de-b1b8-bd43532e832d"} {"msg":"ds_connection connected from Ok(127.0.0.1:52606)","v":0,"name":"crucible","level":30,"time":"2025-03-18T05:02:21.211449026Z","hostname":"bmat-EVT22200007-000056db","pid":1509,"":"io task","client":"1","":"downstairs","session_id":"e054a4d2-a4e6-41de-b1b8-bd43532e832d"} {"msg":"version negotiation from state Connecting { state: WaitForPromote, mode: New }","v":0,"name":"crucible","level":30,"time":"2025-03-18T05:02:21.211665034Z","hostname":"bmat-EVT22200007-000056db","pid":1509,"client":"0","":"downstairs","session_id":"e054a4d2-a4e6-41de-b1b8-bd43532e832d"} {"msg":"version negotiation from state Connecting { state: WaitForPromote, mode: New }","v":0,"name":"crucible","level":30,"time":"2025-03-18T05:02:21.212145056Z","hostname":"bmat-EVT22200007-000056db","pid":1509,"client":"2","":"downstairs","session_id":"e054a4d2-a4e6-41de-b1b8-bd43532e832d"} {"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:02:21.212166869Z","hostname":"bmat-EVT22200007-000056db","pid":1509,"client":"0","":"downstairs","session_id":"e054a4d2-a4e6-41de-b1b8-bd43532e832d"} {"msg":"version negotiation from state Connecting { state: WaitForPromote, mode: New }","v":0,"name":"crucible","level":30,"time":"2025-03-18T05:02:21.212283049Z","hostname":"bmat-EVT22200007-000056db","pid":1509,"client":"1","":"downstairs","session_id":"e054a4d2-a4e6-41de-b1b8-bd43532e832d"} {"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:02:21.212559487Z","hostname":"bmat-EVT22200007-000056db","pid":1509,"client":"1","":"downstairs","session_id":"e054a4d2-a4e6-41de-b1b8-bd43532e832d"} {"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:02:21.212784343Z","hostname":"bmat-EVT22200007-000056db","pid":1509,"client":"2","":"downstairs","session_id":"e054a4d2-a4e6-41de-b1b8-bd43532e832d"} {"msg":"Waiting for more clients to be ready","v":0,"name":"crucible","level":30,"time":"2025-03-18T05:02:21.223256168Z","hostname":"bmat-EVT22200007-000056db","pid":1509,"session_id":"e054a4d2-a4e6-41de-b1b8-bd43532e832d"} {"msg":"Waiting for more clients to be ready","v":0,"name":"crucible","level":30,"time":"2025-03-18T05:02:21.2234442Z","hostname":"bmat-EVT22200007-000056db","pid":1509,"session_id":"e054a4d2-a4e6-41de-b1b8-bd43532e832d"} {"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:02:21.224102876Z","hostname":"bmat-EVT22200007-000056db","pid":1509,"":"downstairs","":"downstairs","session_id":"e054a4d2-a4e6-41de-b1b8-bd43532e832d"} {"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:02:21.224119078Z","hostname":"bmat-EVT22200007-000056db","pid":1509,"":"downstairs","":"downstairs","session_id":"e054a4d2-a4e6-41de-b1b8-bd43532e832d"} {"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:02:21.224128757Z","hostname":"bmat-EVT22200007-000056db","pid":1509,"":"downstairs","":"downstairs","session_id":"e054a4d2-a4e6-41de-b1b8-bd43532e832d"} {"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:02:21.224137474Z","hostname":"bmat-EVT22200007-000056db","pid":1509,"":"downstairs","":"downstairs","session_id":"e054a4d2-a4e6-41de-b1b8-bd43532e832d"} {"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:02:21.224145751Z","hostname":"bmat-EVT22200007-000056db","pid":1509,"":"downstairs","":"downstairs","session_id":"e054a4d2-a4e6-41de-b1b8-bd43532e832d"} {"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:02:21.224172734Z","hostname":"bmat-EVT22200007-000056db","pid":1509,"":"downstairs","":"downstairs","session_id":"e054a4d2-a4e6-41de-b1b8-bd43532e832d"} {"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:02:21.224182093Z","hostname":"bmat-EVT22200007-000056db","pid":1509,"":"downstairs","":"downstairs","session_id":"e054a4d2-a4e6-41de-b1b8-bd43532e832d"} {"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:02:21.22419051Z","hostname":"bmat-EVT22200007-000056db","pid":1509,"":"downstairs","":"downstairs","session_id":"e054a4d2-a4e6-41de-b1b8-bd43532e832d"} {"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:02:21.224199107Z","hostname":"bmat-EVT22200007-000056db","pid":1509,"":"downstairs","":"downstairs","session_id":"e054a4d2-a4e6-41de-b1b8-bd43532e832d"} {"msg":"Max found gen is 1","v":0,"name":"crucible","level":30,"time":"2025-03-18T05:02:21.224207684Z","hostname":"bmat-EVT22200007-000056db","pid":1509,"":"downstairs","":"downstairs","session_id":"e054a4d2-a4e6-41de-b1b8-bd43532e832d"} {"msg":"Generation requested: 1 >= found:1","v":0,"name":"crucible","level":30,"time":"2025-03-18T05:02:21.22421589Z","hostname":"bmat-EVT22200007-000056db","pid":1509,"":"downstairs","":"downstairs","session_id":"e054a4d2-a4e6-41de-b1b8-bd43532e832d"} {"msg":"Next flush: 1","v":0,"name":"crucible","level":30,"time":"2025-03-18T05:02:21.224224858Z","hostname":"bmat-EVT22200007-000056db","pid":1509,"":"downstairs","":"downstairs","session_id":"e054a4d2-a4e6-41de-b1b8-bd43532e832d"} {"msg":"All extents match","v":0,"name":"crucible","level":30,"time":"2025-03-18T05:02:21.224233996Z","hostname":"bmat-EVT22200007-000056db","pid":1509,"":"downstairs","":"downstairs","session_id":"e054a4d2-a4e6-41de-b1b8-bd43532e832d"} {"msg":"No downstairs reconciliation required","v":0,"name":"crucible","level":30,"time":"2025-03-18T05:02:21.224243134Z","hostname":"bmat-EVT22200007-000056db","pid":1509,"session_id":"e054a4d2-a4e6-41de-b1b8-bd43532e832d"} {"msg":"Transition from WaitQuorum to Active","v":0,"name":"crucible","level":30,"time":"2025-03-18T05:02:21.224251641Z","hostname":"bmat-EVT22200007-000056db","pid":1509,"client":"0","":"downstairs","session_id":"e054a4d2-a4e6-41de-b1b8-bd43532e832d"} {"msg":"Transition from WaitQuorum to Active","v":0,"name":"crucible","level":30,"time":"2025-03-18T05:02:21.224258194Z","hostname":"bmat-EVT22200007-000056db","pid":1509,"client":"1","":"downstairs","session_id":"e054a4d2-a4e6-41de-b1b8-bd43532e832d"} {"msg":"Transition from WaitQuorum to Active","v":0,"name":"crucible","level":30,"time":"2025-03-18T05:02:21.224263705Z","hostname":"bmat-EVT22200007-000056db","pid":1509,"client":"2","":"downstairs","session_id":"e054a4d2-a4e6-41de-b1b8-bd43532e832d"} {"msg":"All required reconciliation work is completed","v":0,"name":"crucible","level":30,"time":"2025-03-18T05:02:21.224269346Z","hostname":"bmat-EVT22200007-000056db","pid":1509,"session_id":"e054a4d2-a4e6-41de-b1b8-bd43532e832d"} {"msg":"Set Downstairs and Upstairs active after reconciliation","v":0,"name":"crucible","level":30,"time":"2025-03-18T05:02:21.224274005Z","hostname":"bmat-EVT22200007-000056db","pid":1509,"session_id":"e054a4d2-a4e6-41de-b1b8-bd43532e832d"} {"msg":"519b48f0-321e-46d0-b9ba-e4d9eda11e93 is now active with session: e054a4d2-a4e6-41de-b1b8-bd43532e832d","v":0,"name":"crucible","level":30,"time":"2025-03-18T05:02:21.224278714Z","hostname":"bmat-EVT22200007-000056db","pid":1509,"session_id":"e054a4d2-a4e6-41de-b1b8-bd43532e832d"} {"msg":"Set Active after no reconciliation","v":0,"name":"crucible","level":30,"time":"2025-03-18T05:02:21.224289696Z","hostname":"bmat-EVT22200007-000056db","pid":1509,"session_id":"e054a4d2-a4e6-41de-b1b8-bd43532e832d"} {"msg":"The guest has finished waiting for activation with:1","v":0,"name":"crucible","level":30,"time":"2025-03-18T05:02:21.224294636Z","hostname":"bmat-EVT22200007-000056db","pid":1509} {"msg":"Activated sub_volume 519b48f0-321e-46d0-b9ba-e4d9eda11e93","v":0,"name":"crucible","level":30,"time":"2025-03-18T05:02:21.224370326Z","hostname":"bmat-EVT22200007-000056db","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:0 Downstairs last five completed: 104501 104500 104499 104498 104497 Upstairs last five completed: 104501 104483 104500 104499 104498 CLIENT: Up:0 ds:0 act:3 CLIENT: All crucible jobs finished, exiting program {"msg":"Guest handle has been dropped","v":0,"name":"crucible","level":40,"time":"2025-03-18T05:03:42.124634068Z","hostname":"bmat-EVT22200007-000056db","pid":1509}