/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.9768098 Downstairs region 1 created at /var/tmp/dsc/8820 in 0.82887113 Downstairs region 2 created at /var/tmp/dsc/8830 in 0.4622922 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 access at:127.0.0.1:9998 start ds: 8820 start ds: 8830 Starting downstairs at port 8810 Starting downstairs at port 8820 [8810][0] initial start wait reports Starting Make output file at "/tmp/dsc/downstairs-8820.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-8810.txt" Downstairs /var/tmp/dsc/8820 port 8820 PID:Some(1186) [8820][1] initial start wait reports Running Downstairs /var/tmp/dsc/8810 port 8810 PID:Some(1187) [8810][0] initial start wait reports Running Downstairs /var/tmp/dsc/8830 port 8830 PID:Some(1188) [8830][2] initial start wait reports Running All downstairs are running Sep 27 23:06:56.282 INFO listening, local_addr: 127.0.0.1:9998 Control access at:127.0.0.1:9998 1186 1187 1188 Sep 27 23:07:01.322 INFO accepted connection, remote_addr: 127.0.0.1:44534, 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 27 23:07:01.322 INFO request completed, latency_us: 120, response_code: 204, uri: /disablerestart/all, method: POST, req_id: 378025c2-8d03-4e13-be2c-47128e5b8f26, remote_addr: 127.0.0.1:44534, local_addr: [8820] Disable keep_running 127[8810] Disable keep_running .0.0.1:9998 [8830] Disable keep_running A new loop begins at September 27, 2024 at 11:07:01 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-27T23:07:01.346933443Z","hostname":"w-01J8TVQCPGEHTFRK3TP053XNFM","pid":1196,"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-27T23:07:01.38809805Z","hostname":"w-01J8TVQCPGEHTFRK3TP053XNFM","pid":1196,"task":"crutest"} {"msg":"Upstairs starts","v":0,"name":"crucible","level":30,"time":"2024-09-27T23:07:01.388707204Z","hostname":"w-01J8TVQCPGEHTFRK3TP053XNFM","pid":1196} {"msg":"Crucible Version: BuildInfo {\n version: \"0.0.1\",\n git_sha: \"60f78286ad49cec90cdcc3e028e5e9c76d4fdc1d\",\n git_commit_timestamp: \"2024-09-27T22:46:32.000000000Z\",\n git_branch: \"alan/tests-use-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-27T23:07:01.38876007Z","hostname":"w-01J8TVQCPGEHTFRK3TP053XNFM","pid":1196} {"msg":"Upstairs <-> Downstairs Message Version: 11","v":0,"name":"crucible","level":30,"time":"2024-09-27T23:07:01.388772889Z","hostname":"w-01J8TVQCPGEHTFRK3TP053XNFM","pid":1196} {"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-27T23:07:01.388777408Z","hostname":"w-01J8TVQCPGEHTFRK3TP053XNFM","pid":1196} {"msg":"Crucible bca26bc1-dbb8-4ebb-9024-7879bd618f84 has session id: e4636d35-9142-4927-bb2e-eb5082a04300","v":0,"name":"crucible","level":30,"time":"2024-09-27T23:07:01.389265071Z","hostname":"w-01J8TVQCPGEHTFRK3TP053XNFM","pid":1196,"session_id":"e4636d35-9142-4927-bb2e-eb5082a04300"} {"msg":"Upstairs opts: Upstairs UUID: bca26bc1-dbb8-4ebb-9024-7879bd618f84, 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-27T23:07:01.389371903Z","hostname":"w-01J8TVQCPGEHTFRK3TP053XNFM","pid":1196,"session_id":"e4636d35-9142-4927-bb2e-eb5082a04300"} {"msg":"Crucible stats registered with UUID: bca26bc1-dbb8-4ebb-9024-7879bd618f84","v":0,"name":"crucible","level":30,"time":"2024-09-27T23:07:01.389387322Z","hostname":"w-01J8TVQCPGEHTFRK3TP053XNFM","pid":1196,"session_id":"e4636d35-9142-4927-bb2e-eb5082a04300"} {"msg":"The guest has requested activation with gen:1","v":0,"name":"crucible","level":30,"time":"2024-09-27T23:07:01.419909492Z","hostname":"w-01J8TVQCPGEHTFRK3TP053XNFM","pid":1196} {"msg":"bca26bc1-dbb8-4ebb-9024-7879bd618f84 active request set","v":0,"name":"crucible","level":30,"time":"2024-09-27T23:07:01.41993354Z","hostname":"w-01J8TVQCPGEHTFRK3TP053XNFM","pid":1196,"session_id":"e4636d35-9142-4927-bb2e-eb5082a04300"} {"msg":"sending connect oneshot to client","v":0,"name":"crucible","level":30,"time":"2024-09-27T23:07:01.419941769Z","hostname":"w-01J8TVQCPGEHTFRK3TP053XNFM","pid":1196,"client":"0","":"downstairs","session_id":"e4636d35-9142-4927-bb2e-eb5082a04300"} {"msg":"client set_active_request while in New; waiting...","v":0,"name":"crucible","level":30,"time":"2024-09-27T23:07:01.419998235Z","hostname":"w-01J8TVQCPGEHTFRK3TP053XNFM","pid":1196,"client":"0","":"downstairs","session_id":"e4636d35-9142-4927-bb2e-eb5082a04300"} {"msg":"sending connect oneshot to client","v":0,"name":"crucible","level":30,"time":"2024-09-27T23:07:01.420010144Z","hostname":"w-01J8TVQCPGEHTFRK3TP053XNFM","pid":1196,"client":"1","":"downstairs","session_id":"e4636d35-9142-4927-bb2e-eb5082a04300"} {"msg":"client set_active_request while in New; waiting...","v":0,"name":"crucible","level":30,"time":"2024-09-27T23:07:01.420019503Z","hostname":"w-01J8TVQCPGEHTFRK3TP053XNFM","pid":1196,"client":"1","":"downstairs","session_id":"e4636d35-9142-4927-bb2e-eb5082a04300"} {"msg":"sending connect oneshot to client","v":0,"name":"crucible","level":30,"time":"2024-09-27T23:07:01.420029353Z","hostname":"w-01J8TVQCPGEHTFRK3TP053XNFM","pid":1196,"client":"2","":"downstairs","session_id":"e4636d35-9142-4927-bb2e-eb5082a04300"} {"msg":"client set_active_request while in New; waiting...","v":0,"name":"crucible","level":30,"time":"2024-09-27T23:07:01.420049081Z","hostname":"w-01J8TVQCPGEHTFRK3TP053XNFM","pid":1196,"client":"2","":"downstairs","session_id":"e4636d35-9142-4927-bb2e-eb5082a04300"} {"msg":"connecting to 127.0.0.1:8830","v":0,"name":"crucible","level":30,"time":"2024-09-27T23:07:01.42005866Z","hostname":"w-01J8TVQCPGEHTFRK3TP053XNFM","pid":1196,"":"io task","client":"2","":"downstairs","session_id":"e4636d35-9142-4927-bb2e-eb5082a04300"} {"msg":"connecting to 127.0.0.1:8820","v":0,"name":"crucible","level":30,"time":"2024-09-27T23:07:01.420069999Z","hostname":"w-01J8TVQCPGEHTFRK3TP053XNFM","pid":1196,"":"io task","client":"1","":"downstairs","session_id":"e4636d35-9142-4927-bb2e-eb5082a04300"} {"msg":"connecting to 127.0.0.1:8810","v":0,"name":"crucible","level":30,"time":"2024-09-27T23:07:01.420076089Z","hostname":"w-01J8TVQCPGEHTFRK3TP053XNFM","pid":1196,"":"io task","client":"0","":"downstairs","session_id":"e4636d35-9142-4927-bb2e-eb5082a04300"} {"msg":"ds_connection connected from Ok(127.0.0.1:34747)","v":0,"name":"crucible","level":30,"time":"2024-09-27T23:07:01.420218328Z","hostname":"w-01J8TVQCPGEHTFRK3TP053XNFM","pid":1196,"":"io task","client":"0","":"downstairs","session_id":"e4636d35-9142-4927-bb2e-eb5082a04300"} {"msg":"ds_connection connected from Ok(127.0.0.1:35385)","v":0,"name":"crucible","level":30,"time":"2024-09-27T23:07:01.420346358Z","hostname":"w-01J8TVQCPGEHTFRK3TP053XNFM","pid":1196,"":"io task","client":"2","":"downstairs","session_id":"e4636d35-9142-4927-bb2e-eb5082a04300"} {"msg":"ds_connection connected from Ok(127.0.0.1:40847)","v":0,"name":"crucible","level":30,"time":"2024-09-27T23:07:01.420390375Z","hostname":"w-01J8TVQCPGEHTFRK3TP053XNFM","pid":1196,"":"io task","client":"1","":"downstairs","session_id":"e4636d35-9142-4927-bb2e-eb5082a04300"} {"msg":"ds_transition from New to WaitActive","v":0,"name":"crucible","level":30,"time":"2024-09-27T23:07:01.420685272Z","hostname":"w-01J8TVQCPGEHTFRK3TP053XNFM","pid":1196,"client":"0","":"downstairs","session_id":"e4636d35-9142-4927-bb2e-eb5082a04300"} {"msg":"[0] Transition from New to WaitActive","v":0,"name":"crucible","level":30,"time":"2024-09-27T23:07:01.420698642Z","hostname":"w-01J8TVQCPGEHTFRK3TP053XNFM","pid":1196,"client":"0","":"downstairs","session_id":"e4636d35-9142-4927-bb2e-eb5082a04300"} {"msg":"ds_transition from New to WaitActive","v":0,"name":"crucible","level":30,"time":"2024-09-27T23:07:01.420753807Z","hostname":"w-01J8TVQCPGEHTFRK3TP053XNFM","pid":1196,"client":"1","":"downstairs","session_id":"e4636d35-9142-4927-bb2e-eb5082a04300"} {"msg":"[1] Transition from New to WaitActive","v":0,"name":"crucible","level":30,"time":"2024-09-27T23:07:01.420771456Z","hostname":"w-01J8TVQCPGEHTFRK3TP053XNFM","pid":1196,"client":"1","":"downstairs","session_id":"e4636d35-9142-4927-bb2e-eb5082a04300"} {"msg":"ds_transition from New to WaitActive","v":0,"name":"crucible","level":30,"time":"2024-09-27T23:07:01.420776965Z","hostname":"w-01J8TVQCPGEHTFRK3TP053XNFM","pid":1196,"client":"2","":"downstairs","session_id":"e4636d35-9142-4927-bb2e-eb5082a04300"} {"msg":"[2] Transition from New to WaitActive","v":0,"name":"crucible","level":30,"time":"2024-09-27T23:07:01.420781415Z","hostname":"w-01J8TVQCPGEHTFRK3TP053XNFM","pid":1196,"client":"2","":"downstairs","session_id":"e4636d35-9142-4927-bb2e-eb5082a04300"} {"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-27T23:07:01.420953862Z","hostname":"w-01J8TVQCPGEHTFRK3TP053XNFM","pid":1196,"client":"0","":"downstairs","session_id":"e4636d35-9142-4927-bb2e-eb5082a04300"} {"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-27T23:07:01.42097247Z","hostname":"w-01J8TVQCPGEHTFRK3TP053XNFM","pid":1196,"client":"1","":"downstairs","session_id":"e4636d35-9142-4927-bb2e-eb5082a04300"} {"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-27T23:07:01.42098054Z","hostname":"w-01J8TVQCPGEHTFRK3TP053XNFM","pid":1196,"client":"2","":"downstairs","session_id":"e4636d35-9142-4927-bb2e-eb5082a04300"} {"msg":"ds_transition from WaitActive to WaitQuorum","v":0,"name":"crucible","level":30,"time":"2024-09-27T23:07:01.423550704Z","hostname":"w-01J8TVQCPGEHTFRK3TP053XNFM","pid":1196,"client":"2","":"downstairs","session_id":"e4636d35-9142-4927-bb2e-eb5082a04300"} {"msg":"[2] Transition from WaitActive to WaitQuorum","v":0,"name":"crucible","level":30,"time":"2024-09-27T23:07:01.423566072Z","hostname":"w-01J8TVQCPGEHTFRK3TP053XNFM","pid":1196,"client":"2","":"downstairs","session_id":"e4636d35-9142-4927-bb2e-eb5082a04300"} {"msg":"Waiting for more clients to be ready","v":0,"name":"crucible","level":30,"time":"2024-09-27T23:07:01.423570982Z","hostname":"w-01J8TVQCPGEHTFRK3TP053XNFM","pid":1196,"session_id":"e4636d35-9142-4927-bb2e-eb5082a04300"} {"msg":"ds_transition from WaitActive to WaitQuorum","v":0,"name":"crucible","level":30,"time":"2024-09-27T23:07:01.424087413Z","hostname":"w-01J8TVQCPGEHTFRK3TP053XNFM","pid":1196,"client":"0","":"downstairs","session_id":"e4636d35-9142-4927-bb2e-eb5082a04300"} {"msg":"[0] Transition from WaitActive to WaitQuorum","v":0,"name":"crucible","level":30,"time":"2024-09-27T23:07:01.424104562Z","hostname":"w-01J8TVQCPGEHTFRK3TP053XNFM","pid":1196,"client":"0","":"downstairs","session_id":"e4636d35-9142-4927-bb2e-eb5082a04300"} {"msg":"Waiting for more clients to be ready","v":0,"name":"crucible","level":30,"time":"2024-09-27T23:07:01.424110341Z","hostname":"w-01J8TVQCPGEHTFRK3TP053XNFM","pid":1196,"session_id":"e4636d35-9142-4927-bb2e-eb5082a04300"} {"msg":"ds_transition from WaitActive to WaitQuorum","v":0,"name":"crucible","level":30,"time":"2024-09-27T23:07:01.424114791Z","hostname":"w-01J8TVQCPGEHTFRK3TP053XNFM","pid":1196,"client":"1","":"downstairs","session_id":"e4636d35-9142-4927-bb2e-eb5082a04300"} {"msg":"[1] Transition from WaitActive to WaitQuorum","v":0,"name":"crucible","level":30,"time":"2024-09-27T23:07:01.42412014Z","hostname":"w-01J8TVQCPGEHTFRK3TP053XNFM","pid":1196,"client":"1","":"downstairs","session_id":"e4636d35-9142-4927-bb2e-eb5082a04300"} {"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-27T23:07:01.424206924Z","hostname":"w-01J8TVQCPGEHTFRK3TP053XNFM","pid":1196,"":"downstairs","":"downstairs","session_id":"e4636d35-9142-4927-bb2e-eb5082a04300"} {"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-27T23:07:01.424221962Z","hostname":"w-01J8TVQCPGEHTFRK3TP053XNFM","pid":1196,"":"downstairs","":"downstairs","session_id":"e4636d35-9142-4927-bb2e-eb5082a04300"} {"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-27T23:07:01.424227642Z","hostname":"w-01J8TVQCPGEHTFRK3TP053XNFM","pid":1196,"":"downstairs","":"downstairs","session_id":"e4636d35-9142-4927-bb2e-eb5082a04300"} {"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-27T23:07:01.424232852Z","hostname":"w-01J8TVQCPGEHTFRK3TP053XNFM","pid":1196,"":"downstairs","":"downstairs","session_id":"e4636d35-9142-4927-bb2e-eb5082a04300"} {"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-27T23:07:01.424237961Z","hostname":"w-01J8TVQCPGEHTFRK3TP053XNFM","pid":1196,"":"downstairs","":"downstairs","session_id":"e4636d35-9142-4927-bb2e-eb5082a04300"} {"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-27T23:07:01.424243381Z","hostname":"w-01J8TVQCPGEHTFRK3TP053XNFM","pid":1196,"":"downstairs","":"downstairs","session_id":"e4636d35-9142-4927-bb2e-eb5082a04300"} {"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-27T23:07:01.42424872Z","hostname":"w-01J8TVQCPGEHTFRK3TP053XNFM","pid":1196,"":"downstairs","":"downstairs","session_id":"e4636d35-9142-4927-bb2e-eb5082a04300"} {"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-27T23:07:01.4242539Z","hostname":"w-01J8TVQCPGEHTFRK3TP053XNFM","pid":1196,"":"downstairs","":"downstairs","session_id":"e4636d35-9142-4927-bb2e-eb5082a04300"} {"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-27T23:07:01.42425976Z","hostname":"w-01J8TVQCPGEHTFRK3TP053XNFM","pid":1196,"":"downstairs","":"downstairs","session_id":"e4636d35-9142-4927-bb2e-eb5082a04300"} {"msg":"Max found gen is 1","v":0,"name":"crucible","level":30,"time":"2024-09-27T23:07:01.424265629Z","hostname":"w-01J8TVQCPGEHTFRK3TP053XNFM","pid":1196,"":"downstairs","":"downstairs","session_id":"e4636d35-9142-4927-bb2e-eb5082a04300"} {"msg":"Generation requested: 1 >= found:1","v":0,"name":"crucible","level":30,"time":"2024-09-27T23:07:01.424270929Z","hostname":"w-01J8TVQCPGEHTFRK3TP053XNFM","pid":1196,"":"downstairs","":"downstairs","session_id":"e4636d35-9142-4927-bb2e-eb5082a04300"} {"msg":"Next flush: 1","v":0,"name":"crucible","level":30,"time":"2024-09-27T23:07:01.424276058Z","hostname":"w-01J8TVQCPGEHTFRK3TP053XNFM","pid":1196,"":"downstairs","":"downstairs","session_id":"e4636d35-9142-4927-bb2e-eb5082a04300"} {"msg":"All extents match","v":0,"name":"crucible","level":30,"time":"2024-09-27T23:07:01.424281088Z","hostname":"w-01J8TVQCPGEHTFRK3TP053XNFM","pid":1196,"":"downstairs","":"downstairs","session_id":"e4636d35-9142-4927-bb2e-eb5082a04300"} {"msg":"No downstairs reconciliation required","v":0,"name":"crucible","level":30,"time":"2024-09-27T23:07:01.424287377Z","hostname":"w-01J8TVQCPGEHTFRK3TP053XNFM","pid":1196,"session_id":"e4636d35-9142-4927-bb2e-eb5082a04300"} {"msg":"Transition from WaitQuorum to Active","v":0,"name":"crucible","level":30,"time":"2024-09-27T23:07:01.424291747Z","hostname":"w-01J8TVQCPGEHTFRK3TP053XNFM","pid":1196,"client":"0","":"downstairs","session_id":"e4636d35-9142-4927-bb2e-eb5082a04300"} {"msg":"Transition from WaitQuorum to Active","v":0,"name":"crucible","level":30,"time":"2024-09-27T23:07:01.424296787Z","Wait for a query_work_queue command to finish before sending IO hostname":"w-01J8TVQCPGEHTFRK3TP053XNFM","pid":1196,"client":"1","":"downstairs","session_id":"e4636d35-9142-4927-bb2e-eb5082a04300"} {"msg":"Transition from WaitQuorum to Active","v":0,"name":"crucible","level":30,"time":"2024-09-27T23:07:01.424305046Z","hostname":"w-01J8TVQCPGEHTFRK3TP053XNFM","pid":1196,"client":"2","":"downstairs","session_id":"e4636d35-9142-4927-bb2e-eb5082a04300"} {"msg":"All required reconciliation work is completed","v":0,"name":"crucible","level":30,"time":"2024-09-27T23:07:01.424310826Z","hostname":"w-01J8TVQCPGEHTFRK3TP053XNFM","pid":1196,"session_id":"e4636d35-9142-4927-bb2e-eb5082a04300"} {"msg":"Set Downstairs and Upstairs active after reconciliation","v":0,"name":"crucible","level":30,"time":"2024-09-27T23:07:01.424315365Z","hostname":"w-01J8TVQCPGEHTFRK3TP053XNFM","pid":1196,"session_id":"e4636d35-9142-4927-bb2e-eb5082a04300"} {"msg":"bca26bc1-dbb8-4ebb-9024-7879bd618f84 is now active with session: e4636d35-9142-4927-bb2e-eb5082a04300","v":0,"name":"crucible","level":30,"time":"2024-09-27T23:07:01.424319745Z","hostname":"w-01J8TVQCPGEHTFRK3TP053XNFM","pid":1196,"session_id":"e4636d35-9142-4927-bb2e-eb5082a04300"} {"msg":"Set Active after no reconciliation","v":0,"name":"crucible","level":30,"time":"2024-09-27T23:07:01.424324195Z","hostname":"w-01J8TVQCPGEHTFRK3TP053XNFM","pid":1196,"session_id":"e4636d35-9142-4927-bb2e-eb5082a04300"} {"msg":"The guest has finished waiting for activation with:1","v":0,"name":"crucible","level":30,"time":"2024-09-27T23:07:01.424328664Z","hostname":"w-01J8TVQCPGEHTFRK3TP053XNFM","pid":1196} 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.15 30000 1 5830.23 0.00017 0.00046 0.00124 0.06689 16384 640 rwrites 5.05 30000 1 5935.09 0.00017 0.00046 0.00119 0.07630 16384 640 rreads 5.44 30000 1 5512.07 0.00018 0.00023 0.00029 0.00672 16384 640 rreads 5.39 30000 1 5564.10 0.00018 0.00023 0.00028 0.00672 16384 640 Perf test completed, stop all downstairs Sep 27 23:07:28.893 INFO accepted connection, remote_addr: 127.0.0.1:42047, local_addr: 127.0.0.1:9998 Main task has work to do, go find it got dsc Shutdown Shutdown Sep 27 23:07:28.893 INFO request completed, latency_us[8810] Disable keep_running :Shut it down [8830] Disable keep_running 53, response_code: 204[8830] Got stop action so:false kr:false , uri: /shutdown, method: [8820] Disable keep_running POST, req_id[8820] Got stop action so:false kr:false : 832c9f73-ea01-4b74-b78b-00123d348d05, remote_addr: 127.0.0.1:42047, local_addr: 127.0.0.1:9998 [8810] Got stop action so:false kr:false [8820] Exited with: ExitStatus(unix_wait_status(9)) [8820][1] reports Exit [8830] Exited with: ExitStatus(unix_wait_status(9)) [8810] Exited with: ExitStatus(unix_wait_status(9)) [8830][2] reports Exit [8810][0] 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.414732 Downstairs region 1 created at /var/tmp/dsc/8820 in 1.6933035 Downstairs region 2 created at /var/tmp/dsc/8830 in 1.1912313 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 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 [8820][1] initial start wait reports Starting Starting downstairs at port 8830 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(1205) [8810][0] initial start wait reports Running Downstairs /var/tmp/dsc/8830 port 8830 PID:Some(1206) [8830][2] initial start wait reports Running Downstairs /var/tmp/dsc/8820 port 8820 PID:Some(1207) [8820][1] initial start wait reports Running All downstairs are running Sep 27 23:07:34.257 INFO listening, local_addr: 127.0.0.1:9998 Control access at:127.0.0.1:9998 1206 1205 1207 Sep 27 23:07:39.294 INFO accepted connection, remote_addr: 127.0.0.1:51053, 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 27 23:07:39.295 INFO request completed, latency_us: 126, response_code: 204, uri: /disablerestart/all, method: POST, req_id: 9eddfc36-258b-41d3-ac41-5a5c60c932a7, remote_addr: 127.0.0.1[8820] Disable keep_running :[8810] Disable keep_running 51053, local_addr: 127.0.0.1:9998 [8830] Disable keep_running A new loop begins at September 27, 2024 at 11:07:39 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-27T23:07:39.316814817Z","hostname":"w-01J8TVQCPGEHTFRK3TP053XNFM","pid":1215,"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-27T23:07:39.357169996Z","hostname":"w-01J8TVQCPGEHTFRK3TP053XNFM","pid":1215,"task":"crutest"} {"msg":"Upstairs starts","v":0,"name":"crucible","level":30,"time":"2024-09-27T23:07:39.357758131Z","hostname":"w-01J8TVQCPGEHTFRK3TP053XNFM","pid":1215} {"msg":"Crucible Version: BuildInfo {\n version: \"0.0.1\",\n git_sha: \"60f78286ad49cec90cdcc3e028e5e9c76d4fdc1d\",\n git_commit_timestamp: \"2024-09-27T22:46:32.000000000Z\",\n git_branch: \"alan/tests-use-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-27T23:07:39.357789199Z","hostname":"w-01J8TVQCPGEHTFRK3TP053XNFM","pid":1215} {"msg":"Upstairs <-> Downstairs Message Version: 11","v":0,"name":"crucible","level":30,"time":"2024-09-27T23:07:39.357799119Z","hostname":"w-01J8TVQCPGEHTFRK3TP053XNFM","pid":1215} {"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-27T23:07:39.357807988Z","hostname":"w-01J8TVQCPGEHTFRK3TP053XNFM","pid":1215} {"msg":"Crucible 046bf7a6-afcf-4028-bffa-afead9e0ef88 has session id: 268fbf69-4373-4cad-bbab-177d1380aa12","v":0,"name":"crucible","level":30,"time":"2024-09-27T23:07:39.358109655Z","hostname":"w-01J8TVQCPGEHTFRK3TP053XNFM","pid":1215,"session_id":"268fbf69-4373-4cad-bbab-177d1380aa12"} {"msg":"Upstairs opts: Upstairs UUID: 046bf7a6-afcf-4028-bffa-afead9e0ef88, 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-27T23:07:39.358141582Z","hostname":"w-01J8TVQCPGEHTFRK3TP053XNFM","pid":1215,"session_id":"268fbf69-4373-4cad-bbab-177d1380aa12"} {"msg":"Crucible stats registered with UUID: 046bf7a6-afcf-4028-bffa-afead9e0ef88","v":0,"name":"crucible","level":30,"time":"2024-09-27T23:07:39.358151472Z","hostname":"w-01J8TVQCPGEHTFRK3TP053XNFM","pid":1215,"session_id":"268fbf69-4373-4cad-bbab-177d1380aa12"} {"msg":"The guest has requested activation with gen:1","v":0,"name":"crucible","level":30,"time":"2024-09-27T23:07:39.388005102Z","hostname":"w-01J8TVQCPGEHTFRK3TP053XNFM","pid":1215} {"msg":"046bf7a6-afcf-4028-bffa-afead9e0ef88 active request set","v":0,"name":"crucible","level":30,"time":"2024-09-27T23:07:39.38803168Z","hostname":"w-01J8TVQCPGEHTFRK3TP053XNFM","pid":1215,"session_id":"268fbf69-4373-4cad-bbab-177d1380aa12"} {"msg":"sending connect oneshot to client","v":0,"name":"crucible","level":30,"time":"2024-09-27T23:07:39.38804062Z","hostname":"w-01J8TVQCPGEHTFRK3TP053XNFM","pid":1215,"client":"0","":"downstairs","session_id":"268fbf69-4373-4cad-bbab-177d1380aa12"} {"msg":"client set_active_request while in New; waiting...","v":0,"name":"crucible","level":30,"time":"2024-09-27T23:07:39.388058209Z","hostname":"w-01J8TVQCPGEHTFRK3TP053XNFM","pid":1215,"client":"0","":"downstairs","session_id":"268fbf69-4373-4cad-bbab-177d1380aa12"} {"msg":"sending connect oneshot to client","v":0,"name":"crucible","level":30,"time":"2024-09-27T23:07:39.388067088Z","hostname":"w-01J8TVQCPGEHTFRK3TP053XNFM","pid":1215,"client":"1","":"downstairs","session_id":"268fbf69-4373-4cad-bbab-177d1380aa12"} {"msg":"client set_active_request while in New; waiting...","v":0,"name":"crucible","level":30,"time":"2024-09-27T23:07:39.388087586Z","hostname":"w-01J8TVQCPGEHTFRK3TP053XNFM","pid":1215,"client":"1","":"downstairs","session_id":"268fbf69-4373-4cad-bbab-177d1380aa12"} {"msg":"sending connect oneshot to client","v":0,"name":"crucible","level":30,"time":"2024-09-27T23:07:39.388097095Z","hostname":"w-01J8TVQCPGEHTFRK3TP053XNFM","pid":1215,"client":"2","":"downstairs","session_id":"268fbf69-4373-4cad-bbab-177d1380aa12"} {"msg":"client set_active_request while in New; waiting...","v":0,"name":"crucible","level":30,"time":"2024-09-27T23:07:39.388106845Z","hostname":"w-01J8TVQCPGEHTFRK3TP053XNFM","pid":1215,"client":"2","":"downstairs","session_id":"268fbf69-4373-4cad-bbab-177d1380aa12"} {"msg":"connecting to 127.0.0.1:8830","v":0,"name":"crucible","level":30,"time":"2024-09-27T23:07:39.388116214Z","hostname":"w-01J8TVQCPGEHTFRK3TP053XNFM","pid":1215,"":"io task","client":"2","":"downstairs","session_id":"268fbf69-4373-4cad-bbab-177d1380aa12"} {"msg":"connecting to 127.0.0.1:8810","v":0,"name":"crucible","level":30,"time":"2024-09-27T23:07:39.388126073Z","hostname":"w-01J8TVQCPGEHTFRK3TP053XNFM","pid":1215,"":"io task","client":"0","":"downstairs","session_id":"268fbf69-4373-4cad-bbab-177d1380aa12"} {"msg":"connecting to 127.0.0.1:8820","v":0,"name":"crucible","level":30,"time":"2024-09-27T23:07:39.388135912Z","hostname":"w-01J8TVQCPGEHTFRK3TP053XNFM","pid":1215,"":"io task","client":"1","":"downstairs","session_id":"268fbf69-4373-4cad-bbab-177d1380aa12"} {"msg":"ds_connection connected from Ok(127.0.0.1:38646)","v":0,"name":"crucible","level":30,"time":"2024-09-27T23:07:39.388249454Z","hostname":"w-01J8TVQCPGEHTFRK3TP053XNFM","pid":1215,"":"io task","client":"0","":"downstairs","session_id":"268fbf69-4373-4cad-bbab-177d1380aa12"} {"msg":"ds_connection connected from Ok(127.0.0.1:54798)","v":0,"name":"crucible","level":30,"time":"2024-09-27T23:07:39.388262483Z","hostname":"w-01J8TVQCPGEHTFRK3TP053XNFM","pid":1215,"":"io task","client":"2","":"downstairs","session_id":"268fbf69-4373-4cad-bbab-177d1380aa12"} {"msg":"ds_connection connected from Ok(127.0.0.1:55760)","v":0,"name":"crucible","level":30,"time":"2024-09-27T23:07:39.388270572Z","hostname":"w-01J8TVQCPGEHTFRK3TP053XNFM","pid":1215,"":"io task","client":"1","":"downstairs","session_id":"268fbf69-4373-4cad-bbab-177d1380aa12"} {"msg":"ds_transition from New to WaitActive","v":0,"name":"crucible","level":30,"time":"2024-09-27T23:07:39.388585928Z","hostname":"w-01J8TVQCPGEHTFRK3TP053XNFM","pid":1215,"client":"0","":"downstairs","session_id":"268fbf69-4373-4cad-bbab-177d1380aa12"} {"msg":"[0] Transition from New to WaitActive","v":0,"name":"crucible","level":30,"time":"2024-09-27T23:07:39.388606947Z","hostname":"w-01J8TVQCPGEHTFRK3TP053XNFM","pid":1215,"client":"0","":"downstairs","session_id":"268fbf69-4373-4cad-bbab-177d1380aa12"} {"msg":"ds_transition from New to WaitActive","v":0,"name":"crucible","level":30,"time":"2024-09-27T23:07:39.388620535Z","hostname":"w-01J8TVQCPGEHTFRK3TP053XNFM","pid":1215,"client":"1","":"downstairs","session_id":"268fbf69-4373-4cad-bbab-177d1380aa12"} {"msg":"[1] Transition from New to WaitActive","v":0,"name":"crucible","level":30,"time":"2024-09-27T23:07:39.388625645Z","hostname":"w-01J8TVQCPGEHTFRK3TP053XNFM","pid":1215,"client":"1","":"downstairs","session_id":"268fbf69-4373-4cad-bbab-177d1380aa12"} {"msg":"ds_transition from New to WaitActive","v":0,"name":"crucible","level":30,"time":"2024-09-27T23:07:39.388666292Z","hostname":"w-01J8TVQCPGEHTFRK3TP053XNFM","pid":1215,"client":"2","":"downstairs","session_id":"268fbf69-4373-4cad-bbab-177d1380aa12"} {"msg":"[2] Transition from New to WaitActive","v":0,"name":"crucible","level":30,"time":"2024-09-27T23:07:39.388714308Z","hostname":"w-01J8TVQCPGEHTFRK3TP053XNFM","pid":1215,"client":"2","":"downstairs","session_id":"268fbf69-4373-4cad-bbab-177d1380aa12"} {"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-27T23:07:39.388838899Z","hostname":"w-01J8TVQCPGEHTFRK3TP053XNFM","pid":1215,"client":"0","":"downstairs","session_id":"268fbf69-4373-4cad-bbab-177d1380aa12"} {"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-27T23:07:39.388918643Z","hostname":"w-01J8TVQCPGEHTFRK3TP053XNFM","pid":1215,"client":"1","":"downstairs","session_id":"268fbf69-4373-4cad-bbab-177d1380aa12"} {"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-27T23:07:39.389042753Z","hostname":"w-01J8TVQCPGEHTFRK3TP053XNFM","pid":1215,"client":"2","":"downstairs","session_id":"268fbf69-4373-4cad-bbab-177d1380aa12"} {"msg":"ds_transition from WaitActive to WaitQuorum","v":0,"name":"crucible","level":30,"time":"2024-09-27T23:07:39.394444331Z","hostname":"w-01J8TVQCPGEHTFRK3TP053XNFM","pid":1215,"client":"1","":"downstairs","session_id":"268fbf69-4373-4cad-bbab-177d1380aa12"} {"msg":"[1] Transition from WaitActive to WaitQuorum","v":0,"name":"crucible","level":30,"time":"2024-09-27T23:07:39.394468069Z","hostname":"w-01J8TVQCPGEHTFRK3TP053XNFM","pid":1215,"client":"1","":"downstairs","session_id":"268fbf69-4373-4cad-bbab-177d1380aa12"} {"msg":"Waiting for more clients to be ready","v":0,"name":"crucible","level":30,"time":"2024-09-27T23:07:39.394474399Z","hostname":"w-01J8TVQCPGEHTFRK3TP053XNFM","pid":1215,"session_id":"268fbf69-4373-4cad-bbab-177d1380aa12"} {"msg":"ds_transition from WaitActive to WaitQuorum","v":0,"name":"crucible","level":30,"time":"2024-09-27T23:07:39.395604912Z","hostname":"w-01J8TVQCPGEHTFRK3TP053XNFM","pid":1215,"client":"0","":"downstairs","session_id":"268fbf69-4373-4cad-bbab-177d1380aa12"} {"msg":"[0] Transition from WaitActive to WaitQuorum","v":0,"name":"crucible","level":30,"time":"2024-09-27T23:07:39.39563236Z","hostname":"w-01J8TVQCPGEHTFRK3TP053XNFM","pid":1215,"client":"0","":"downstairs","session_id":"268fbf69-4373-4cad-bbab-177d1380aa12"} {"msg":"Waiting for more clients to be ready","v":0,"name":"crucible","level":30,"time":"2024-09-27T23:07:39.39564233Z","hostname":"w-01J8TVQCPGEHTFRK3TP053XNFM","pid":1215,"session_id":"268fbf69-4373-4cad-bbab-177d1380aa12"} {"msg":"ds_transition from WaitActive to WaitQuorum","v":0,"name":"crucible","level":30,"time":"2024-09-27T23:07:39.395650639Z","hostname":"w-01J8TVQCPGEHTFRK3TP053XNFM","pid":1215,"client":"2","":"downstairs","session_id":"268fbf69-4373-4cad-bbab-177d1380aa12"} {"msg":"[2] Transition from WaitActive to WaitQuorum","v":0,"name":"crucible","level":30,"time":"2024-09-27T23:07:39.395661178Z","hostname":"w-01J8TVQCPGEHTFRK3TP053XNFM","pid":1215,"client":"2","":"downstairs","session_id":"268fbf69-4373-4cad-bbab-177d1380aa12"} {"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-27T23:07:39.395698355Z","hostname":"w-01J8TVQCPGEHTFRK3TP053XNFM","pid":1215,"":"downstairs","":"downstairs","session_id":"268fbf69-4373-4cad-bbab-177d1380aa12"} {"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-27T23:07:39.395717164Z","hostname":"w-01J8TVQCPGEHTFRK3TP053XNFM","pid":1215,"":"downstairs","":"downstairs","session_id":"268fbf69-4373-4cad-bbab-177d1380aa12"} {"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-27T23:07:39.395722653Z","hostname":"w-01J8TVQCPGEHTFRK3TP053XNFM","pid":1215,"":"downstairs","":"downstairs","session_id":"268fbf69-4373-4cad-bbab-177d1380aa12"} {"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-27T23:07:39.395727703Z","hostname":"w-01J8TVQCPGEHTFRK3TP053XNFM","pid":1215,"":"downstairs","":"downstairs","session_id":"268fbf69-4373-4cad-bbab-177d1380aa12"} {"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-27T23:07:39.395732892Z","hostname":"w-01J8TVQCPGEHTFRK3TP053XNFM","pid":1215,"":"downstairs","":"downstairs","session_id":"268fbf69-4373-4cad-bbab-177d1380aa12"} {"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-27T23:07:39.395737562Z","hostname":"w-01J8TVQCPGEHTFRK3TP053XNFM","pid":1215,"":"downstairs","":"downstairs","session_id":"268fbf69-4373-4cad-bbab-177d1380aa12"} {"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-27T23:07:39.395743822Z","hostname":"w-01J8TVQCPGEHTFRK3TP053XNFM","pid":1215,"":"downstairs","":"downstairs","session_id":"268fbf69-4373-4cad-bbab-177d1380aa12"} {"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-27T23:07:39.395748081Z","hostname":"w-01J8TVQCPGEHTFRK3TP053XNFM","pid":1215,"":"downstairs","":"downstairs","session_id":"268fbf69-4373-4cad-bbab-177d1380aa12"} {"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-27T23:07:39.395752231Z","hostname":"w-01J8TVQCPGEHTFRK3TP053XNFM","pid":1215,"":"downstairs","":"downstairs","session_id":"268fbf69-4373-4cad-bbab-177d1380aa12"} {"msg":"Max found gen is 1","v":0,"name":"crucible","level":30,"time":"2024-09-27T23:07:39.395758521Z","hostname":"w-01J8TVQCPGEHTFRK3TP053XNFM","pid":1215,"":"downstairs","":"downstairs","session_id":"268fbf69-4373-4cad-bbab-177d1380aa12"} {"msg":"Generation requested: 1 >= found:1","v":0,"name":"crucible","level":30,"time":"2024-09-27T23:07:39.39576708Z","hostname":"w-01J8TVQCPGEHTFRK3TP053XNFM","pid":1215,"":"downstairs","":"downstairs","session_id":"268fbf69-4373-4cad-bbab-177d1380aa12"} {"msg":"Next flush: 1","v":0,"name":"crucible","level":30,"time":"2024-09-27T23:07:39.395776279Z","hostname":"w-01J8TVQCPGEHTFRK3TP053XNFM","pid":1215,"":"downstairs","":"downstairs","session_id":"268fbf69-4373-4cad-bbab-177d1380aa12"} {"msg":"All extents match","v":0,"name":"crucible","level":30,"time":"2024-09-27T23:07:39.395783789Z","hostname":"w-01J8TVQCPGEHTFRK3TP053XNFM","pid":1215,"":"downstairs","":"downstairs","session_id":"268fbf69-4373-4cad-bbab-177d1380aa12"} {"msg":"No downstairs reconciliation required","v":0,"name":"crucible","level":30,"time":"2024-09-27T23:07:39.395800687Z","hostname":"w-01J8TVQCPGEHTFRK3TP053XNFM","pid":1215,"session_id":"268fbf69-4373-4cad-bbab-177d1380aa12"} {"msg":"Transition from WaitQuorum to Active","v":0,"name":"crucible","level":30,"time":"2024-09-27T23:07:39.395805157Z","hostname":"w-01J8TVQCPGEHTFRK3TP053XNFM","pid":1215,"client":"0","":"downstairs","session_id":"268fbf69-4373-4cad-bbab-177d1380aa12"} {"msg":"Transition from WaitQuorum to Active","v":0,"name":"crucible","level":30,"time":"2024-09-27T23:07:39.395809337Z","hostname":"w-01J8TVQCPGEHTFRK3TP053XNFM","pid":1215,"client":"1","":"downstairs","session_id":"268fbf69-4373-4cad-bbab-177d1380aa12"} {"msg":"Transition from WaitQuorum to Active","v":0,"name":"crucible","level":30,"time":"2024-09-27T23:07:39.395813336Z","hostname":"w-01J8TVQCPGEHTFRK3TP053XNFM","pid":1215,"client":"2","":"downstairs","session_id":"268fbf69-4373-4cad-bbab-177d1380aa12"} {"msg":"All required reconciliation work is completed","v":0,"name":"crucible","level":30,"time":"2024-09-27T23:07:39.395818216Z","hostname":"w-01J8TVQCPGEHTFRK3TP053XNFM","pid":1215,"session_id":"268fbf69-4373-4cad-bbab-177d1380aa12"} {"msg":"Set Downstairs and Upstairs active after reconciliation","v":0,"name":"crucible","level":30,"time":"2024-09-27T23:07:39.395822716Z","hostname":"w-01J8TVQCPGEHTFRK3TP053XNFM","pid":1215,"session_id":"268fbf69-4373-4cad-bbab-177d1380aa12"} {"msg":"046bf7a6-afcf-4028-bffa-afead9e0ef88 is now active with session: 268fbf69-4373-4cad-bbab-177d1380aa12","v":0,"name":"crucible","level":30,"time":"2024-09-27T23:07:39.395826475Z","hostname":"w-01J8TVQCPGEHTFRK3TP053XNFM","pid":1215,"session_id":"268fbf69-4373-4cad-bbab-177d1380aa12"} {"msg":"Set Active after no reconciliation","v":0,"name":"crucible","level":30,"time":"2024-09-27T23:07:39.395830995Z","hostname":"w-01J8TVQCPGEHTFRK3TP053XNFM","pid":1215,"session_id":"268fbf69-4373-4cad-bbab-177d1380aa12"} {"msg":"The guest has finished waiting for activation with:1","v":0,"name":"crucible","level":30,"time":"2024-09-27T23:07:39.395845594Z","hostname":"w-01J8TVQCPGEHTFRK3TP053XNFM","pid":1215} Wait for a query_work_queue command to finish before sending IO 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 6.19 30000 1 4848.00 0.00021 0.00067 0.00135 0.05480 16384 1280 rwrites 6.29 30000 1 4767.02 0.00021 0.00077 0.00136 0.06287 16384 1280 rreads 5.37 30000 1 5586.96 0.00018 0.00022 0.00028 0.00661 16384 1280 rreads 5.33 30000 1 5627.18 0.00018 0.00022 0.00027 0.00661 16384 1280 Perf test completed, stop all downstairs Sep 27 23:08:05.028 INFO accepted connection, remote_addr: 127.0.0.1:40626, 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 Sep 27 23:08:05.028[8810] Got stop action so:false kr:false [8820] Disable keep_running INFO[8820] Got stop action so:false kr:false request completed, latency_us:[8830] Disable keep_running [8830] Got stop action so:false kr:false 62, response_code: 204, uri: /shutdown, method: POST, req_id: 02667556-433e-4895-9bd3-becf16d38db6, remote_addr: 127.0.0.1:40626, local_addr: 127.0.0.1:9998 [8830] Exited with: ExitStatus(unix_wait_status(9)) [8830][2] reports Exit [8820] Exited with: ExitStatus(unix_wait_status(9)) [8810] Exited with: ExitStatus(unix_wait_status(9)) [8820][1] reports Exit [8810][0] reports Exit TEST SECONDS COUNT DPTH IOPS MEAN P95 P99 MAX ES EC rwrites 5.15 30000 1 5830.23 0.00017 0.00046 0.00124 0.06689 16384 640 rwrites 5.05 30000 1 5935.09 0.00017 0.00046 0.00119 0.07630 16384 640 rwrites 6.19 30000 1 4848.00 0.00021 0.00067 0.00135 0.05480 16384 1280 rwrites 6.29 30000 1 4767.02 0.00021 0.00077 0.00136 0.06287 16384 1280 TEST SECONDS COUNT DPTH IOPS MEAN P95 P99 MAX ES EC rreads 5.44 30000 1 5512.07 0.00018 0.00023 0.00029 0.00672 16384 640 rreads 5.39 30000 1 5564.10 0.00018 0.00023 0.00028 0.00672 16384 640 rreads 5.37 30000 1 5586.96 0.00018 0.00022 0.00028 0.00661 16384 1280 rreads 5.33 30000 1 5627.18 0.00018 0.00022 0.00027 0.00661 16384 1280 Perf test finished on September 27, 2024 at 11:08:06 PM UTC