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(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 23 06:06:28.447 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 23 06:06:33.492 INFO accepted connection, remote_addr: 127.0.0.1:40967, 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 23 06:06:33.493 [8810] Disable keep_running INFO[8830] Disable keep_running request completed, latency_us:[8820] Disable keep_running 189, response_code: 204, uri: /disablerestart/all, method: POST, req_id: 83a71128-3308-49c5-853c-77c9cb5dffaf, remote_addr: 127.0.0.1:40967, local_addr: 127.0.0.1:9998 Mar 23 06:07:59.455 INFO accepted connection, remote_addr: 127.0.0.1:44174, local_addr: 127.0.0.1:9998 Mar 23 06:07:59.456 INFO request completed, latency_us: 73, response_code: 204, uri: /shutdown, method: POST, req_id: 9735d207-2f43-41c2-89cb-7db335fbabbe, remote_addr: 127.0.0.1:44174, local_addr: 127.0.0.1:9998 Main task has work to do, go find it got dsc Shutdown Shutdown Shut it down [8810] Disable keep_running [8810] Got stop action so:false kr:false [8820] Disable keep_running [8820] Got stop action so:false kr:false [8830] Disable keep_running [8830] 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: \"a0baefa8a6d4c0e5f0d4f746f2af5de9c08b52b6\",\n git_commit_timestamp: \"2025-03-23T05:46:50.000000000Z\",\n git_branch: \"renovate/rust-1.x\",\n rustc_semver: \"1.85.1\",\n rustc_channel: \"stable\",\n rustc_host_triple: \"x86_64-unknown-illumos\",\n rustc_commit_sha: \"4eb161250e340c8f48f66e2b929ef4a5bed7c181\",\n cargo_triple: \"x86_64-unknown-illumos\",\n debug: false,\n opt_level: 3,\n}","v":0,"name":"crucible","level":30,"time":"2025-03-23T06:06:33.558652101Z","hostname":"bmat-EVT22200007-0000589e","pid":1509} {"msg":"Upstairs <-> Downstairs Message Version: 13","v":0,"name":"crucible","level":30,"time":"2025-03-23T06:06:33.558658794Z","hostname":"bmat-EVT22200007-0000589e","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-23T06:06:33.558664626Z","hostname":"bmat-EVT22200007-0000589e","pid":1509} {"msg":"Crucible 86e7f775-e236-455e-a344-3aab7a3e9dee has session id: 189e11bb-6efa-49df-9dcb-a083412cf642","v":0,"name":"crucible","level":30,"time":"2025-03-23T06:06:33.559499451Z","hostname":"bmat-EVT22200007-0000589e","pid":1509,"session_id":"189e11bb-6efa-49df-9dcb-a083412cf642"} {"msg":"Upstairs opts: Upstairs UUID: 86e7f775-e236-455e-a344-3aab7a3e9dee, 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-23T06:06:33.559525292Z","hostname":"bmat-EVT22200007-0000589e","pid":1509,"session_id":"189e11bb-6efa-49df-9dcb-a083412cf642"} {"msg":"Crucible stats registered with UUID: 86e7f775-e236-455e-a344-3aab7a3e9dee","v":0,"name":"crucible","level":30,"time":"2025-03-23T06:06:33.559537547Z","hostname":"bmat-EVT22200007-0000589e","pid":1509,"session_id":"189e11bb-6efa-49df-9dcb-a083412cf642"} {"msg":"could not find Downstairs address for Nexus","v":0,"name":"crucible","level":40,"time":"2025-03-23T06:06:33.559542406Z","hostname":"bmat-EVT22200007-0000589e","pid":1509,"session_id":"189e11bb-6efa-49df-9dcb-a083412cf642"} {"msg":"Downstairs in volume = 3","v":0,"name":"crucible","level":30,"time":"2025-03-23T06:06:33.559934694Z","hostname":"bmat-EVT22200007-0000589e","pid":1509,"task":"crutest"} {"msg":"The guest has requested activation with gen:1","v":0,"name":"crucible","level":30,"time":"2025-03-23T06:06:33.559988401Z","hostname":"bmat-EVT22200007-0000589e","pid":1509} {"msg":"86e7f775-e236-455e-a344-3aab7a3e9dee active request set","v":0,"name":"crucible","level":30,"time":"2025-03-23T06:06:33.56003871Z","hostname":"bmat-EVT22200007-0000589e","pid":1509,"session_id":"189e11bb-6efa-49df-9dcb-a083412cf642"} {"msg":"sending connect oneshot to client","v":0,"name":"crucible","level":30,"time":"2025-03-23T06:06:33.560045013Z","hostname":"bmat-EVT22200007-0000589e","pid":1509,"client":"0","":"downstairs","session_id":"189e11bb-6efa-49df-9dcb-a083412cf642"} {"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-23T06:06:33.560065804Z","hostname":"bmat-EVT22200007-0000589e","pid":1509,"client":"0","":"downstairs","session_id":"189e11bb-6efa-49df-9dcb-a083412cf642"} {"msg":"sending connect oneshot to client","v":0,"name":"crucible","level":30,"time":"2025-03-23T06:06:33.560071395Z","hostname":"bmat-EVT22200007-0000589e","pid":1509,"client":"1","":"downstairs","session_id":"189e11bb-6efa-49df-9dcb-a083412cf642"} {"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-23T06:06:33.560086155Z","hostname":"bmat-EVT22200007-0000589e","pid":1509,"client":"1","":"downstairs","session_id":"189e11bb-6efa-49df-9dcb-a083412cf642"} {"msg":"sending connect oneshot to client","v":0,"name":"crucible","level":30,"time":"2025-03-23T06:06:33.560091255Z","hostname":"bmat-EVT22200007-0000589e","pid":1509,"client":"2","":"downstairs","session_id":"189e11bb-6efa-49df-9dcb-a083412cf642"} {"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-23T06:06:33.560096235Z","hostname":"bmat-EVT22200007-0000589e","pid":1509,"client":"2","":"downstairs","session_id":"189e11bb-6efa-49df-9dcb-a083412cf642"} {"msg":"connecting to 127.0.0.1:8830","v":0,"name":"crucible","level":30,"time":"2025-03-23T06:06:33.560302323Z","hostname":"bmat-EVT22200007-0000589e","pid":1509,"":"io task","client":"2","":"downstairs","session_id":"189e11bb-6efa-49df-9dcb-a083412cf642"} {"msg":"connecting to 127.0.0.1:8810","v":0,"name":"crucible","level":30,"time":"2025-03-23T06:06:33.560326832Z","hostname":"bmat-EVT22200007-0000589e","pid":1509,"":"io task","client":"0","":"downstairs","session_id":"189e11bb-6efa-49df-9dcb-a083412cf642"} {"msg":"connecting to 127.0.0.1:8820","v":0,"name":"crucible","level":30,"time":"2025-03-23T06:06:33.560333605Z","hostname":"bmat-EVT22200007-0000589e","pid":1509,"":"io task","client":"1","":"downstairs","session_id":"189e11bb-6efa-49df-9dcb-a083412cf642"} {"msg":"ds_connection connected from Ok(127.0.0.1:34299)","v":0,"name":"crucible","level":30,"time":"2025-03-23T06:06:33.560339487Z","hostname":"bmat-EVT22200007-0000589e","pid":1509,"":"io task","client":"2","":"downstairs","session_id":"189e11bb-6efa-49df-9dcb-a083412cf642"} {"msg":"ds_connection connected from Ok(127.0.0.1:50079)","v":0,"name":"crucible","level":30,"time":"2025-03-23T06:06:33.560353244Z","hostname":"bmat-EVT22200007-0000589e","pid":1509,"":"io task","client":"1","":"downstairs","session_id":"189e11bb-6efa-49df-9dcb-a083412cf642"} {"msg":"ds_connection connected from Ok(127.0.0.1:60075)","v":0,"name":"crucible","level":30,"time":"2025-03-23T06:06:33.560425598Z","hostname":"bmat-EVT22200007-0000589e","pid":1509,"":"io task","client":"0","":"downstairs","session_id":"189e11bb-6efa-49df-9dcb-a083412cf642"} {"msg":"version negotiation from state Connecting { state: WaitForPromote, mode: New }","v":0,"name":"crucible","level":30,"time":"2025-03-23T06:06:33.561247768Z","hostname":"bmat-EVT22200007-0000589e","pid":1509,"client":"1","":"downstairs","session_id":"189e11bb-6efa-49df-9dcb-a083412cf642"} {"msg":"version negotiation from state Connecting { state: WaitForPromote, mode: New }","v":0,"name":"crucible","level":30,"time":"2025-03-23T06:06:33.561623062Z","hostname":"bmat-EVT22200007-0000589e","pid":1509,"client":"2","":"downstairs","session_id":"189e11bb-6efa-49df-9dcb-a083412cf642"} {"msg":"version negotiation from state Connecting { state: WaitForPromote, mode: New }","v":0,"name":"crucible","level":30,"time":"2025-03-23T06:06:33.561632731Z","hostname":"bmat-EVT22200007-0000589e","pid":1509,"client":"0","":"downstairs","session_id":"189e11bb-6efa-49df-9dcb-a083412cf642"} {"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-23T06:06:33.561638422Z","hostname":"bmat-EVT22200007-0000589e","pid":1509,"client":"1","":"downstairs","session_id":"189e11bb-6efa-49df-9dcb-a083412cf642"} {"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-23T06:06:33.561993366Z","hostname":"bmat-EVT22200007-0000589e","pid":1509,"client":"0","":"downstairs","session_id":"189e11bb-6efa-49df-9dcb-a083412cf642"} {"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-23T06:06:33.56215193Z","hostname":"bmat-EVT22200007-0000589e","pid":1509,"client":"2","":"downstairs","session_id":"189e11bb-6efa-49df-9dcb-a083412cf642"} {"msg":"Waiting for more clients to be ready","v":0,"name":"crucible","level":30,"time":"2025-03-23T06:06:33.573152903Z","hostname":"bmat-EVT22200007-0000589e","pid":1509,"session_id":"189e11bb-6efa-49df-9dcb-a083412cf642"} {"msg":"Waiting for more clients to be ready","v":0,"name":"crucible","level":30,"time":"2025-03-23T06:06:33.573256548Z","hostname":"bmat-EVT22200007-0000589e","pid":1509,"session_id":"189e11bb-6efa-49df-9dcb-a083412cf642"} {"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-23T06:06:33.574156182Z","hostname":"bmat-EVT22200007-0000589e","pid":1509,"":"downstairs","":"downstairs","session_id":"189e11bb-6efa-49df-9dcb-a083412cf642"} {"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-23T06:06:33.574183216Z","hostname":"bmat-EVT22200007-0000589e","pid":1509,"":"downstairs","":"downstairs","session_id":"189e11bb-6efa-49df-9dcb-a083412cf642"} {"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-23T06:06:33.574189789Z","hostname":"bmat-EVT22200007-0000589e","pid":1509,"":"downstairs","":"downstairs","session_id":"189e11bb-6efa-49df-9dcb-a083412cf642"} {"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-23T06:06:33.57419517Z","hostname":"bmat-EVT22200007-0000589e","pid":1509,"":"downstairs","":"downstairs","session_id":"189e11bb-6efa-49df-9dcb-a083412cf642"} {"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-23T06:06:33.57420059Z","hostname":"bmat-EVT22200007-0000589e","pid":1509,"":"downstairs","":"downstairs","session_id":"189e11bb-6efa-49df-9dcb-a083412cf642"} {"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-23T06:06:33.574212915Z","hostname":"bmat-EVT22200007-0000589e","pid":1509,"":"downstairs","":"downstairs","session_id":"189e11bb-6efa-49df-9dcb-a083412cf642"} {"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-23T06:06:33.574218506Z","hostname":"bmat-EVT22200007-0000589e","pid":1509,"":"downstairs","":"downstairs","session_id":"189e11bb-6efa-49df-9dcb-a083412cf642"} {"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-23T06:06:33.574223466Z","hostname":"bmat-EVT22200007-0000589e","pid":1509,"":"downstairs","":"downstairs","session_id":"189e11bb-6efa-49df-9dcb-a083412cf642"} {"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-23T06:06:33.574228355Z","hostname":"bmat-EVT22200007-0000589e","pid":1509,"":"downstairs","":"downstairs","session_id":"189e11bb-6efa-49df-9dcb-a083412cf642"} {"msg":"Max found gen is 1","v":0,"name":"crucible","level":30,"time":"2025-03-23T06:06:33.574233586Z","hostname":"bmat-EVT22200007-0000589e","pid":1509,"":"downstairs","":"downstairs","session_id":"189e11bb-6efa-49df-9dcb-a083412cf642"} {"msg":"Generation requested: 1 >= found:1","v":0,"name":"crucible","level":30,"time":"2025-03-23T06:06:33.574238355Z","hostname":"bmat-EVT22200007-0000589e","pid":1509,"":"downstairs","":"downstairs","session_id":"189e11bb-6efa-49df-9dcb-a083412cf642"} {"msg":"Next flush: 1","v":0,"name":"crucible","level":30,"time":"2025-03-23T06:06:33.574243085Z","hostname":"bmat-EVT22200007-0000589e","pid":1509,"":"downstairs","":"downstairs","session_id":"189e11bb-6efa-49df-9dcb-a083412cf642"} {"msg":"All extents match","v":0,"name":"crucible","level":30,"time":"2025-03-23T06:06:33.574247924Z","hostname":"bmat-EVT22200007-0000589e","pid":1509,"":"downstairs","":"downstairs","session_id":"189e11bb-6efa-49df-9dcb-a083412cf642"} {"msg":"No downstairs reconciliation required","v":0,"name":"crucible","level":30,"time":"2025-03-23T06:06:33.574253465Z","hostname":"bmat-EVT22200007-0000589e","pid":1509,"session_id":"189e11bb-6efa-49df-9dcb-a083412cf642"} {"msg":"Transition from WaitQuorum to Active","v":0,"name":"crucible","level":30,"time":"2025-03-23T06:06:33.574258124Z","hostname":"bmat-EVT22200007-0000589e","pid":1509,"client":"0","":"downstairs","session_id":"189e11bb-6efa-49df-9dcb-a083412cf642"} {"msg":"Transition from WaitQuorum to Active","v":0,"name":"crucible","level":30,"time":"2025-03-23T06:06:33.574263786Z","hostname":"bmat-EVT22200007-0000589e","pid":1509,"client":"1","":"downstairs","session_id":"189e11bb-6efa-49df-9dcb-a083412cf642"} {"msg":"Transition from WaitQuorum to Active","v":0,"name":"crucible","level":30,"time":"2025-03-23T06:06:33.574268946Z","hostname":"bmat-EVT22200007-0000589e","pid":1509,"client":"2","":"downstairs","session_id":"189e11bb-6efa-49df-9dcb-a083412cf642"} {"msg":"All required reconciliation work is completed","v":0,"name":"crucible","level":30,"time":"2025-03-23T06:06:33.574273936Z","hostname":"bmat-EVT22200007-0000589e","pid":1509,"session_id":"189e11bb-6efa-49df-9dcb-a083412cf642"} {"msg":"Set Downstairs and Upstairs active after reconciliation","v":0,"name":"crucible","level":30,"time":"2025-03-23T06:06:33.574278124Z","hostname":"bmat-EVT22200007-0000589e","pid":1509,"session_id":"189e11bb-6efa-49df-9dcb-a083412cf642"} {"msg":"86e7f775-e236-455e-a344-3aab7a3e9dee is now active with session: 189e11bb-6efa-49df-9dcb-a083412cf642","v":0,"name":"crucible","level":30,"time":"2025-03-23T06:06:33.574282623Z","hostname":"bmat-EVT22200007-0000589e","pid":1509,"session_id":"189e11bb-6efa-49df-9dcb-a083412cf642"} {"msg":"Set Active after no reconciliation","v":0,"name":"crucible","level":30,"time":"2025-03-23T06:06:33.574289988Z","hostname":"bmat-EVT22200007-0000589e","pid":1509,"session_id":"189e11bb-6efa-49df-9dcb-a083412cf642"} {"msg":"The guest has finished waiting for activation with:1","v":0,"name":"crucible","level":30,"time":"2025-03-23T06:06:33.574294717Z","hostname":"bmat-EVT22200007-0000589e","pid":1509} {"msg":"Activated sub_volume 86e7f775-e236-455e-a344-3aab7a3e9dee","v":0,"name":"crucible","level":30,"time":"2025-03-23T06:06:33.574379385Z","hostname":"bmat-EVT22200007-0000589e","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:30 States: Active Active Active JOBID ACK TYPE BKS/EXT DS:0 DS:1 DS:2 REPLAY 104517 Acked Write 256 Done Done Done false 104518 Acked Write 256 Done Done Done false 104519 Acked Write 256 Done Done Done false 104520 Acked Write 256 Done Done Done false 104521 Acked Write 256 Done Done Done false 104522 Acked Write 256 Done Done Done false 104523 Acked Write 256 Done Done Done false 104524 Acked Write 256 Done Done Done false 104525 Acked Write 256 Done Done Done false 104526 Acked Write 256 Done Done Done false 104527 Acked Write 256 Done Done Done false 104528 Acked Write 256 Done Done Done false 104529 Acked Write 256 Done Done Done false 104530 Acked Write 256 Done Done Done false 104531 Acked Write 256 Done Done Done false 104532 Acked Write 256 Done Done Done false 104533 Acked Write 256 Done Done Done false 104534 Acked Write 256 Done Done Done false 104535 Acked Write 256 Done Done Done false 104536 Acked Write 256 Done Done Done false 104537 Acked Write 256 Done Done Done false 104538 Acked Write 256 Done Done Done false 104539 Acked Write 256 Done Done Done false 104540 Acked Write 256 Done Done Done false 104541 Acked Write 256 Done Done Done false 104542 Acked Write 256 Done Done Done false 104543 Acked Write 256 Done Done Done false 104544 Acked Write 256 Done Done Done false 104545 Acked Write 256 Done Done Done false 104546 Acked Flush 0 Done Done Sent false STATES DS:0 DS:1 DS:2 TOTAL Sent 0 0 1 1 Done 30 30 29 89 Skipped 0 0 0 0 Error 0 0 0 0 Last Flush: Some(JobId(104546)) Some(JobId(104546)) None Downstairs last five completed: 104516 104515 104514 104513 104512 Upstairs last five completed: 104546 104516 104545 104544 104543 CLIENT: Up:0 ds:30 act:3 ---------------------------------------------------------------- Crucible gen:1 GIO:true work queues: Upstairs:0 downstairs:0 Downstairs last five completed: 104546 104545 104544 104543 104542 Upstairs last five completed: 104546 104516 104545 104544 104543 CLIENT: Up:0 ds:0 act:3 CLIENT: All crucible jobs finished, exiting program