/input/rbuild/work Create region with ES:16384 EC:640 BS:4096 Creating region directory at: /var/tmp/dsc Creating dsc directory at: /tmp/dsc Downstairs region 0 created at /var/tmp/dsc/8810 in 0.906888 Downstairs region 1 created at /var/tmp/dsc/8820 in 0.6869705 Downstairs region 2 created at /var/tmp/dsc/8830 in 0.73164546 Created 3 regions Using existing output directory "/tmp/dsc" Update our region info with: Some(RegionExtentInfo { block_size: 4096, blocks_per_extent: 16384, extent_count: 640 }) 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 Starting downstairs at port 8830 Make output file at "/tmp/dsc/downstairs-8810.txt" 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 [8810][0] initial start wait reports Starting [8820][1] initial start wait reports Starting Downstairs /var/tmp/dsc/8810 port 8810 PID:Some(1184) [8810][0] initial start wait reports Running Downstairs /var/tmp/dsc/8830 port 8830 PID:Some(1185) [8830][2] initial start wait reports Running Downstairs /var/tmp/dsc/8820 port 8820 PID:Some(1186) [8820][1] initial start wait reports Running All downstairs are running Sep 26 19:44:18.985 INFO listening, local_addr: 127.0.0.1:9998 Control access at:127.0.0.1:9998 1184 1185 1186 Sep 26 19:44:24.024 INFO accepted connection, remote_addr: 127.0.0.1:43227, local_addr: 127.0.0.1:9998 Main task has work to do, go find it got dsc DisableRestartAll disable restart on all: 3 Sep 26 19:44:24.024 INFO request completed, latency_us[8810] Disable keep_running :[8820] Disable keep_running [8830] Disable keep_running 181, response_code: 204, uri: /disablerestart/all, method: POST, req_id: 3a3d3170-06dc-448d-8661-555a02a0b452, remote_addr: 127.0.0.1:43227, local_addr: 127.0.0.1:9998 A new loop begins at September 26, 2024 at 07:44:24 PM UTC /var/tmp/bins/crutest perf -g 1 -t 127.0.0.1:8810 -t 127.0.0.1:8820 -t 127.0.0.1:8830 -c 30000 -q --write-loops 2 --read-loops 2 --perf-out /tmp/perf-ES-16384-EC-640.csv {"msg":"look at: http://127.0.0.1:12810 ","v":0,"name":"crucible","level":30,"time":"2024-09-26T19:44:24.048172276Z","hostname":"w-01J8QXQECXY8DGRWH5ED8Q50RF","pid":1194,"task":"crutest"} {"msg":"RI is: RegionDefinition { block_size: 4096, extent_size: Block { value: 16384, shift: 12 }, extent_count: 640, uuid: 12345678-0000-0000-0000-000000008810, encrypted: false, database_read_version: 1, database_write_version: 1 }","v":0,"name":"crucible","level":30,"time":"2024-09-26T19:44:24.089001801Z","hostname":"w-01J8QXQECXY8DGRWH5ED8Q50RF","pid":1194,"task":"crutest"} {"msg":"Upstairs starts","v":0,"name":"crucible","level":30,"time":"2024-09-26T19:44:24.089638316Z","hostname":"w-01J8QXQECXY8DGRWH5ED8Q50RF","pid":1194} {"msg":"Crucible Version: BuildInfo {\n version: \"0.0.1\",\n git_sha: \"8e980c14034391699f5d7f17cfb24177d0aafaf2\",\n git_commit_timestamp: \"2024-09-26T19:23:10.000000000Z\",\n git_branch: \"alan/crutest-meet-dsc\",\n rustc_semver: \"1.80.0\",\n rustc_channel: \"stable\",\n rustc_host_triple: \"x86_64-unknown-illumos\",\n rustc_commit_sha: \"051478957371ee0084a7c0913941d2a8c4757bb9\",\n cargo_triple: \"x86_64-unknown-illumos\",\n debug: false,\n opt_level: 3,\n}","v":0,"name":"crucible","level":30,"time":"2024-09-26T19:44:24.08967618Z","hostname":"w-01J8QXQECXY8DGRWH5ED8Q50RF","pid":1194} {"msg":"Upstairs <-> Downstairs Message Version: 11","v":0,"name":"crucible","level":30,"time":"2024-09-26T19:44:24.089689377Z","hostname":"w-01J8QXQECXY8DGRWH5ED8Q50RF","pid":1194} {"msg":"Using region definition RegionDefinition { block_size: 4096, extent_size: Block { value: 16384, shift: 12 }, extent_count: 640, uuid: 00000000-0000-0000-0000-000000000000, encrypted: false, database_read_version: 1, database_write_version: 1 }","v":0,"name":"crucible","level":30,"time":"2024-09-26T19:44:24.089693887Z","hostname":"w-01J8QXQECXY8DGRWH5ED8Q50RF","pid":1194} {"msg":"Crucible acd32d68-4aac-4b9a-a812-435ae08f73bf has session id: 38cb9fea-9855-4546-983a-af874e7d8e21","v":0,"name":"crucible","level":30,"time":"2024-09-26T19:44:24.090107468Z","hostname":"w-01J8QXQECXY8DGRWH5ED8Q50RF","pid":1194,"session_id":"38cb9fea-9855-4546-983a-af874e7d8e21"} {"msg":"Upstairs opts: Upstairs UUID: acd32d68-4aac-4b9a-a812-435ae08f73bf, 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-09-26T19:44:24.090178487Z","hostname":"w-01J8QXQECXY8DGRWH5ED8Q50RF","pid":1194,"session_id":"38cb9fea-9855-4546-983a-af874e7d8e21"} {"msg":"Crucible stats registered with UUID: acd32d68-4aac-4b9a-a812-435ae08f73bf","v":0,"name":"crucible","level":30,"time":"2024-09-26T19:44:24.090199683Z","hostname":"w-01J8QXQECXY8DGRWH5ED8Q50RF","pid":1194,"session_id":"38cb9fea-9855-4546-983a-af874e7d8e21"} {"msg":"The guest has requested activation with gen:1","v":0,"name":"crucible","level":30,"time":"2024-09-26T19:44:24.122453533Z","hostname":"w-01J8QXQECXY8DGRWH5ED8Q50RF","pid":1194} {"msg":"acd32d68-4aac-4b9a-a812-435ae08f73bf active request set","v":0,"name":"crucible","level":30,"time":"2024-09-26T19:44:24.12247249Z","hostname":"w-01J8QXQECXY8DGRWH5ED8Q50RF","pid":1194,"session_id":"38cb9fea-9855-4546-983a-af874e7d8e21"} {"msg":"sending connect oneshot to client","v":0,"name":"crucible","level":30,"time":"2024-09-26T19:44:24.122492477Z","hostname":"w-01J8QXQECXY8DGRWH5ED8Q50RF","pid":1194,"client":"0","":"downstairs","session_id":"38cb9fea-9855-4546-983a-af874e7d8e21"} {"msg":"client set_active_request while in New; waiting...","v":0,"name":"crucible","level":30,"time":"2024-09-26T19:44:24.122520972Z","hostname":"w-01J8QXQECXY8DGRWH5ED8Q50RF","pid":1194,"client":"0","":"downstairs","session_id":"38cb9fea-9855-4546-983a-af874e7d8e21"} {"msg":"sending connect oneshot to client","v":0,"name":"crucible","level":30,"time":"2024-09-26T19:44:24.12253281Z","hostname":"w-01J8QXQECXY8DGRWH5ED8Q50RF","pid":1194,"client":"1","":"downstairs","session_id":"38cb9fea-9855-4546-983a-af874e7d8e21"} {"msg":"client set_active_request while in New; waiting...","v":0,"name":"crucible","level":30,"time":"2024-09-26T19:44:24.122543138Z","hostname":"w-01J8QXQECXY8DGRWH5ED8Q50RF","pid":1194,"client":"1","":"downstairs","session_id":"38cb9fea-9855-4546-983a-af874e7d8e21"} {"msg":"sending connect oneshot to client","v":0,"name":"crucible","level":30,"time":"2024-09-26T19:44:24.122554696Z","hostname":"w-01J8QXQECXY8DGRWH5ED8Q50RF","pid":1194,"client":"2","":"downstairs","session_id":"38cb9fea-9855-4546-983a-af874e7d8e21"} {"msg":"client set_active_request while in New; waiting...","v":0,"name":"crucible","level":30,"time":"2024-09-26T19:44:24.122567264Z","hostname":"w-01J8QXQECXY8DGRWH5ED8Q50RF","pid":1194,"client":"2","":"downstairs","session_id":"38cb9fea-9855-4546-983a-af874e7d8e21"} {"msg":"connecting to 127.0.0.1:8810","v":0,"name":"crucible","level":30,"time":"2024-09-26T19:44:24.122667548Z","hostname":"w-01J8QXQECXY8DGRWH5ED8Q50RF","pid":1194,"":"io task","client":"0","":"downstairs","session_id":"38cb9fea-9855-4546-983a-af874e7d8e21"} {"msg":"connecting to 127.0.0.1:8830","v":0,"name":"crucible","level":30,"time":"2024-09-26T19:44:24.122751974Z","hostname":"w-01J8QXQECXY8DGRWH5ED8Q50RF","pid":1194,"":"io task","client":"2","":"downstairs","session_id":"38cb9fea-9855-4546-983a-af874e7d8e21"} {"msg":"connecting to 127.0.0.1:8820","v":0,"name":"crucible","level":30,"time":"2024-09-26T19:44:24.122788008Z","hostname":"w-01J8QXQECXY8DGRWH5ED8Q50RF","pid":1194,"":"io task","client":"1","":"downstairs","session_id":"38cb9fea-9855-4546-983a-af874e7d8e21"} {"msg":"ds_connection connected from Ok(127.0.0.1:58268)","v":0,"name":"crucible","level":30,"time":"2024-09-26T19:44:24.122876193Z","hostname":"w-01J8QXQECXY8DGRWH5ED8Q50RF","pid":1194,"":"io task","client":"1","":"downstairs","session_id":"38cb9fea-9855-4546-983a-af874e7d8e21"} {"msg":"ds_connection connected from Ok(127.0.0.1:32801)","v":0,"name":"crucible","level":30,"time":"2024-09-26T19:44:24.122907618Z","hostname":"w-01J8QXQECXY8DGRWH5ED8Q50RF","pid":1194,"":"io task","client":"2","":"downstairs","session_id":"38cb9fea-9855-4546-983a-af874e7d8e21"} {"msg":"ds_connection connected from Ok(127.0.0.1:60726)","v":0,"name":"crucible","level":30,"time":"2024-09-26T19:44:24.122941092Z","hostname":"w-01J8QXQECXY8DGRWH5ED8Q50RF","pid":1194,"":"io task","client":"0","":"downstairs","session_id":"38cb9fea-9855-4546-983a-af874e7d8e21"} {"msg":"ds_transition from New to WaitActive","v":0,"name":"crucible","level":30,"time":"2024-09-26T19:44:24.123737521Z","hostname":"w-01J8QXQECXY8DGRWH5ED8Q50RF","pid":1194,"client":"0","":"downstairs","session_id":"38cb9fea-9855-4546-983a-af874e7d8e21"} {"msg":"[0] Transition from New to WaitActive","v":0,"name":"crucible","level":30,"time":"2024-09-26T19:44:24.123754338Z","hostname":"w-01J8QXQECXY8DGRWH5ED8Q50RF","pid":1194,"client":"0","":"downstairs","session_id":"38cb9fea-9855-4546-983a-af874e7d8e21"} {"msg":"ds_transition from New to WaitActive","v":0,"name":"crucible","level":30,"time":"2024-09-26T19:44:24.123760437Z","hostname":"w-01J8QXQECXY8DGRWH5ED8Q50RF","pid":1194,"client":"1","":"downstairs","session_id":"38cb9fea-9855-4546-983a-af874e7d8e21"} {"msg":"[1] Transition from New to WaitActive","v":0,"name":"crucible","level":30,"time":"2024-09-26T19:44:24.123768146Z","hostname":"w-01J8QXQECXY8DGRWH5ED8Q50RF","pid":1194,"client":"1","":"downstairs","session_id":"38cb9fea-9855-4546-983a-af874e7d8e21"} {"msg":"ds_transition from New to WaitActive","v":0,"name":"crucible","level":30,"time":"2024-09-26T19:44:24.123798741Z","hostname":"w-01J8QXQECXY8DGRWH5ED8Q50RF","pid":1194,"client":"2","":"downstairs","session_id":"38cb9fea-9855-4546-983a-af874e7d8e21"} {"msg":"[2] Transition from New to WaitActive","v":0,"name":"crucible","level":30,"time":"2024-09-26T19:44:24.123809299Z","hostname":"w-01J8QXQECXY8DGRWH5ED8Q50RF","pid":1194,"client":"2","":"downstairs","session_id":"38cb9fea-9855-4546-983a-af874e7d8e21"} {"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-09-26T19:44:24.123955365Z","hostname":"w-01J8QXQECXY8DGRWH5ED8Q50RF","pid":1194,"client":"1","":"downstairs","session_id":"38cb9fea-9855-4546-983a-af874e7d8e21"} {"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-09-26T19:44:24.123973692Z","hostname":"w-01J8QXQECXY8DGRWH5ED8Q50RF","pid":1194,"client":"0","":"downstairs","session_id":"38cb9fea-9855-4546-983a-af874e7d8e21"} {"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-09-26T19:44:24.124062358Z","hostname":"w-01J8QXQECXY8DGRWH5ED8Q50RF","pid":1194,"client":"2","":"downstairs","session_id":"38cb9fea-9855-4546-983a-af874e7d8e21"} {"msg":"ds_transition from WaitActive to WaitQuorum","v":0,"name":"crucible","level":30,"time":"2024-09-26T19:44:24.126124777Z","hostname":"w-01J8QXQECXY8DGRWH5ED8Q50RF","pid":1194,"client":"0","":"downstairs","session_id":"38cb9fea-9855-4546-983a-af874e7d8e21"} {"msg":"[0] Transition from WaitActive to WaitQuorum","v":0,"name":"crucible","level":30,"time":"2024-09-26T19:44:24.126140335Z","hostname":"w-01J8QXQECXY8DGRWH5ED8Q50RF","pid":1194,"client":"0","":"downstairs","session_id":"38cb9fea-9855-4546-983a-af874e7d8e21"} {"msg":"Waiting for more clients to be ready","v":0,"name":"crucible","level":30,"time":"2024-09-26T19:44:24.126144804Z","hostname":"w-01J8QXQECXY8DGRWH5ED8Q50RF","pid":1194,"session_id":"38cb9fea-9855-4546-983a-af874e7d8e21"} {"msg":"ds_transition from WaitActive to WaitQuorum","v":0,"name":"crucible","level":30,"time":"2024-09-26T19:44:24.126148363Z","hostname":"w-01J8QXQECXY8DGRWH5ED8Q50RF","pid":1194,"client":"1","":"downstairs","session_id":"38cb9fea-9855-4546-983a-af874e7d8e21"} {"msg":"[1] Transition from WaitActive to WaitQuorum","v":0,"name":"crucible","level":30,"time":"2024-09-26T19:44:24.126152593Z","hostname":"w-01J8QXQECXY8DGRWH5ED8Q50RF","pid":1194,"client":"1","":"downstairs","session_id":"38cb9fea-9855-4546-983a-af874e7d8e21"} {"msg":"Waiting for more clients to be ready","v":0,"name":"crucible","level":30,"time":"2024-09-26T19:44:24.126156732Z","hostname":"w-01J8QXQECXY8DGRWH5ED8Q50RF","pid":1194,"session_id":"38cb9fea-9855-4546-983a-af874e7d8e21"} {"msg":"ds_transition from WaitActive to WaitQuorum","v":0,"name":"crucible","level":30,"time":"2024-09-26T19:44:24.126488817Z","hostname":"w-01J8QXQECXY8DGRWH5ED8Q50RF","pid":1194,"client":"2","":"downstairs","session_id":"38cb9fea-9855-4546-983a-af874e7d8e21"} {"msg":"[2] Transition from WaitActive to WaitQuorum","v":0,"name":"crucible","level":30,"time":"2024-09-26T19:44:24.126502955Z","hostname":"w-01J8QXQECXY8DGRWH5ED8Q50RF","pid":1194,"client":"2","":"downstairs","session_id":"38cb9fea-9855-4546-983a-af874e7d8e21"} {"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-09-26T19:44:24.126517933Z","hostname":"w-01J8QXQECXY8DGRWH5ED8Q50RF","pid":1194,"":"downstairs","":"downstairs","session_id":"38cb9fea-9855-4546-983a-af874e7d8e21"} {"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-09-26T19:44:24.126528921Z","hostname":"w-01J8QXQECXY8DGRWH5ED8Q50RF","pid":1194,"":"downstairs","":"downstairs","session_id":"38cb9fea-9855-4546-983a-af874e7d8e21"} {"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-09-26T19:44:24.12653357Z","hostname":"w-01J8QXQECXY8DGRWH5ED8Q50RF","pid":1194,"":"downstairs","":"downstairs","session_id":"38cb9fea-9855-4546-983a-af874e7d8e21"} {"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-09-26T19:44:24.126537999Z","hostname":"w-01J8QXQECXY8DGRWH5ED8Q50RF","pid":1194,"":"downstairs","":"downstairs","session_id":"38cb9fea-9855-4546-983a-af874e7d8e21"} {"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-09-26T19:44:24.126542229Z","hostname":"w-01J8QXQECXY8DGRWH5ED8Q50RF","pid":1194,"":"downstairs","":"downstairs","session_id":"38cb9fea-9855-4546-983a-af874e7d8e21"} {"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-09-26T19:44:24.126546368Z","hostname":"w-01J8QXQECXY8DGRWH5ED8Q50RF","pid":1194,"":"downstairs","":"downstairs","session_id":"38cb9fea-9855-4546-983a-af874e7d8e21"} {"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-09-26T19:44:24.126551137Z","hostname":"w-01J8QXQECXY8DGRWH5ED8Q50RF","pid":1194,"":"downstairs","":"downstairs","session_id":"38cb9fea-9855-4546-983a-af874e7d8e21"} {"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-09-26T19:44:24.126555586Z","hostname":"w-01J8QXQECXY8DGRWH5ED8Q50RF","pid":1194,"":"downstairs","":"downstairs","session_id":"38cb9fea-9855-4546-983a-af874e7d8e21"} {"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-09-26T19:44:24.126559675Z","hostname":"w-01J8QXQECXY8DGRWH5ED8Q50RF","pid":1194,"":"downstairs","":"downstairs","session_id":"38cb9fea-9855-4546-983a-af874e7d8e21"} {"msg":"Max found gen is 1","v":0,"name":"crucible","level":30,"time":"2024-09-26T19:44:24.126564255Z","hostname":"w-01J8QXQECXY8DGRWH5ED8Q50RF","pid":1194,"":"downstairs","":"downstairs","session_id":"38cb9fea-9855-4546-983a-af874e7d8e21"} {"msg":"Generation requested: 1 >= found:1","v":0,"name":"crucible","level":30,"time":"2024-09-26T19:44:24.126568874Z","hostname":"w-01J8QXQECXY8DGRWH5ED8Q50RF","pid":1194,"":"downstairs","":"downstairs","session_id":"38cb9fea-9855-4546-983a-af874e7d8e21"} {"msg":"Next flush: 1","v":0,"name":"crucible","level":30,"time":"2024-09-26T19:44:24.126573133Z","hostname":"w-01J8QXQECXY8DGRWH5ED8Q50RF","pid":1194,"":"downstairs","":"downstairs","session_id":"38cb9fea-9855-4546-983a-af874e7d8e21"} {"msg":"All extents match","v":0,"name":"crucible","level":30,"time":"2024-09-26T19:44:24.126577243Z","hostname":"w-01J8QXQECXY8DGRWH5ED8Q50RF","pid":1194,"":"downstairs","":"downstairs","session_id":"38cb9fea-9855-4546-983a-af874e7d8e21"} {"msg":"No downstairs reconciliation required","v":0,"name":"crucible","level":30,"time":"2024-09-26T19:44:24.126581902Z","hostname":"w-01J8QXQECXY8DGRWH5ED8Q50RF","pid":1194,"session_id":"38cb9fea-9855-4546-983a-af874e7d8e21"} {"msg":"Transition from WaitQuorum to Active","v":0,"name":"crucible","level":30,"time":"2024-09-26T19:44:24.126586141Z","hostname":"w-01J8QXQECXY8DGRWH5ED8Q50RF","pid":1194,"client":"0","":"downstairs","session_id":"38cb9fea-9855-4546-983a-af874e7d8e21"} {"msg":"Transition from WaitQuorum to Active","v":0,"name":"crucible","level":30,"time":"2024-09-26T19:44:24.12659023Z","hostname":"w-01J8QXQECXY8DGRWH5ED8Q50RF","pid":1194,"client":"1","":"downstairs","session_id":"38cb9fea-9855-4546-983a-af874e7d8e21"} {"msg":"Transition from WaitQuorum to Active","v":0,"name":"crucible","level":30,"time":"2024-09-26T19:44:24.12659526Z","hostname":"w-01J8QXQECXY8DGRWH5ED8Q50RF","pid":1194,"client":"2","":"downstairs","session_id":"38cb9fea-9855-4546-983a-af874e7d8e21"} {"msg":"All required reconciliation work is completed","v":0,"name":"crucible","level":30,"time":"2024-09-26T19:44:24.126599389Z","hostname":"w-01J8QXQECXY8DGRWH5ED8Q50RF","pid":1194,"session_id":"38cb9fea-9855-4546-983a-af874e7d8e21"} {"msg":"Set Downstairs and Upstairs active after reconciliation","v":0,"name":"crucible","level":30,"time":"2024-09-26T19:44:24.126602959Z","hostname":"w-01J8QXQECXY8DGRWH5ED8Q50RF","pid":1194,"session_id":"38cb9fea-9855-4546-983a-af874e7d8e21"} {"msg":"acd32d68-4aac-4b9a-a812-435ae08f73bf is now active with session: 38cb9fea-9855-4546-983a-af874e7d8e21","v":0,"name":"crucible","level":30,"time":"2024-09-26T19:44:24.126607048Z","hostname":"w-01J8QXQECXY8DGRWH5ED8Q50RF","pid":1194,"session_id":"38cb9fea-9855-4546-983a-af874e7d8e21"} {"msg":"Set Active after no reconciliation","v":0,"name":"crucible","level":30,"time":"2024-09-26T19:44:24.126611137Z","hostname":"w-01J8QXQECXY8DGRWH5ED8Q50RF","pid":1194,"session_id":"38cb9fea-9855-4546-983a-af874e7d8e21"} {"msg":"The guest has finished waiting for activation with:1","v":0,"name":"crucible","level":30,"time":"2024-09-26T19:44:24.126614806Z","hostname":"w-01J8QXQECXY8DGRWH5ED8Q50RF","pid":1194} Wait for a query_work_queue command to finish before sending IO Region: es:16384 ec:640 bs:4096 ts:42949672960 tb:10485760 max_io:256 or 1048576 Perf test TEST SECONDS COUNT DPTH IOPS MEAN P95 P99 MAX ES EC rwrites 5.26 30000 1 5706.09 0.00017 0.00048 0.00124 0.04783 16384 640 rwrites 6.19 30000 1 4844.82 0.00021 0.00116 0.00128 0.08275 16384 640 rreads 5.42 30000 1 5539.88 0.00018 0.00023 0.00029 0.00821 16384 640 rreads 5.36 30000 1 5592.98 0.00018 0.00023 0.00028 0.00821 16384 640 Perf test completed, stop all downstairs Sep 26 19:44:48.628 INFO accepted connection, remote_addr: 127.0.0.1:62850, local_addr: 127.0.0.1:9998 Main task has work to do, go find it got dsc Shutdown Shutdown Shut it down Sep 26 19:44:48.628 INFO request completed, latency_us: 58, response_code[8810] Disable keep_running : 204, uri: /shutdown, [8810] Got stop action so:false kr:false method[8820] Disable keep_running : POST, req_id: c9eeaab0-471c-489e-b4ad-5637aadf88d6, remote_addr: 127.0.0.1:62850, local_addr: 127.0.0.1:9998 [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 [8830] Exited with: ExitStatus(unix_wait_status(9)) [8820] Exited with: ExitStatus(unix_wait_status(9)) [8830][2] reports Exit [8820][1] reports Exit Create region with ES:16384 EC:1280 BS:4096 Removing existing dsc directory "/tmp/dsc" Removing existing region "/var/tmp/dsc" Creating region directory at: /var/tmp/dsc Creating dsc directory at: /tmp/dsc Downstairs region 0 created at /var/tmp/dsc/8810 in 1.2215433 Downstairs region 1 created at /var/tmp/dsc/8820 in 1.2991428 Downstairs region 2 created at /var/tmp/dsc/8830 in 1.2463877 Created 3 regions Using existing output directory "/tmp/dsc" Update our region info with: Some(RegionExtentInfo { block_size: 4096, blocks_per_extent: 16384, extent_count: 1280 }) 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 [8810][0] initial start wait reports Starting Make output file at "/tmp/dsc/downstairs-8810.txt" 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 Make output file at "/tmp/dsc/downstairs-8820.txt" Downstairs /var/tmp/dsc/8810 port 8810 PID:Some(1203) [8810][0] initial start wait reports Running Downstairs /var/tmp/dsc/8830 port 8830 PID:Some(1204) [8830][2] initial start wait reports Running Sep 26 19:44:53.456 INFO listening, local_addr: 127.0.0.1:9998 Downstairs /var/tmp/dsc/8820 port 8820 PID:Some(1205) [8820][1] initial start wait reports Running All downstairs are running Control access at:127.0.0.1:9998 1204 1203 1205 Sep 26 19:44:58.496 INFO accepted connection, remote_addr: 127.0.0.1:55614, local_addr: 127.0.0.1:9998 Main task has work to do, go find it got dsc DisableRestartAll disable restart on all: 3 Sep 26 19:44:58.496 INFO request completed[8810] Disable keep_running , latency_us:[8820] Disable keep_running 174, response_code: 204, uri: /disablerestart/all, method: POST, req_id: cd7cc678-f0fc-4d87-b877-e66e2c7b8054, remote_addr: [8830] Disable keep_running 127.0.0.1:55614, local_addr: 127.0.0.1:9998 A new loop begins at September 26, 2024 at 07:44:58 PM UTC /var/tmp/bins/crutest perf -g 1 -t 127.0.0.1:8810 -t 127.0.0.1:8820 -t 127.0.0.1:8830 -c 30000 -q --write-loops 2 --read-loops 2 --perf-out /tmp/perf-ES-16384-EC-1280.csv {"msg":"look at: http://127.0.0.1:12810 ","v":0,"name":"crucible","level":30,"time":"2024-09-26T19:44:58.517447455Z","hostname":"w-01J8QXQECXY8DGRWH5ED8Q50RF","pid":1213,"task":"crutest"} {"msg":"RI is: RegionDefinition { block_size: 4096, extent_size: Block { value: 16384, shift: 12 }, extent_count: 1280, uuid: 12345678-0000-0000-0000-000000008810, encrypted: false, database_read_version: 1, database_write_version: 1 }","v":0,"name":"crucible","level":30,"time":"2024-09-26T19:44:58.557820585Z","hostname":"w-01J8QXQECXY8DGRWH5ED8Q50RF","pid":1213,"task":"crutest"} {"msg":"Upstairs starts","v":0,"name":"crucible","level":30,"time":"2024-09-26T19:44:58.558300106Z","hostname":"w-01J8QXQECXY8DGRWH5ED8Q50RF","pid":1213} {"msg":"Crucible Version: BuildInfo {\n version: \"0.0.1\",\n git_sha: \"8e980c14034391699f5d7f17cfb24177d0aafaf2\",\n git_commit_timestamp: \"2024-09-26T19:23:10.000000000Z\",\n git_branch: \"alan/crutest-meet-dsc\",\n rustc_semver: \"1.80.0\",\n rustc_channel: \"stable\",\n rustc_host_triple: \"x86_64-unknown-illumos\",\n rustc_commit_sha: \"051478957371ee0084a7c0913941d2a8c4757bb9\",\n cargo_triple: \"x86_64-unknown-illumos\",\n debug: false,\n opt_level: 3,\n}","v":0,"name":"crucible","level":30,"time":"2024-09-26T19:44:58.558325532Z","hostname":"w-01J8QXQECXY8DGRWH5ED8Q50RF","pid":1213} {"msg":"Upstairs <-> Downstairs Message Version: 11","v":0,"name":"crucible","level":30,"time":"2024-09-26T19:44:58.558332541Z","hostname":"w-01J8QXQECXY8DGRWH5ED8Q50RF","pid":1213} {"msg":"Using region definition RegionDefinition { block_size: 4096, extent_size: Block { value: 16384, shift: 12 }, extent_count: 1280, uuid: 00000000-0000-0000-0000-000000000000, encrypted: false, database_read_version: 1, database_write_version: 1 }","v":0,"name":"crucible","level":30,"time":"2024-09-26T19:44:58.55833801Z","hostname":"w-01J8QXQECXY8DGRWH5ED8Q50RF","pid":1213} {"msg":"Crucible e46a650a-5ccc-4a1e-8518-52feb02787e3 has session id: 06c0a37c-7b4a-402f-974e-1344ed6d369d","v":0,"name":"crucible","level":30,"time":"2024-09-26T19:44:58.558632091Z","hostname":"w-01J8QXQECXY8DGRWH5ED8Q50RF","pid":1213,"session_id":"06c0a37c-7b4a-402f-974e-1344ed6d369d"} {"msg":"Upstairs opts: Upstairs UUID: e46a650a-5ccc-4a1e-8518-52feb02787e3, 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-09-26T19:44:58.558655818Z","hostname":"w-01J8QXQECXY8DGRWH5ED8Q50RF","pid":1213,"session_id":"06c0a37c-7b4a-402f-974e-1344ed6d369d"} {"msg":"Crucible stats registered with UUID: e46a650a-5ccc-4a1e-8518-52feb02787e3","v":0,"name":"crucible","level":30,"time":"2024-09-26T19:44:58.558672105Z","hostname":"w-01J8QXQECXY8DGRWH5ED8Q50RF","pid":1213,"session_id":"06c0a37c-7b4a-402f-974e-1344ed6d369d"} {"msg":"The guest has requested activation with gen:1","v":0,"name":"crucible","level":30,"time":"2024-09-26T19:44:58.591909732Z","hostname":"w-01J8QXQECXY8DGRWH5ED8Q50RF","pid":1213} {"msg":"e46a650a-5ccc-4a1e-8518-52feb02787e3 active request set","v":0,"name":"crucible","level":30,"time":"2024-09-26T19:44:58.591928639Z","hostname":"w-01J8QXQECXY8DGRWH5ED8Q50RF","pid":1213,"session_id":"06c0a37c-7b4a-402f-974e-1344ed6d369d"} {"msg":"sending connect oneshot to client","v":0,"name":"crucible","level":30,"time":"2024-09-26T19:44:58.591934668Z","hostname":"w-01J8QXQECXY8DGRWH5ED8Q50RF","pid":1213,"client":"0","":"downstairs","session_id":"06c0a37c-7b4a-402f-974e-1344ed6d369d"} {"msg":"client set_active_request while in New; waiting...","v":0,"name":"crucible","level":30,"time":"2024-09-26T19:44:58.591951295Z","hostname":"w-01J8QXQECXY8DGRWH5ED8Q50RF","pid":1213,"client":"0","":"downstairs","session_id":"06c0a37c-7b4a-402f-974e-1344ed6d369d"} {"msg":"sending connect oneshot to client","v":0,"name":"crucible","level":30,"time":"2024-09-26T19:44:58.591958644Z","hostname":"w-01J8QXQECXY8DGRWH5ED8Q50RF","pid":1213,"client":"1","":"downstairs","session_id":"06c0a37c-7b4a-402f-974e-1344ed6d369d"} {"msg":"client set_active_request while in New; waiting...","v":0,"name":"crucible","level":30,"time":"2024-09-26T19:44:58.591964443Z","hostname":"w-01J8QXQECXY8DGRWH5ED8Q50RF","pid":1213,"client":"1","":"downstairs","session_id":"06c0a37c-7b4a-402f-974e-1344ed6d369d"} {"msg":"sending connect oneshot to client","v":0,"name":"crucible","level":30,"time":"2024-09-26T19:44:58.591970842Z","hostname":"w-01J8QXQECXY8DGRWH5ED8Q50RF","pid":1213,"client":"2","":"downstairs","session_id":"06c0a37c-7b4a-402f-974e-1344ed6d369d"} {"msg":"client set_active_request while in New; waiting...","v":0,"name":"crucible","level":30,"time":"2024-09-26T19:44:58.591976231Z","hostname":"w-01J8QXQECXY8DGRWH5ED8Q50RF","pid":1213,"client":"2","":"downstairs","session_id":"06c0a37c-7b4a-402f-974e-1344ed6d369d"} {"msg":"connecting to 127.0.0.1:8830","v":0,"name":"crucible","level":30,"time":"2024-09-26T19:44:58.59198169Z","hostname":"w-01J8QXQECXY8DGRWH5ED8Q50RF","pid":1213,"":"io task","client":"2","":"downstairs","session_id":"06c0a37c-7b4a-402f-974e-1344ed6d369d"} {"msg":"connecting to 127.0.0.1:8810","v":0,"name":"crucible","level":30,"time":"2024-09-26T19:44:58.591989499Z","hostname":"w-01J8QXQECXY8DGRWH5ED8Q50RF","pid":1213,"":"io task","client":"0","":"downstairs","session_id":"06c0a37c-7b4a-402f-974e-1344ed6d369d"} {"msg":"connecting to 127.0.0.1:8820","v":0,"name":"crucible","level":30,"time":"2024-09-26T19:44:58.59204529Z","hostname":"w-01J8QXQECXY8DGRWH5ED8Q50RF","pid":1213,"":"io task","client":"1","":"downstairs","session_id":"06c0a37c-7b4a-402f-974e-1344ed6d369d"} {"msg":"ds_connection connected from Ok(127.0.0.1:53600)","v":0,"name":"crucible","level":30,"time":"2024-09-26T19:44:58.592117968Z","hostname":"w-01J8QXQECXY8DGRWH5ED8Q50RF","pid":1213,"":"io task","client":"1","":"downstairs","session_id":"06c0a37c-7b4a-402f-974e-1344ed6d369d"} {"msg":"ds_connection connected from Ok(127.0.0.1:56101)","v":0,"name":"crucible","level":30,"time":"2024-09-26T19:44:58.592130516Z","hostname":"w-01J8QXQECXY8DGRWH5ED8Q50RF","pid":1213,"":"io task","client":"2","":"downstairs","session_id":"06c0a37c-7b4a-402f-974e-1344ed6d369d"} {"msg":"ds_connection connected from Ok(127.0.0.1:41213)","v":0,"name":"crucible","level":30,"time":"2024-09-26T19:44:58.592143344Z","hostname":"w-01J8QXQECXY8DGRWH5ED8Q50RF","pid":1213,"":"io task","client":"0","":"downstairs","session_id":"06c0a37c-7b4a-402f-974e-1344ed6d369d"} {"msg":"ds_transition from New to WaitActive","v":0,"name":"crucible","level":30,"time":"2024-09-26T19:44:58.592580871Z","hostname":"w-01J8QXQECXY8DGRWH5ED8Q50RF","pid":1213,"client":"1","":"downstairs","session_id":"06c0a37c-7b4a-402f-974e-1344ed6d369d"} {"msg":"[1] Transition from New to WaitActive","v":0,"name":"crucible","level":30,"time":"2024-09-26T19:44:58.592594989Z","hostname":"w-01J8QXQECXY8DGRWH5ED8Q50RF","pid":1213,"client":"1","":"downstairs","session_id":"06c0a37c-7b4a-402f-974e-1344ed6d369d"} {"msg":"ds_transition from New to WaitActive","v":0,"name":"crucible","level":30,"time":"2024-09-26T19:44:58.592600278Z","hostname":"w-01J8QXQECXY8DGRWH5ED8Q50RF","pid":1213,"client":"2","":"downstairs","session_id":"06c0a37c-7b4a-402f-974e-1344ed6d369d"} {"msg":"[2] Transition from New to WaitActive","v":0,"name":"crucible","level":30,"time":"2024-09-26T19:44:58.592606507Z","hostname":"w-01J8QXQECXY8DGRWH5ED8Q50RF","pid":1213,"client":"2","":"downstairs","session_id":"06c0a37c-7b4a-402f-974e-1344ed6d369d"} {"msg":"ds_transition from New to WaitActive","v":0,"name":"crucible","level":30,"time":"2024-09-26T19:44:58.592613016Z","hostname":"w-01J8QXQECXY8DGRWH5ED8Q50RF","pid":1213,"client":"0","":"downstairs","session_id":"06c0a37c-7b4a-402f-974e-1344ed6d369d"} {"msg":"[0] Transition from New to WaitActive","v":0,"name":"crucible","level":30,"time":"2024-09-26T19:44:58.592620895Z","hostname":"w-01J8QXQECXY8DGRWH5ED8Q50RF","pid":1213,"client":"0","":"downstairs","session_id":"06c0a37c-7b4a-402f-974e-1344ed6d369d"} {"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-09-26T19:44:58.592859636Z","hostname":"w-01J8QXQECXY8DGRWH5ED8Q50RF","pid":1213,"client":"1","":"downstairs","session_id":"06c0a37c-7b4a-402f-974e-1344ed6d369d"} {"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-09-26T19:44:58.592878442Z","hostname":"w-01J8QXQECXY8DGRWH5ED8Q50RF","pid":1213,"client":"2","":"downstairs","session_id":"06c0a37c-7b4a-402f-974e-1344ed6d369d"} {"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-09-26T19:44:58.592886161Z","hostname":"w-01J8QXQECXY8DGRWH5ED8Q50RF","pid":1213,"client":"0","":"downstairs","session_id":"06c0a37c-7b4a-402f-974e-1344ed6d369d"} {"msg":"ds_transition from WaitActive to WaitQuorum","v":0,"name":"crucible","level":30,"time":"2024-09-26T19:44:58.598244387Z","hostname":"w-01J8QXQECXY8DGRWH5ED8Q50RF","pid":1213,"client":"0","":"downstairs","session_id":"06c0a37c-7b4a-402f-974e-1344ed6d369d"} {"msg":"[0] Transition from WaitActive to WaitQuorum","v":0,"name":"crucible","level":30,"time":"2024-09-26T19:44:58.598272923Z","hostname":"w-01J8QXQECXY8DGRWH5ED8Q50RF","pid":1213,"client":"0","":"downstairs","session_id":"06c0a37c-7b4a-402f-974e-1344ed6d369d"} {"msg":"Waiting for more clients to be ready","v":0,"name":"crucible","level":30,"time":"2024-09-26T19:44:58.598283681Z","hostname":"w-01J8QXQECXY8DGRWH5ED8Q50RF","pid":1213,"session_id":"06c0a37c-7b4a-402f-974e-1344ed6d369d"} {"msg":"ds_transition from WaitActive to WaitQuorum","v":0,"name":"crucible","level":30,"time":"2024-09-26T19:44:58.598304477Z","hostname":"w-01J8QXQECXY8DGRWH5ED8Q50RF","pid":1213,"client":"2","":"downstairs","session_id":"06c0a37c-7b4a-402f-974e-1344ed6d369d"} {"msg":"[2] Transition from WaitActive to WaitQuorum","v":0,"name":"crucible","level":30,"time":"2024-09-26T19:44:58.598314536Z","hostname":"w-01J8QXQECXY8DGRWH5ED8Q50RF","pid":1213,"client":"2","":"downstairs","session_id":"06c0a37c-7b4a-402f-974e-1344ed6d369d"} {"msg":"Waiting for more clients to be ready","v":0,"name":"crucible","level":30,"time":"2024-09-26T19:44:58.598334572Z","hostname":"w-01J8QXQECXY8DGRWH5ED8Q50RF","pid":1213,"session_id":"06c0a37c-7b4a-402f-974e-1344ed6d369d"} {"msg":"ds_transition from WaitActive to WaitQuorum","v":0,"name":"crucible","level":30,"time":"2024-09-26T19:44:58.598342311Z","hostname":"w-01J8QXQECXY8DGRWH5ED8Q50RF","pid":1213,"client":"1","":"downstairs","session_id":"06c0a37c-7b4a-402f-974e-1344ed6d369d"} {"msg":"[1] Transition from WaitActive to WaitQuorum","v":0,"name":"crucible","level":30,"time":"2024-09-26T19:44:58.598360938Z","hostname":"w-01J8QXQECXY8DGRWH5ED8Q50RF","pid":1213,"client":"1","":"downstairs","session_id":"06c0a37c-7b4a-402f-974e-1344ed6d369d"} {"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-09-26T19:44:58.598369936Z","hostname":"w-01J8QXQECXY8DGRWH5ED8Q50RF","pid":1213,"":"downstairs","":"downstairs","session_id":"06c0a37c-7b4a-402f-974e-1344ed6d369d"} {"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-09-26T19:44:58.598390123Z","hostname":"w-01J8QXQECXY8DGRWH5ED8Q50RF","pid":1213,"":"downstairs","":"downstairs","session_id":"06c0a37c-7b4a-402f-974e-1344ed6d369d"} {"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-09-26T19:44:58.598405471Z","hostname":"w-01J8QXQECXY8DGRWH5ED8Q50RF","pid":1213,"":"downstairs","":"downstairs","session_id":"06c0a37c-7b4a-402f-974e-1344ed6d369d"} {"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-09-26T19:44:58.598426087Z","hostname":"w-01J8QXQECXY8DGRWH5ED8Q50RF","pid":1213,"":"downstairs","":"downstairs","session_id":"06c0a37c-7b4a-402f-974e-1344ed6d369d"} {"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-09-26T19:44:58.598435396Z","hostname":"w-01J8QXQECXY8DGRWH5ED8Q50RF","pid":1213,"":"downstairs","":"downstairs","session_id":"06c0a37c-7b4a-402f-974e-1344ed6d369d"} {"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-09-26T19:44:58.598454842Z","hostname":"w-01J8QXQECXY8DGRWH5ED8Q50RF","pid":1213,"":"downstairs","":"downstairs","session_id":"06c0a37c-7b4a-402f-974e-1344ed6d369d"} {"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-09-26T19:44:58.598463861Z","hostname":"w-01J8QXQECXY8DGRWH5ED8Q50RF","pid":1213,"":"downstairs","":"downstairs","session_id":"06c0a37c-7b4a-402f-974e-1344ed6d369d"} {"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-09-26T19:44:58.598484308Z","hostname":"w-01J8QXQECXY8DGRWH5ED8Q50RF","pid":1213,"":"downstairs","":"downstairs","session_id":"06c0a37c-7b4a-402f-974e-1344ed6d369d"} {"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-09-26T19:44:58.598495106Z","hostname":"w-01J8QXQECXY8DGRWH5ED8Q50RF","pid":1213,"":"downstairs","":"downstairs","session_id":"06c0a37c-7b4a-402f-974e-1344ed6d369d"} {"msg":"Max found gen is 1","v":0,"name":"crucible","level":30,"time":"2024-09-26T19:44:58.598515292Z","hostname":"w-01J8QXQECXY8DGRWH5ED8Q50RF","pid":1213,"":"downstairs","":"downstairs","session_id":"06c0a37c-7b4a-402f-974e-1344ed6d369d"} {"msg":"Generation requested: 1 >= found:1","v":0,"name":"crucible","level":30,"time":"2024-09-26T19:44:58.598524381Z","hostname":"w-01J8QXQECXY8DGRWH5ED8Q50RF","pid":1213,"":"downstairs","":"downstairs","session_id":"06c0a37c-7b4a-402f-974e-1344ed6d369d"} {"msg":"Next flush: 1","v":0,"name":"crucible","level":30,"time":"2024-09-26T19:44:58.598543518Z","hostname":"w-01J8QXQECXY8DGRWH5ED8Q50RF","pid":1213,"":"downstairs","":"downstairs","session_id":"06c0a37c-7b4a-402f-974e-1344ed6d369d"} {"msg":"All extents match","v":0,"name":"crucible","level":30,"time":"2024-09-26T19:44:58.598553606Z","hostname":"w-01J8QXQECXY8DGRWH5ED8Q50RF","pid":1213,"":"downstairs","":"downstairs","session_id":"06c0a37c-7b4a-402f-974e-1344ed6d369d"} {"msg":"No downstairs reconciliation required",Wait for a query_work_queue command to finish before sending IO "v":0,"name":"crucible","level":30,"time":"2024-09-26T19:44:58.598579602Z","hostname":"w-01J8QXQECXY8DGRWH5ED8Q50RF","pid":1213,"session_id":"06c0a37c-7b4a-402f-974e-1344ed6d369d"} {"msg":"Transition from WaitQuorum to Active","v":0,"name":"crucible","level":30,"time":"2024-09-26T19:44:58.598585111Z","hostname":"w-01J8QXQECXY8DGRWH5ED8Q50RF","pid":1213,"client":"0","":"downstairs","session_id":"06c0a37c-7b4a-402f-974e-1344ed6d369d"} {"msg":"Transition from WaitQuorum to Active","v":0,"name":"crucible","level":30,"time":"2024-09-26T19:44:58.598594719Z","hostname":"w-01J8QXQECXY8DGRWH5ED8Q50RF","pid":1213,"client":"1","":"downstairs","session_id":"06c0a37c-7b4a-402f-974e-1344ed6d369d"} {"msg":"Transition from WaitQuorum to Active","v":0,"name":"crucible","level":30,"time":"2024-09-26T19:44:58.598604518Z","hostname":"w-01J8QXQECXY8DGRWH5ED8Q50RF","pid":1213,"client":"2","":"downstairs","session_id":"06c0a37c-7b4a-402f-974e-1344ed6d369d"} {"msg":"All required reconciliation work is completed","v":0,"name":"crucible","level":30,"time":"2024-09-26T19:44:58.598614106Z","hostname":"w-01J8QXQECXY8DGRWH5ED8Q50RF","pid":1213,"session_id":"06c0a37c-7b4a-402f-974e-1344ed6d369d"} {"msg":"Set Downstairs and Upstairs active after reconciliation","v":0,"name":"crucible","level":30,"time":"2024-09-26T19:44:58.598623435Z","hostname":"w-01J8QXQECXY8DGRWH5ED8Q50RF","pid":1213,"session_id":"06c0a37c-7b4a-402f-974e-1344ed6d369d"} {"msg":"e46a650a-5ccc-4a1e-8518-52feb02787e3 is now active with session: 06c0a37c-7b4a-402f-974e-1344ed6d369d","v":0,"name":"crucible","level":30,"time":"2024-09-26T19:44:58.598631553Z","hostname":"w-01J8QXQECXY8DGRWH5ED8Q50RF","pid":1213,"session_id":"06c0a37c-7b4a-402f-974e-1344ed6d369d"} {"msg":"Set Active after no reconciliation","v":0,"name":"crucible","level":30,"time":"2024-09-26T19:44:58.598640342Z","hostname":"w-01J8QXQECXY8DGRWH5ED8Q50RF","pid":1213,"session_id":"06c0a37c-7b4a-402f-974e-1344ed6d369d"} {"msg":"The guest has finished waiting for activation with:1","v":0,"name":"crucible","level":30,"time":"2024-09-26T19:44:58.598648281Z","hostname":"w-01J8QXQECXY8DGRWH5ED8Q50RF","pid":1213} Region: es:16384 ec:1280 bs:4096 ts:85899345920 tb:20971520 max_io:256 or 1048576 Perf test TEST SECONDS COUNT DPTH IOPS MEAN P95 P99 MAX ES EC rwrites 7.08 30000 1 4235.29 0.00024 0.00117 0.00139 0.06256 16384 1280 rwrites 8.14 30000 1 3683.92 0.00027 0.00118 0.00146 0.06189 16384 1280 rreads 5.32 30000 1 5640.54 0.00018 0.00022 0.00028 0.00567 16384 1280 rreads 5.33 30000 1 5628.43 0.00018 0.00022 0.00027 0.00567 16384 1280 Perf test completed, stop all downstairs Sep 26 19:45:27.123 INFO accepted connection, remote_addr: 127.0.0.1:34465, local_addr: 127.0.0.1:9998 Main task has work to do, go find it got dsc Shutdown Shutdown Sep 26 19:45:27.123 INFO request completed, latency_us: 59, [8810] Disable keep_running response_codeShut it down : 204, uri: /shutdown, method[8820] Disable keep_running : POST, req_id:[8820] Got stop action so:false kr:false f86d4013-73ac-4d2c-84f0-4e0f53dcc1a5, remote_addr:[8810] Got stop action so:false kr:false 127.0.0.1:34465, local_addr[8830] Disable keep_running :[8830] Got stop action so:false kr:false 127.0.0.1:9998 [8830] Exited with: ExitStatus(unix_wait_status(9)) [8810] Exited with: ExitStatus(unix_wait_status(9)) [8830][2] reports Exit [8810][0] reports Exit [8820] Exited with: ExitStatus(unix_wait_status(9)) [8820][1] reports Exit TEST SECONDS COUNT DPTH IOPS MEAN P95 P99 MAX ES EC rwrites 5.26 30000 1 5706.09 0.00017 0.00048 0.00124 0.04783 16384 640 rwrites 6.19 30000 1 4844.82 0.00021 0.00116 0.00128 0.08275 16384 640 rwrites 7.08 30000 1 4235.29 0.00024 0.00117 0.00139 0.06256 16384 1280 rwrites 8.14 30000 1 3683.92 0.00027 0.00118 0.00146 0.06189 16384 1280 TEST SECONDS COUNT DPTH IOPS MEAN P95 P99 MAX ES EC rreads 5.42 30000 1 5539.88 0.00018 0.00023 0.00029 0.00821 16384 640 rreads 5.36 30000 1 5592.98 0.00018 0.00023 0.00028 0.00821 16384 640 rreads 5.32 30000 1 5640.54 0.00018 0.00022 0.00028 0.00567 16384 1280 rreads 5.33 30000 1 5628.43 0.00018 0.00022 0.00027 0.00567 16384 1280 Perf test finished on September 26, 2024 at 07:45:28 PM UTC