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 8830 Starting downstairs at port 8820 Make output file at "/tmp/dsc/downstairs-8830.txt" Make output file at "/tmp/dsc/downstairs-8820.txt" [8830][2] initial start wait reports Starting [8820][1] 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/8820 port 8820 PID:Some(1507) [8820][1] initial start wait reports Running Downstairs /var/tmp/dsc/8830 port 8830 PID:Some(1508) [8830][2] initial start wait reports Running All downstairs are running Mar 17 22:24:40.777 INFO listening, local_addr: 127.0.0.1:9998 Control access at:127.0.0.1:9998 Mar 17 22:24:45.813 INFO accepted connection, remote_addr: 127.0.0.1:51441, 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 17 22:24:45.814 INFO request completed, latency_us: 105, response_code: 204, uri: /disablerestart/all, method: POST, req_id: 5aaf71c8-9e79-41bb-922b-f25f634b1412, remote_addr: 127.0.0.1:51441, local_addr: [8820] Disable keep_running 127[8810] Disable keep_running .[8830] Disable keep_running 0.0.1:9998 Mar 17 22:26:22.908 INFO accepted connection, remote_addr: 127.0.0.1:51925, local_addr: 127.0.0.1:9998 Main task has work to do, go find it got dsc Shutdown Shutdown Shut it down Mar 17 22:26:22.908 INFO request completed, [8810] Disable keep_running latency_us[8810] Got stop action so:false kr:false : 49, response_code: 204, [8830] Disable keep_running uri[8830] Got stop action so:false kr:false : /shutdown, method: POST, req_id: 4d43c6d7-7f7e-47ab-b564-13c004afe046, remote_addr: 127.0.0.1:51925, local_addr: 127.0.0.1:9998 [8820] Disable keep_running [8820] Got stop action so:false kr:false [8820] Exited with: ExitStatus(unix_wait_status(9)) [8810] Exited with: ExitStatus(unix_wait_status(9)) [8820][1] reports Exit [8810][0] 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: \"acc6b11fa639390710fd9a0449e05c901b048ed2\",\n git_commit_timestamp: \"2025-03-17T22:02:02.000000000Z\",\n git_branch: \"renovate/itertools-0.x\",\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-17T22:24:45.868875917Z","hostname":"w-01JPK385YEKY6MP5MTXXJ43FAT","pid":1511} {"msg":"Upstairs <-> Downstairs Message Version: 13","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:24:45.868881346Z","hostname":"w-01JPK385YEKY6MP5MTXXJ43FAT","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-17T22:24:45.868886405Z","hostname":"w-01JPK385YEKY6MP5MTXXJ43FAT","pid":1511} {"msg":"Crucible 1513be51-1bbb-4c39-bb4f-8c0b5edcdaf8 has session id: 95612b4d-d53d-4139-a284-dd246b03279b","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:24:45.869288418Z","hostname":"w-01JPK385YEKY6MP5MTXXJ43FAT","pid":1511,"session_id":"95612b4d-d53d-4139-a284-dd246b03279b"} {"msg":"Upstairs opts: Upstairs UUID: 1513be51-1bbb-4c39-bb4f-8c0b5edcdaf8, 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-17T22:24:45.869360826Z","hostname":"w-01JPK385YEKY6MP5MTXXJ43FAT","pid":1511,"session_id":"95612b4d-d53d-4139-a284-dd246b03279b"} {"msg":"Crucible stats registered with UUID: 1513be51-1bbb-4c39-bb4f-8c0b5edcdaf8","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:24:45.869377213Z","hostname":"w-01JPK385YEKY6MP5MTXXJ43FAT","pid":1511,"session_id":"95612b4d-d53d-4139-a284-dd246b03279b"} {"msg":"could not find Downstairs address for Nexus","v":0,"name":"crucible","level":40,"time":"2025-03-17T22:24:45.869385122Z","hostname":"w-01JPK385YEKY6MP5MTXXJ43FAT","pid":1511,"session_id":"95612b4d-d53d-4139-a284-dd246b03279b"} {"msg":"Downstairs in volume = 3","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:24:45.869566671Z","hostname":"w-01JPK385YEKY6MP5MTXXJ43FAT","pid":1511,"task":"crutest"} {"msg":"The guest has requested activation with gen:1","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:24:45.86957561Z","hostname":"w-01JPK385YEKY6MP5MTXXJ43FAT","pid":1511} {"msg":"1513be51-1bbb-4c39-bb4f-8c0b5edcdaf8 active request set","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:24:45.86963326Z","hostname":"w-01JPK385YEKY6MP5MTXXJ43FAT","pid":1511,"session_id":"95612b4d-d53d-4139-a284-dd246b03279b"} {"msg":"sending connect oneshot to client","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:24:45.869639279Z","hostname":"w-01JPK385YEKY6MP5MTXXJ43FAT","pid":1511,"client":"0","":"downstairs","session_id":"95612b4d-d53d-4139-a284-dd246b03279b"} {"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-17T22:24:45.869650057Z","hostname":"w-01JPK385YEKY6MP5MTXXJ43FAT","pid":1511,"client":"0","":"downstairs","session_id":"95612b4d-d53d-4139-a284-dd246b03279b"} {"msg":"sending connect oneshot to client","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:24:45.869655676Z","hostname":"w-01JPK385YEKY6MP5MTXXJ43FAT","pid":1511,"client":"1","":"downstairs","session_id":"95612b4d-d53d-4139-a284-dd246b03279b"} {"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-17T22:24:45.869661555Z","hostname":"w-01JPK385YEKY6MP5MTXXJ43FAT","pid":1511,"client":"1","":"downstairs","session_id":"95612b4d-d53d-4139-a284-dd246b03279b"} {"msg":"sending connect oneshot to client","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:24:45.869674993Z","hostname":"w-01JPK385YEKY6MP5MTXXJ43FAT","pid":1511,"client":"2","":"downstairs","session_id":"95612b4d-d53d-4139-a284-dd246b03279b"} {"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-17T22:24:45.869681732Z","hostname":"w-01JPK385YEKY6MP5MTXXJ43FAT","pid":1511,"client":"2","":"downstairs","session_id":"95612b4d-d53d-4139-a284-dd246b03279b"} {"msg":"connecting to 127.0.0.1:8830","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:24:45.869718536Z","hostname":"w-01JPK385YEKY6MP5MTXXJ43FAT","pid":1511,"":"io task","client":"2","":"downstairs","session_id":"95612b4d-d53d-4139-a284-dd246b03279b"} {"msg":"connecting to 127.0.0.1:8810","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:24:45.869731244Z","hostname":"w-01JPK385YEKY6MP5MTXXJ43FAT","pid":1511,"":"io task","client":"0","":"downstairs","session_id":"95612b4d-d53d-4139-a284-dd246b03279b"} {"msg":"connecting to 127.0.0.1:8820","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:24:45.869742372Z","hostname":"w-01JPK385YEKY6MP5MTXXJ43FAT","pid":1511,"":"io task","client":"1","":"downstairs","session_id":"95612b4d-d53d-4139-a284-dd246b03279b"} {"msg":"ds_connection connected from Ok(127.0.0.1:60409)","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:24:45.869801122Z","hostname":"w-01JPK385YEKY6MP5MTXXJ43FAT","pid":1511,"":"io task","client":"2","":"downstairs","session_id":"95612b4d-d53d-4139-a284-dd246b03279b"} {"msg":"ds_connection connected from Ok(127.0.0.1:53592)","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:24:45.869840976Z","hostname":"w-01JPK385YEKY6MP5MTXXJ43FAT","pid":1511,"":"io task","client":"0","":"downstairs","session_id":"95612b4d-d53d-4139-a284-dd246b03279b"} {"msg":"ds_connection connected from Ok(127.0.0.1:55867)","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:24:45.869883238Z","hostname":"w-01JPK385YEKY6MP5MTXXJ43FAT","pid":1511,"":"io task","client":"1","":"downstairs","session_id":"95612b4d-d53d-4139-a284-dd246b03279b"} {"msg":"version negotiation from state Connecting { state: WaitForPromote, mode: New }","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:24:45.870197406Z","hostname":"w-01JPK385YEKY6MP5MTXXJ43FAT","pid":1511,"client":"0","":"downstairs","session_id":"95612b4d-d53d-4139-a284-dd246b03279b"} {"msg":"version negotiation from state Connecting { state: WaitForPromote, mode: New }","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:24:45.87023576Z","hostname":"w-01JPK385YEKY6MP5MTXXJ43FAT","pid":1511,"client":"2","":"downstairs","session_id":"95612b4d-d53d-4139-a284-dd246b03279b"} {"msg":"version negotiation from state Connecting { state: WaitForPromote, mode: New }","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:24:45.870328684Z","hostname":"w-01JPK385YEKY6MP5MTXXJ43FAT","pid":1511,"client":"1","":"downstairs","session_id":"95612b4d-d53d-4139-a284-dd246b03279b"} {"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-17T22:24:45.870435306Z","hostname":"w-01JPK385YEKY6MP5MTXXJ43FAT","pid":1511,"client":"0","":"downstairs","session_id":"95612b4d-d53d-4139-a284-dd246b03279b"} {"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-17T22:24:45.870467621Z","hostname":"w-01JPK385YEKY6MP5MTXXJ43FAT","pid":1511,"client":"2","":"downstairs","session_id":"95612b4d-d53d-4139-a284-dd246b03279b"} {"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-17T22:24:45.870507384Z","hostname":"w-01JPK385YEKY6MP5MTXXJ43FAT","pid":1511,"client":"1","":"downstairs","session_id":"95612b4d-d53d-4139-a284-dd246b03279b"} {"msg":"Waiting for more clients to be ready","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:24:45.876914615Z","hostname":"w-01JPK385YEKY6MP5MTXXJ43FAT","pid":1511,"session_id":"95612b4d-d53d-4139-a284-dd246b03279b"} {"msg":"Waiting for more clients to be ready","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:24:45.877151616Z","hostname":"w-01JPK385YEKY6MP5MTXXJ43FAT","pid":1511,"session_id":"95612b4d-d53d-4139-a284-dd246b03279b"} {"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-17T22:24:45.87748594Z","hostname":"w-01JPK385YEKY6MP5MTXXJ43FAT","pid":1511,"":"downstairs","":"downstairs","session_id":"95612b4d-d53d-4139-a284-dd246b03279b"} {"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-17T22:24:45.877495848Z","hostname":"w-01JPK385YEKY6MP5MTXXJ43FAT","pid":1511,"":"downstairs","":"downstairs","session_id":"95612b4d-d53d-4139-a284-dd246b03279b"} {"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-17T22:24:45.877501227Z","hostname":"w-01JPK385YEKY6MP5MTXXJ43FAT","pid":1511,"":"downstairs","":"downstairs","session_id":"95612b4d-d53d-4139-a284-dd246b03279b"} {"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-17T22:24:45.877505927Z","hostname":"w-01JPK385YEKY6MP5MTXXJ43FAT","pid":1511,"":"downstairs","":"downstairs","session_id":"95612b4d-d53d-4139-a284-dd246b03279b"} {"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-17T22:24:45.877513765Z","hostname":"w-01JPK385YEKY6MP5MTXXJ43FAT","pid":1511,"":"downstairs","":"downstairs","session_id":"95612b4d-d53d-4139-a284-dd246b03279b"} {"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-17T22:24:45.877517995Z","hostname":"w-01JPK385YEKY6MP5MTXXJ43FAT","pid":1511,"":"downstairs","":"downstairs","session_id":"95612b4d-d53d-4139-a284-dd246b03279b"} {"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-17T22:24:45.877522024Z","hostname":"w-01JPK385YEKY6MP5MTXXJ43FAT","pid":1511,"":"downstairs","":"downstairs","session_id":"95612b4d-d53d-4139-a284-dd246b03279b"} {"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-17T22:24:45.877526003Z","hostname":"w-01JPK385YEKY6MP5MTXXJ43FAT","pid":1511,"":"downstairs","":"downstairs","session_id":"95612b4d-d53d-4139-a284-dd246b03279b"} {"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-17T22:24:45.877530013Z","hostname":"w-01JPK385YEKY6MP5MTXXJ43FAT","pid":1511,"":"downstairs","":"downstairs","session_id":"95612b4d-d53d-4139-a284-dd246b03279b"} {"msg":"Max found gen is 1","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:24:45.877534062Z","hostname":"w-01JPK385YEKY6MP5MTXXJ43FAT","pid":1511,"":"downstairs","":"downstairs","session_id":"95612b4d-d53d-4139-a284-dd246b03279b"} {"msg":"Generation requested: 1 >= found:1","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:24:45.877541041Z","hostname":"w-01JPK385YEKY6MP5MTXXJ43FAT","pid":1511,"":"downstairs","":"downstairs","session_id":"95612b4d-d53d-4139-a284-dd246b03279b"} {"msg":"Next flush: 1","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:24:45.87754812Z","hostname":"w-01JPK385YEKY6MP5MTXXJ43FAT","pid":1511,"":"downstairs","":"downstairs","session_id":"95612b4d-d53d-4139-a284-dd246b03279b"} {"msg":"All extents match","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:24:45.877555169Z","hostname":"w-01JPK385YEKY6MP5MTXXJ43FAT","pid":1511,"":"downstairs","":"downstairs","session_id":"95612b4d-d53d-4139-a284-dd246b03279b"} {"msg":"No downstairs reconciliation required","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:24:45.877562337Z","hostname":"w-01JPK385YEKY6MP5MTXXJ43FAT","pid":1511,"session_id":"95612b4d-d53d-4139-a284-dd246b03279b"} {"msg":"Transition from WaitQuorum to Active","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:24:45.877568496Z","hostname":"w-01JPK385YEKY6MP5MTXXJ43FAT","pid":1511,"client":"0","":"downstairs","session_id":"95612b4d-d53d-4139-a284-dd246b03279b"} {"msg":"Transition from WaitQuorum to Active","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:24:45.877575445Z","hostname":"w-01JPK385YEKY6MP5MTXXJ43FAT","pid":1511,"client":"1","":"downstairs","session_id":"95612b4d-d53d-4139-a284-dd246b03279b"} {"msg":"Transition from WaitQuorum to Active","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:24:45.877582554Z","hostname":"w-01JPK385YEKY6MP5MTXXJ43FAT","pid":1511,"client":"2","":"downstairs","session_id":"95612b4d-d53d-4139-a284-dd246b03279b"} {"msg":"All required reconciliation work is completed","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:24:45.877588603Z","hostname":"w-01JPK385YEKY6MP5MTXXJ43FAT","pid":1511,"session_id":"95612b4d-d53d-4139-a284-dd246b03279b"} {"msg":"Set Downstairs and Upstairs active after reconciliation","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:24:45.877592852Z","hostname":"w-01JPK385YEKY6MP5MTXXJ43FAT","pid":1511,"session_id":"95612b4d-d53d-4139-a284-dd246b03279b"} {"msg":"1513be51-1bbb-4c39-bb4f-8c0b5edcdaf8 is now active with session: 95612b4d-d53d-4139-a284-dd246b03279b","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:24:45.877596711Z","hostname":"w-01JPK385YEKY6MP5MTXXJ43FAT","pid":1511,"session_id":"95612b4d-d53d-4139-a284-dd246b03279b"} {"msg":"Set Active after no reconciliation","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:24:45.877603461Z","hostname":"w-01JPK385YEKY6MP5MTXXJ43FAT","pid":1511,"session_id":"95612b4d-d53d-4139-a284-dd246b03279b"} {"msg":"The guest has finished waiting for activation with:1","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:24:45.877609919Z","hostname":"w-01JPK385YEKY6MP5MTXXJ43FAT","pid":1511} {"msg":"Activated sub_volume 1513be51-1bbb-4c39-bb4f-8c0b5edcdaf8","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:24:45.877640734Z","hostname":"w-01JPK385YEKY6MP5MTXXJ43FAT","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:21 States: Active Active Active JOBID ACK TYPE BKS/EXT DS:0 DS:1 DS:2 REPLAY 104760 Acked Write 256 Done Done Done false 104761 Acked Write 256 Done Done Done false 104762 Acked Write 256 Done Done Done false 104763 Acked Write 256 Done Done Done false 104764 Acked Write 256 Done Done Done false 104765 Acked Write 256 Done Done Done false 104766 Acked Write 256 Done Done Done false 104767 Acked Write 256 Done Done Done false 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 Flush 0 Done Done Sent false STATES DS:0 DS:1 DS:2 TOTAL Sent 0 0 1 1 Done 21 21 20 62 Skipped 0 0 0 0 Error 0 0 0 0 Last Flush: Some(JobId(104780)) Some(JobId(104780)) None Downstairs last five completed: 104759 104758 104757 104756 104755 Upstairs last five completed: 104780 104759 104779 104778 104777 CLIENT: Up:0 ds:21 act:3 ---------------------------------------------------------------- Crucible gen:1 GIO:true work queues: Upstairs:0 downstairs:0 Downstairs last five completed: 104780 104779 104778 104777 104776 Upstairs last five completed: 104780 104759 104779 104778 104777 CLIENT: Up:0 ds:0 act:3 CLIENT: All crucible jobs finished, exiting program