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 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
Make output file at "/tmp/dsc/downstairs-8810.txt"
[8810][0] initial start wait reports Starting
Downstairs /var/tmp/dsc/8830 port 8830 PID:Some(1494)
[8830][2] initial start wait reports Running
Downstairs /var/tmp/dsc/8810 port 8810 PID:Some(1495)
[8810][0] initial start wait reports Running
Nov 08 20:25:52.010 INFO listening, local_addr: 127.0.0.1:9998
Downstairs /var/tmp/dsc/8820 port 8820 PID:Some(1496)
[8820][1] initial start wait reports Running
All downstairs are running
Control access at:127.0.0.1:9998
Nov 08 20:25:57.064 INFO accepted connection, remote_addr: 127.0.0.1:37512, 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
Nov 08 20:25:57.065 INFO request completed, latency_us: 159, response_code: 204, uri: /disablerestart/all, method: POST, req_id: 97c843cc-2e0a-4fa3-b8ad-fcab30938e6e[8820] Disable keep_running
, [8830] Disable keep_running
remote_addr: 127.0.0.1:37512, local_addr: 127.0.0.1:9998
Nov 08 20:27:27.296 INFO accepted connection, remote_addr: 127.0.0.1:50484, local_addr: 127.0.0.1:9998
Main task has work to do, go find it
got dsc Shutdown
Shutdown
[8810] Disable keep_running
Shut it down
[8810] Got stop action so:false kr:false
Nov 08 20:27:27.297 INFO request completed, latency_us: 84, response_code: 204, uri: /shutdown, method: POST, req_id: 1450a2e5-5947-4870-abea-2831dacfe16e, remote_addr: 127.0.0.1:50484, local_addr: 127.0.0.1:9998
[8820] Disable keep_running
[8830] Disable keep_running
[8820] Got stop action so:false kr:false
[8830] 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: \"0fd98d0d5d909611f8b408ccda2559d35fe117bb\",\n    git_commit_timestamp: \"2024-11-08T20:05:44.000000000Z\",\n    git_branch: \"mkeeter/drop-skipped-backpressure-guard\",\n    rustc_semver: \"1.82.0\",\n    rustc_channel: \"stable\",\n    rustc_host_triple: \"x86_64-unknown-illumos\",\n    rustc_commit_sha: \"f6e511eec7342f59a25f7c0534f1dbea00d01b14\",\n    cargo_triple: \"x86_64-unknown-illumos\",\n    debug: false,\n    opt_level: 3,\n}","v":0,"name":"crucible","level":30,"time":"2024-11-08T20:25:57.136357456Z","hostname":"bmat-EVT22200007-00004825","pid":1499}
{"msg":"Upstairs <-> Downstairs Message Version: 12","v":0,"name":"crucible","level":30,"time":"2024-11-08T20:25:57.136367295Z","hostname":"bmat-EVT22200007-00004825","pid":1499}
{"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":"2024-11-08T20:25:57.136374991Z","hostname":"bmat-EVT22200007-00004825","pid":1499}
{"msg":"Crucible 7428c836-1df5-4e33-897b-f234b72a54ee has session id: b72efc05-0c44-4df2-8a66-7d5b7d7824b0","v":0,"name":"crucible","level":30,"time":"2024-11-08T20:25:57.136917519Z","hostname":"bmat-EVT22200007-00004825","pid":1499,"session_id":"b72efc05-0c44-4df2-8a66-7d5b7d7824b0"}
{"msg":"Upstairs opts: Upstairs UUID: 7428c836-1df5-4e33-897b-f234b72a54ee, 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":"2024-11-08T20:25:57.136942338Z","hostname":"bmat-EVT22200007-00004825","pid":1499,"session_id":"b72efc05-0c44-4df2-8a66-7d5b7d7824b0"}
{"msg":"Crucible stats registered with UUID: 7428c836-1df5-4e33-897b-f234b72a54ee","v":0,"name":"crucible","level":30,"time":"2024-11-08T20:25:57.13695847Z","hostname":"bmat-EVT22200007-00004825","pid":1499,"session_id":"b72efc05-0c44-4df2-8a66-7d5b7d7824b0"}
{"msg":"Downstairs in volume = 3","v":0,"name":"crucible","level":30,"time":"2024-11-08T20:25:57.175971319Z","hostname":"bmat-EVT22200007-00004825","pid":1499,"task":"crutest"}
{"msg":"The guest has requested activation with gen:1","v":0,"name":"crucible","level":30,"time":"2024-11-08T20:25:57.175999545Z","hostname":"bmat-EVT22200007-00004825","pid":1499}
{"msg":"7428c836-1df5-4e33-897b-f234b72a54ee active request set","v":0,"name":"crucible","level":30,"time":"2024-11-08T20:25:57.176006168Z","hostname":"bmat-EVT22200007-00004825","pid":1499,"session_id":"b72efc05-0c44-4df2-8a66-7d5b7d7824b0"}
{"msg":"sending connect oneshot to client","v":0,"name":"crucible","level":30,"time":"2024-11-08T20:25:57.176019294Z","hostname":"bmat-EVT22200007-00004825","pid":1499,"client":"0","":"downstairs","session_id":"b72efc05-0c44-4df2-8a66-7d5b7d7824b0"}
{"msg":"client set_active_request while in New; waiting...","v":0,"name":"crucible","level":30,"time":"2024-11-08T20:25:57.176041257Z","hostname":"bmat-EVT22200007-00004825","pid":1499,"client":"0","":"downstairs","session_id":"b72efc05-0c44-4df2-8a66-7d5b7d7824b0"}
{"msg":"sending connect oneshot to client","v":0,"name":"crucible","level":30,"time":"2024-11-08T20:25:57.176052449Z","hostname":"bmat-EVT22200007-00004825","pid":1499,"client":"1","":"downstairs","session_id":"b72efc05-0c44-4df2-8a66-7d5b7d7824b0"}
{"msg":"client set_active_request while in New; waiting...","v":0,"name":"crucible","level":30,"time":"2024-11-08T20:25:57.176063701Z","hostname":"bmat-EVT22200007-00004825","pid":1499,"client":"1","":"downstairs","session_id":"b72efc05-0c44-4df2-8a66-7d5b7d7824b0"}
{"msg":"sending connect oneshot to client","v":0,"name":"crucible","level":30,"time":"2024-11-08T20:25:57.176074442Z","hostname":"bmat-EVT22200007-00004825","pid":1499,"client":"2","":"downstairs","session_id":"b72efc05-0c44-4df2-8a66-7d5b7d7824b0"}
{"msg":"client set_active_request while in New; waiting...","v":0,"name":"crucible","level":30,"time":"2024-11-08T20:25:57.176083891Z","hostname":"bmat-EVT22200007-00004825","pid":1499,"client":"2","":"downstairs","session_id":"b72efc05-0c44-4df2-8a66-7d5b7d7824b0"}
{"msg":"connecting to 127.0.0.1:8830","v":0,"name":"crucible","level":30,"time":"2024-11-08T20:25:57.176092919Z","hostname":"bmat-EVT22200007-00004825","pid":1499,"":"io task","client":"2","":"downstairs","session_id":"b72efc05-0c44-4df2-8a66-7d5b7d7824b0"}
{"msg":"connecting to 127.0.0.1:8810","v":0,"name":"crucible","level":30,"time":"2024-11-08T20:25:57.176221923Z","hostname":"bmat-EVT22200007-00004825","pid":1499,"":"io task","client":"0","":"downstairs","session_id":"b72efc05-0c44-4df2-8a66-7d5b7d7824b0"}
{"msg":"ds_connection connected from Ok(127.0.0.1:49991)","v":0,"name":"crucible","level":30,"time":"2024-11-08T20:25:57.176239838Z","hostname":"bmat-EVT22200007-00004825","pid":1499,"":"io task","client":"2","":"downstairs","session_id":"b72efc05-0c44-4df2-8a66-7d5b7d7824b0"}
{"msg":"connecting to 127.0.0.1:8820","v":0,"name":"crucible","level":30,"time":"2024-11-08T20:25:57.176252062Z","hostname":"bmat-EVT22200007-00004825","pid":1499,"":"io task","client":"1","":"downstairs","session_id":"b72efc05-0c44-4df2-8a66-7d5b7d7824b0"}
{"msg":"ds_connection connected from Ok(127.0.0.1:64049)","v":0,"name":"crucible","level":30,"time":"2024-11-08T20:25:57.176347951Z","hostname":"bmat-EVT22200007-00004825","pid":1499,"":"io task","client":"0","":"downstairs","session_id":"b72efc05-0c44-4df2-8a66-7d5b7d7824b0"}
{"msg":"ds_connection connected from Ok(127.0.0.1:34067)","v":0,"name":"crucible","level":30,"time":"2024-11-08T20:25:57.176366307Z","hostname":"bmat-EVT22200007-00004825","pid":1499,"":"io task","client":"1","":"downstairs","session_id":"b72efc05-0c44-4df2-8a66-7d5b7d7824b0"}
{"msg":"ds_transition from New to WaitActive","v":0,"name":"crucible","level":30,"time":"2024-11-08T20:25:57.177132096Z","hostname":"bmat-EVT22200007-00004825","pid":1499,"client":"0","":"downstairs","session_id":"b72efc05-0c44-4df2-8a66-7d5b7d7824b0"}
{"msg":"[0] Transition from New to WaitActive","v":0,"name":"crucible","level":30,"time":"2024-11-08T20:25:57.177169159Z","hostname":"bmat-EVT22200007-00004825","pid":1499,"client":"0","":"downstairs","session_id":"b72efc05-0c44-4df2-8a66-7d5b7d7824b0"}
{"msg":"ds_transition from New to WaitActive","v":0,"name":"crucible","level":30,"time":"2024-11-08T20:25:57.177177415Z","hostname":"bmat-EVT22200007-00004825","pid":1499,"client":"1","":"downstairs","session_id":"b72efc05-0c44-4df2-8a66-7d5b7d7824b0"}
{"msg":"[1] Transition from New to WaitActive","v":0,"name":"crucible","level":30,"time":"2024-11-08T20:25:57.177185291Z","hostname":"bmat-EVT22200007-00004825","pid":1499,"client":"1","":"downstairs","session_id":"b72efc05-0c44-4df2-8a66-7d5b7d7824b0"}
{"msg":"ds_transition from New to WaitActive","v":0,"name":"crucible","level":30,"time":"2024-11-08T20:25:57.177192415Z","hostname":"bmat-EVT22200007-00004825","pid":1499,"client":"2","":"downstairs","session_id":"b72efc05-0c44-4df2-8a66-7d5b7d7824b0"}
{"msg":"[2] Transition from New to WaitActive","v":0,"name":"crucible","level":30,"time":"2024-11-08T20:25:57.17720009Z","hostname":"bmat-EVT22200007-00004825","pid":1499,"client":"2","":"downstairs","session_id":"b72efc05-0c44-4df2-8a66-7d5b7d7824b0"}
{"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":"2024-11-08T20:25:57.177557604Z","hostname":"bmat-EVT22200007-00004825","pid":1499,"client":"1","":"downstairs","session_id":"b72efc05-0c44-4df2-8a66-7d5b7d7824b0"}
{"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":"2024-11-08T20:25:57.177572022Z","hostname":"bmat-EVT22200007-00004825","pid":1499,"client":"0","":"downstairs","session_id":"b72efc05-0c44-4df2-8a66-7d5b7d7824b0"}
{"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":"2024-11-08T20:25:57.17758591Z","hostname":"bmat-EVT22200007-00004825","pid":1499,"client":"2","":"downstairs","session_id":"b72efc05-0c44-4df2-8a66-7d5b7d7824b0"}
{"msg":"ds_transition from WaitActive to WaitQuorum","v":0,"name":"crucible","level":30,"time":"2024-11-08T20:25:57.188611799Z","hostname":"bmat-EVT22200007-00004825","pid":1499,"client":"0","":"downstairs","session_id":"b72efc05-0c44-4df2-8a66-7d5b7d7824b0"}
{"msg":"[0] Transition from WaitActive to WaitQuorum","v":0,"name":"crucible","level":30,"time":"2024-11-08T20:25:57.188636187Z","hostname":"bmat-EVT22200007-00004825","pid":1499,"client":"0","":"downstairs","session_id":"b72efc05-0c44-4df2-8a66-7d5b7d7824b0"}
{"msg":"Waiting for more clients to be ready","v":0,"name":"crucible","level":30,"time":"2024-11-08T20:25:57.188643812Z","hostname":"bmat-EVT22200007-00004825","pid":1499,"session_id":"b72efc05-0c44-4df2-8a66-7d5b7d7824b0"}
{"msg":"ds_transition from WaitActive to WaitQuorum","v":0,"name":"crucible","level":30,"time":"2024-11-08T20:25:57.188658371Z","hostname":"bmat-EVT22200007-00004825","pid":1499,"client":"1","":"downstairs","session_id":"b72efc05-0c44-4df2-8a66-7d5b7d7824b0"}
{"msg":"[1] Transition from WaitActive to WaitQuorum","v":0,"name":"crucible","level":30,"time":"2024-11-08T20:25:57.188665605Z","hostname":"bmat-EVT22200007-00004825","pid":1499,"client":"1","":"downstairs","session_id":"b72efc05-0c44-4df2-8a66-7d5b7d7824b0"}
{"msg":"Waiting for more clients to be ready","v":0,"name":"crucible","level":30,"time":"2024-11-08T20:25:57.188672088Z","hostname":"bmat-EVT22200007-00004825","pid":1499,"session_id":"b72efc05-0c44-4df2-8a66-7d5b7d7824b0"}
{"msg":"ds_transition from WaitActive to WaitQuorum","v":0,"name":"crucible","level":30,"time":"2024-11-08T20:25:57.189488306Z","hostname":"bmat-EVT22200007-00004825","pid":1499,"client":"2","":"downstairs","session_id":"b72efc05-0c44-4df2-8a66-7d5b7d7824b0"}
{"msg":"[2] Transition from WaitActive to WaitQuorum","v":0,"name":"crucible","level":30,"time":"2024-11-08T20:25:57.189503055Z","hostname":"bmat-EVT22200007-00004825","pid":1499,"client":"2","":"downstairs","session_id":"b72efc05-0c44-4df2-8a66-7d5b7d7824b0"}
{"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":"2024-11-08T20:25:57.189510119Z","hostname":"bmat-EVT22200007-00004825","pid":1499,"":"downstairs","":"downstairs","session_id":"b72efc05-0c44-4df2-8a66-7d5b7d7824b0"}
{"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":"2024-11-08T20:25:57.189523565Z","hostname":"bmat-EVT22200007-00004825","pid":1499,"":"downstairs","":"downstairs","session_id":"b72efc05-0c44-4df2-8a66-7d5b7d7824b0"}
{"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":"2024-11-08T20:25:57.189532082Z","hostname":"bmat-EVT22200007-00004825","pid":1499,"":"downstairs","":"downstairs","session_id":"b72efc05-0c44-4df2-8a66-7d5b7d7824b0"}
{"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":"2024-11-08T20:25:57.189539476Z","hostname":"bmat-EVT22200007-00004825","pid":1499,"":"downstairs","":"downstairs","session_id":"b72efc05-0c44-4df2-8a66-7d5b7d7824b0"}
{"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":"2024-11-08T20:25:57.18954643Z","hostname":"bmat-EVT22200007-00004825","pid":1499,"":"downstairs","":"downstairs","session_id":"b72efc05-0c44-4df2-8a66-7d5b7d7824b0"}
{"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":"2024-11-08T20:25:57.189553504Z","hostname":"bmat-EVT22200007-00004825","pid":1499,"":"downstairs","":"downstairs","session_id":"b72efc05-0c44-4df2-8a66-7d5b7d7824b0"}
{"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":"2024-11-08T20:25:57.189560568Z","hostname":"bmat-EVT22200007-00004825","pid":1499,"":"downstairs","":"downstairs","session_id":"b72efc05-0c44-4df2-8a66-7d5b7d7824b0"}
{"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":"2024-11-08T20:25:57.189567221Z","hostname":"bmat-EVT22200007-00004825","pid":1499,"":"downstairs","":"downstairs","session_id":"b72efc05-0c44-4df2-8a66-7d5b7d7824b0"}
{"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":"2024-11-08T20:25:57.189573784Z","hostname":"bmat-EVT22200007-00004825","pid":1499,"":"downstairs","":"downstairs","session_id":"b72efc05-0c44-4df2-8a66-7d5b7d7824b0"}
{"msg":"Max found gen is 1","v":0,"name":"crucible","level":30,"time":"2024-11-08T20:25:57.189580287Z","hostname":"bmat-EVT22200007-00004825","pid":1499,"":"downstairs","":"downstairs","session_id":"b72efc05-0c44-4df2-8a66-7d5b7d7824b0"}
{"msg":"Generation requested: 1 >= found:1","v":0,"name":"crucible","level":30,"time":"2024-11-08T20:25:57.18958685Z","hostname":"bmat-EVT22200007-00004825","pid":1499,"":"downstairs","":"downstairs","session_id":"b72efc05-0c44-4df2-8a66-7d5b7d7824b0"}
{"msg":"Next flush: 1","v":0,"name":"crucible","level":30,"time":"2024-11-08T20:25:57.189593363Z","hostname":"bmat-EVT22200007-00004825","pid":1499,"":"downstairs","":"downstairs","session_id":"b72efc05-0c44-4df2-8a66-7d5b7d7824b0"}
{"msg":"All extents match","v":0,"name":"crucible","level":30,"time":"2024-11-08T20:25:57.189599936Z","hostname":"bmat-EVT22200007-00004825","pid":1499,"":"downstairs","":"downstairs","session_id":"b72efc05-0c44-4df2-8a66-7d5b7d7824b0"}
{"msg":"No downstairs reconciliation required","v":0,"name":"crucible","level":30,"time":"2024-11-08T20:25:57.189612901Z","hostname":"bmat-EVT22200007-00004825","pid":1499,"session_id":"b72efc05-0c44-4df2-8a66-7d5b7d7824b0"}
{"msg":"Transition from WaitQuorum to Active","v":0,"name":"crucible","level":30,"time":"2024-11-08T20:25:57.189618783Z","hostname":"bmat-EVT22200007-00004825","pid":1499,"client":"0","":"downstairs","session_id":"b72efc05-0c44-4df2-8a66-7d5b7d7824b0"}
{"msg":"Transition from WaitQuorum to Active","v":0,"name":"crucible","level":30,"time":"2024-11-08T20:25:57.189625175Z","hostname":"bmat-EVT22200007-00004825","pid":1499,"client":"1","":"downstairs","session_id":"b72efc05-0c44-4df2-8a66-7d5b7d7824b0"}
{"msg":"Transition from WaitQuorum to Active","v":0,"name":"crucible","level":30,"time":"2024-11-08T20:25:57.189631808Z","hostname":"bmat-EVT22200007-00004825","pid":1499,"client":"2","":"downstairs","session_id":"b72efc05-0c44-4df2-8a66-7d5b7d7824b0"}
{"msg":"All required reconciliation work is completed","v":0,"name":"crucible","level":30,"time":"2024-11-08T20:25:57.189638481Z","hostname":"bmat-EVT22200007-00004825","pid":1499,"session_id":"b72efc05-0c44-4df2-8a66-7d5b7d7824b0"}
{"msg":"Set Downstairs and Upstairs active after reconciliation","v":0,"name":"crucible","level":30,"time":"2024-11-08T20:25:57.189643912Z","hostname":"bmat-EVT22200007-00004825","pid":1499,"session_id":"b72efc05-0c44-4df2-8a66-7d5b7d7824b0"}
{"msg":"7428c836-1df5-4e33-897b-f234b72a54ee is now active with session: b72efc05-0c44-4df2-8a66-7d5b7d7824b0","v":0,"name":"crucible","level":30,"time":"2024-11-08T20:25:57.189649954Z","hostname":"bmat-EVT22200007-00004825","pid":1499,"session_id":"b72efc05-0c44-4df2-8a66-7d5b7d7824b0"}
{"msg":"Set Active after no reconciliation","v":0,"name":"crucible","level":30,"time":"2024-11-08T20:25:57.189655475Z","hostname":"bmat-EVT22200007-00004825","pid":1499,"session_id":"b72efc05-0c44-4df2-8a66-7d5b7d7824b0"}
{"msg":"The guest has finished waiting for activation with:1","v":0,"name":"crucible","level":30,"time":"2024-11-08T20:25:57.189714702Z","hostname":"bmat-EVT22200007-00004825","pid":1499}
Wait for a query_work_queue command to finish before sending IO
Region: 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: 103574 103573 103572 103571 103570
Upstairs last five completed:   103574 103573 103572 103571 103570
CLIENT: Up:0 ds:0 act:3
CLIENT: All crucible jobs finished, exiting program