Perf test begins at February 12, 2024 at 01:33:46 AM UTC A new loop begins at February 12, 2024 at 01:33:53 AM 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":"Upstairs starts","v":0,"name":"crucible","level":30,"time":"2024-02-12T01:33:53.69216669Z","hostname":"ip-10-150-1-137.us-west-2.compute.internal","pid":1160} {"msg":"Crucible Version: BuildInfo {\n version: \"0.0.1\",\n git_sha: \"9f74bb5fe2be09de9f7a47f2db64d7dce836b79c\",\n git_commit_timestamp: \"2024-02-12T01:11:14.000000000Z\",\n git_branch: \"main\",\n rustc_semver: \"1.75.0\",\n rustc_channel: \"stable\",\n rustc_host_triple: \"x86_64-unknown-illumos\",\n rustc_commit_sha: \"82e1608dfa6e0b5569232559e3d385fea5a93112\",\n cargo_triple: \"x86_64-unknown-illumos\",\n debug: false,\n opt_level: 3,\n}","v":0,"name":"crucible","level":30,"time":"2024-02-12T01:33:53.692376212Z","hostname":"ip-10-150-1-137.us-west-2.compute.internal","pid":1160} {"msg":"Upstairs <-> Downstairs Message Version: 5","v":0,"name":"crucible","level":30,"time":"2024-02-12T01:33:53.692384202Z","hostname":"ip-10-150-1-137.us-west-2.compute.internal","pid":1160} {"msg":"Crucible aaf85fa7-0425-4aff-83bc-0e87b788997f has session id: 2500af7f-0993-4993-a8cd-eecbee9df411","v":0,"name":"crucible","level":30,"time":"2024-02-12T01:33:53.692389662Z","hostname":"ip-10-150-1-137.us-west-2.compute.internal","pid":1160,"session_id":"2500af7f-0993-4993-a8cd-eecbee9df411"} {"msg":"Upstairs opts: Upstairs UUID: aaf85fa7-0425-4aff-83bc-0e87b788997f, 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-02-12T01:33:53.69244254Z","hostname":"ip-10-150-1-137.us-west-2.compute.internal","pid":1160,"session_id":"2500af7f-0993-4993-a8cd-eecbee9df411"} {"msg":"Crucible stats registered with UUID: aaf85fa7-0425-4aff-83bc-0e87b788997f","v":0,"name":"crucible","level":30,"time":"2024-02-12T01:33:53.69244883Z","hostname":"ip-10-150-1-137.us-west-2.compute.internal","pid":1160,"session_id":"2500af7f-0993-4993-a8cd-eecbee9df411"} Crucible runtime is spawned {"msg":"The guest has requested activation with gen:1","v":0,"name":"crucible","level":30,"time":"2024-02-12T01:33:53.692555266Z","hostname":"ip-10-150-1-137.us-west-2.compute.internal","pid":1160} {"msg":"aaf85fa7-0425-4aff-83bc-0e87b788997f active request set","v":0,"name":"crucible","level":30,"time":"2024-02-12T01:33:53.69271904Z","hostname":"ip-10-150-1-137.us-west-2.compute.internal","pid":1160,"session_id":"2500af7f-0993-4993-a8cd-eecbee9df411"} {"msg":"sending connect oneshot to client","v":0,"name":"crucible","level":30,"time":"2024-02-12T01:33:53.692735289Z","hostname":"ip-10-150-1-137.us-west-2.compute.internal","pid":1160,"client":"0","":"downstairs","session_id":"2500af7f-0993-4993-a8cd-eecbee9df411"} {"msg":"client set_active_request while in New; waiting...","v":0,"name":"crucible","level":30,"time":"2024-02-12T01:33:53.692741969Z","hostname":"ip-10-150-1-137.us-west-2.compute.internal","pid":1160,"client":"0","":"downstairs","session_id":"2500af7f-0993-4993-a8cd-eecbee9df411"} {"msg":"sending connect oneshot to client","v":0,"name":"crucible","level":30,"time":"2024-02-12T01:33:53.692749348Z","hostname":"ip-10-150-1-137.us-west-2.compute.internal","pid":1160,"client":"1","":"downstairs","session_id":"2500af7f-0993-4993-a8cd-eecbee9df411"} {"msg":"client set_active_request while in New; waiting...","v":0,"name":"crucible","level":30,"time":"2024-02-12T01:33:53.692755548Z","hostname":"ip-10-150-1-137.us-west-2.compute.internal","pid":1160,"client":"1","":"downstairs","session_id":"2500af7f-0993-4993-a8cd-eecbee9df411"} {"msg":"sending connect oneshot to client","v":0,"name":"crucible","level":30,"time":"2024-02-12T01:33:53.692762658Z","hostname":"ip-10-150-1-137.us-west-2.compute.internal","pid":1160,"client":"2","":"downstairs","session_id":"2500af7f-0993-4993-a8cd-eecbee9df411"} {"msg":"client set_active_request while in New; waiting...","v":0,"name":"crucible","level":30,"time":"2024-02-12T01:33:53.692772958Z","hostname":"ip-10-150-1-137.us-west-2.compute.internal","pid":1160,"client":"2","":"downstairs","session_id":"2500af7f-0993-4993-a8cd-eecbee9df411"} {"msg":"connecting to 127.0.0.1:8810","v":0,"name":"crucible","level":30,"time":"2024-02-12T01:33:53.692787387Z","hostname":"ip-10-150-1-137.us-west-2.compute.internal","pid":1160,"":"io task","client":"0","":"downstairs","session_id":"2500af7f-0993-4993-a8cd-eecbee9df411"} {"msg":"connecting to 127.0.0.1:8830","v":0,"name":"crucible","level":30,"time":"2024-02-12T01:33:53.692811446Z","hostname":"ip-10-150-1-137.us-west-2.compute.internal","pid":1160,"":"io task","client":"2","":"downstairs","session_id":"2500af7f-0993-4993-a8cd-eecbee9df411"} {"msg":"connecting to 127.0.0.1:8820","v":0,"name":"crucible","level":30,"time":"2024-02-12T01:33:53.692821396Z","hostname":"ip-10-150-1-137.us-west-2.compute.internal","pid":1160,"":"io task","client":"1","":"downstairs","session_id":"2500af7f-0993-4993-a8cd-eecbee9df411"} {"msg":"ds_connection connected","v":0,"name":"crucible","level":30,"time":"2024-02-12T01:33:53.692965891Z","hostname":"ip-10-150-1-137.us-west-2.compute.internal","pid":1160,"":"io task","client":"0","":"downstairs","session_id":"2500af7f-0993-4993-a8cd-eecbee9df411"} {"msg":"ds_connection connected","v":0,"name":"crucible","level":30,"time":"2024-02-12T01:33:53.693074866Z","hostname":"ip-10-150-1-137.us-west-2.compute.internal","pid":1160,"":"io task","client":"1","":"downstairs","session_id":"2500af7f-0993-4993-a8cd-eecbee9df411"} {"msg":"ds_connection connected","v":0,"name":"crucible","level":30,"time":"2024-02-12T01:33:53.693088416Z","hostname":"ip-10-150-1-137.us-west-2.compute.internal","pid":1160,"":"io task","client":"2","":"downstairs","session_id":"2500af7f-0993-4993-a8cd-eecbee9df411"} {"msg":"ds_transition from New to WaitActive","v":0,"name":"crucible","level":30,"time":"2024-02-12T01:33:53.693451412Z","hostname":"ip-10-150-1-137.us-west-2.compute.internal","pid":1160,"client":"2","":"downstairs","session_id":"2500af7f-0993-4993-a8cd-eecbee9df411"} {"msg":"[2] Transition from New to WaitActive","v":0,"name":"crucible","level":30,"time":"2024-02-12T01:33:53.693471802Z","hostname":"ip-10-150-1-137.us-west-2.compute.internal","pid":1160,"client":"2","":"downstairs","session_id":"2500af7f-0993-4993-a8cd-eecbee9df411"} {"msg":"ds_transition from New to WaitActive","v":0,"name":"crucible","level":30,"time":"2024-02-12T01:33:53.693479621Z","hostname":"ip-10-150-1-137.us-west-2.compute.internal","pid":1160,"client":"1","":"downstairs","session_id":"2500af7f-0993-4993-a8cd-eecbee9df411"} {"msg":"[1] Transition from New to WaitActive","v":0,"name":"crucible","level":30,"time":"2024-02-12T01:33:53.693485151Z","hostname":"ip-10-150-1-137.us-west-2.compute.internal","pid":1160,"client":"1","":"downstairs","session_id":"2500af7f-0993-4993-a8cd-eecbee9df411"} {"msg":"ds_transition from New to WaitActive","v":0,"name":"crucible","level":30,"time":"2024-02-12T01:33:53.693489651Z","hostname":"ip-10-150-1-137.us-west-2.compute.internal","pid":1160,"client":"0","":"downstairs","session_id":"2500af7f-0993-4993-a8cd-eecbee9df411"} {"msg":"[0] Transition from New to WaitActive","v":0,"name":"crucible","level":30,"time":"2024-02-12T01:33:53.6935109Z","hostname":"ip-10-150-1-137.us-west-2.compute.internal","pid":1160,"client":"0","":"downstairs","session_id":"2500af7f-0993-4993-a8cd-eecbee9df411"} {"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-02-12T01:33:53.693751601Z","hostname":"ip-10-150-1-137.us-west-2.compute.internal","pid":1160,"client":"1","":"downstairs","session_id":"2500af7f-0993-4993-a8cd-eecbee9df411"} {"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-02-12T01:33:53.693767761Z","hostname":"ip-10-150-1-137.us-west-2.compute.internal","pid":1160,"client":"2","":"downstairs","session_id":"2500af7f-0993-4993-a8cd-eecbee9df411"} {"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-02-12T01:33:53.69378062Z","hostname":"ip-10-150-1-137.us-west-2.compute.internal","pid":1160,"client":"0","":"downstairs","session_id":"2500af7f-0993-4993-a8cd-eecbee9df411"} {"msg":"ds_transition from WaitActive to WaitQuorum","v":0,"name":"crucible","level":30,"time":"2024-02-12T01:33:53.696147092Z","hostname":"ip-10-150-1-137.us-west-2.compute.internal","pid":1160,"client":"1","":"downstairs","session_id":"2500af7f-0993-4993-a8cd-eecbee9df411"} {"msg":"[1] Transition from WaitActive to WaitQuorum","v":0,"name":"crucible","level":30,"time":"2024-02-12T01:33:53.696165061Z","hostname":"ip-10-150-1-137.us-west-2.compute.internal","pid":1160,"client":"1","":"downstairs","session_id":"2500af7f-0993-4993-a8cd-eecbee9df411"} {"msg":"Waiting for true more clients to be ready","v":0,"name":"crucible","level":30,"time":"2024-02-12T01:33:53.696170341Z","hostname":"ip-10-150-1-137.us-west-2.compute.internal","pid":1160,"session_id":"2500af7f-0993-4993-a8cd-eecbee9df411"} {"msg":"ds_transition from WaitActive to WaitQuorum","v":0,"name":"crucible","level":30,"time":"2024-02-12T01:33:53.696956552Z","hostname":"ip-10-150-1-137.us-west-2.compute.internal","pid":1160,"client":"0","":"downstairs","session_id":"2500af7f-0993-4993-a8cd-eecbee9df411"} {"msg":"[0] Transition from WaitActive to WaitQuorum","v":0,"name":"crucible","level":30,"time":"2024-02-12T01:33:53.696971862Z","hostname":"ip-10-150-1-137.us-west-2.compute.internal","pid":1160,"client":"0","":"downstairs","session_id":"2500af7f-0993-4993-a8cd-eecbee9df411"} {"msg":"Waiting for true more clients to be ready","v":0,"name":"crucible","level":30,"time":"2024-02-12T01:33:53.696976511Z","hostname":"ip-10-150-1-137.us-west-2.compute.internal","pid":1160,"session_id":"2500af7f-0993-4993-a8cd-eecbee9df411"} {"msg":"ds_transition from WaitActive to WaitQuorum","v":0,"name":"crucible","level":30,"time":"2024-02-12T01:33:53.697097257Z","hostname":"ip-10-150-1-137.us-west-2.compute.internal","pid":1160,"client":"2","":"downstairs","session_id":"2500af7f-0993-4993-a8cd-eecbee9df411"} {"msg":"[2] Transition from WaitActive to WaitQuorum","v":0,"name":"crucible","level":30,"time":"2024-02-12T01:33:53.697117486Z","hostname":"ip-10-150-1-137.us-west-2.compute.internal","pid":1160,"client":"2","":"downstairs","session_id":"2500af7f-0993-4993-a8cd-eecbee9df411"} {"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-02-12T01:33:53.697122586Z","hostname":"ip-10-150-1-137.us-west-2.compute.internal","pid":1160,"":"downstairs","":"downstairs","session_id":"2500af7f-0993-4993-a8cd-eecbee9df411"} {"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-02-12T01:33:53.697127106Z","hostname":"ip-10-150-1-137.us-west-2.compute.internal","pid":1160,"":"downstairs","":"downstairs","session_id":"2500af7f-0993-4993-a8cd-eecbee9df411"} {"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-02-12T01:33:53.697131465Z","hostname":"ip-10-150-1-137.us-west-2.compute.internal","pid":1160,"":"downstairs","":"downstairs","session_id":"2500af7f-0993-4993-a8cd-eecbee9df411"} {"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-02-12T01:33:53.697136875Z","hostname":"ip-10-150-1-137.us-west-2.compute.internal","pid":1160,"":"downstairs","":"downstairs","session_id":"2500af7f-0993-4993-a8cd-eecbee9df411"} {"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-02-12T01:33:53.697141405Z","hostname":"ip-10-150-1-137.us-west-2.compute.internal","pid":1160,"":"downstairs","":"downstairs","session_id":"2500af7f-0993-4993-a8cd-eecbee9df411"} {"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-02-12T01:33:53.697145665Z","hostname":"ip-10-150-1-137.us-west-2.compute.internal","pid":1160,"":"downstairs","":"downstairs","session_id":"2500af7f-0993-4993-a8cd-eecbee9df411"} {"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-02-12T01:33:53.697150055Z","hostname":"ip-10-150-1-137.us-west-2.compute.internal","pid":1160,"":"downstairs","":"downstairs","session_id":"2500af7f-0993-4993-a8cd-eecbee9df411"} {"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-02-12T01:33:53.697154645Z","hostname":"ip-10-150-1-137.us-west-2.compute.internal","pid":1160,"":"downstairs","":"downstairs","session_id":"2500af7f-0993-4993-a8cd-eecbee9df411"} {"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-02-12T01:33:53.697159195Z","hostname":"ip-10-150-1-137.us-west-2.compute.internal","pid":1160,"":"downstairs","":"downstairs","session_id":"2500af7f-0993-4993-a8cd-eecbee9df411"} {"msg":"Max found gen is 1","v":0,"name":"crucible","level":30,"time":"2024-02-12T01:33:53.697164204Z","hostname":"ip-10-150-1-137.us-west-2.compute.internal","pid":1160,"":"downstairs","":"downstairs","session_id":"2500af7f-0993-4993-a8cd-eecbee9df411"} {"msg":"Generation requested: 1 >= found:1","v":0,"name":"crucible","level":30,"time":"2024-02-12T01:33:53.697170204Z","hostname":"ip-10-150-1-137.us-west-2.compute.internal","pid":1160,"":"downstairs","":"downstairs","session_id":"2500af7f-0993-4993-a8cd-eecbee9df411"} {"msg":"Next flush: 1","v":0,"name":"crucible","level":30,"time":"2024-02-12T01:33:53.697174494Z","hostname":"ip-10-150-1-137.us-west-2.compute.internal","pid":1160,"":"downstairs","":"downstairs","session_id":"2500af7f-0993-4993-a8cd-eecbee9df411"} {"msg":"All extents match","v":0,"name":"crucible","level":30,"time":"2024-02-12T01:33:53.697183263Z","hostname":"ip-10-150-1-137.us-west-2.compute.internal","pid":1160,"":"downstairs","":"downstairs","session_id":"2500af7f-0993-4993-a8cd-eecbee9df411"} {"msg":"No downstairs reconciliation required","v":0,"name":"crucible","level":30,"time":"2024-02-12T01:33:53.697194113Z","hostname":"ip-10-150-1-137.us-west-2.compute.internal","pid":1160,"session_id":"2500af7f-0993-4993-a8cd-eecbee9df411"} {"msg":"Transition from WaitQuorum to Active","v":0,"name":"crucible","level":30,"time":"2024-02-12T01:33:53.697198383Z","hostname":"ip-10-150-1-137.us-west-2.compute.internal","pid":1160,"client":"0","":"downstairs","session_id":"2500af7f-0993-4993-a8cd-eecbee9df411"} {"msg":"Transition from WaitQuorum to Active","v":0,"name":"crucible","level":30,"time":"2024-02-12T01:33:53.697203593Z",Wait for a query_work_queue command to finish before sending IO "hostname":"ip-10-150-1-137.us-west-2.compute.internal","pid":1160,"client":"1","":"downstairs","session_id":"2500af7f-0993-4993-a8cd-eecbee9df411"} {"msg":"Transition from WaitQuorum to Active","v":0,"name":"crucible","level":30,"time":"2024-02-12T01:33:53.697213393Z","hostname":"ip-10-150-1-137.us-west-2.compute.internal","pid":1160,"client":"2","":"downstairs","session_id":"2500af7f-0993-4993-a8cd-eecbee9df411"} {"msg":"All required reconciliation work is completed","v":0,"name":"crucible","level":30,"time":"2024-02-12T01:33:53.697220282Z","hostname":"ip-10-150-1-137.us-west-2.compute.internal","pid":1160,"session_id":"2500af7f-0993-4993-a8cd-eecbee9df411"} {"msg":"Set Downstairs and Upstairs active after reconciliation","v":0,"name":"crucible","level":30,"time":"2024-02-12T01:33:53.697226302Z","hostname":"ip-10-150-1-137.us-west-2.compute.internal","pid":1160,"session_id":"2500af7f-0993-4993-a8cd-eecbee9df411"} {"msg":"aaf85fa7-0425-4aff-83bc-0e87b788997f is now active with session: 2500af7f-0993-4993-a8cd-eecbee9df411","v":0,"name":"crucible","level":30,"time":"2024-02-12T01:33:53.697232862Z","hostname":"ip-10-150-1-137.us-west-2.compute.internal","pid":1160,"session_id":"2500af7f-0993-4993-a8cd-eecbee9df411"} {"msg":"Set Active after no reconciliation","v":0,"name":"crucible","level":30,"time":"2024-02-12T01:33:53.697239281Z","hostname":"ip-10-150-1-137.us-west-2.compute.internal","pid":1160,"session_id":"2500af7f-0993-4993-a8cd-eecbee9df411"} {"msg":"The guest has finished waiting for activation with:1","v":0,"name":"crucible","level":30,"time":"2024-02-12T01:33:53.697243421Z","hostname":"ip-10-150-1-137.us-west-2.compute.internal","pid":1160} 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 20.30 30000 1 1478.15 0.00068 0.00145 0.00194 0.03405 16384 640 rwrites 7.07 30000 1 4242.35 0.00024 0.00055 0.00144 0.06235 16384 640 rreads 5.55 30000 1 5402.54 0.00018 0.00023 0.00029 0.01366 16384 640 rreads 5.53 30000 1 5421.63 0.00018 0.00023 0.00028 0.01366 16384 640 {"msg":"Guest handle has been dropped","v":0,"name":"crucible","level":40,"time":"2024-02-12T01:34:41.621353447Z","hostname":"ip-10-150-1-137.us-west-2.compute.internal","pid":1160} A new loop begins at February 12, 2024 at 01:34:51 AM 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":"Upstairs starts","v":0,"name":"crucible","level":30,"time":"2024-02-12T01:34:51.719329588Z","hostname":"ip-10-150-1-137.us-west-2.compute.internal","pid":1179} {"msg":"Crucible Version: BuildInfo {\n version: \"0.0.1\",\n git_sha: \"9f74bb5fe2be09de9f7a47f2db64d7dce836b79c\",\n git_commit_timestamp: \"2024-02-12T01:11:14.000000000Z\",\n git_branch: \"main\",\n rustc_semver: \"1.75.0\",\n rustc_channel: \"stable\",\n rustc_host_triple: \"x86_64-unknown-illumos\",\n rustc_commit_sha: \"82e1608dfa6e0b5569232559e3d385fea5a93112\",\n cargo_triple: \"x86_64-unknown-illumos\",\n debug: false,\n opt_level: 3,\n}"Crucible runtime is spawned ,"v":0,"name":"crucible","level":30,"time":"2024-02-12T01:34:51.719471163Z","hostname":"ip-10-150-1-137.us-west-2.compute.internal","pid":1179} {"msg":"Upstairs <-> Downstairs Message Version: 5","v":0,"name":"crucible","level":30,"time":"2024-02-12T01:34:51.719478442Z","hostname":"ip-10-150-1-137.us-west-2.compute.internal","pid":1179} {"msg":"Crucible 703d94cc-db0c-4851-a990-e449b95de1d6 has session id: bdb0a961-57f6-482c-b37c-a5777ce49cfa","v":0,"name":"crucible","level":30,"time":"2024-02-12T01:34:51.719483662Z","hostname":"ip-10-150-1-137.us-west-2.compute.internal","pid":1179,"session_id":"bdb0a961-57f6-482c-b37c-a5777ce49cfa"} {"msg":"Upstairs opts: Upstairs UUID: 703d94cc-db0c-4851-a990-e449b95de1d6, 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-02-12T01:34:51.719495742Z","hostname":"ip-10-150-1-137.us-west-2.compute.internal","pid":1179,"session_id":"bdb0a961-57f6-482c-b37c-a5777ce49cfa"} {"msg":"Crucible stats registered with UUID: 703d94cc-db0c-4851-a990-e449b95de1d6","v":0,"name":"crucible","level":30,"time":"2024-02-12T01:34:51.719502902Z","hostname":"ip-10-150-1-137.us-west-2.compute.internal","pid":1179,"session_id":"bdb0a961-57f6-482c-b37c-a5777ce49cfa"} {"msg":"The guest has requested activation with gen:1","v":0,"name":"crucible","level":30,"time":"2024-02-12T01:34:51.719508361Z","hostname":"ip-10-150-1-137.us-west-2.compute.internal","pid":1179} {"msg":"703d94cc-db0c-4851-a990-e449b95de1d6 active request set","v":0,"name":"crucible","level":30,"time":"2024-02-12T01:34:51.719575889Z","hostname":"ip-10-150-1-137.us-west-2.compute.internal","pid":1179,"session_id":"bdb0a961-57f6-482c-b37c-a5777ce49cfa"} {"msg":"sending connect oneshot to client","v":0,"name":"crucible","level":30,"time":"2024-02-12T01:34:51.719591618Z","hostname":"ip-10-150-1-137.us-west-2.compute.internal","pid":1179,"client":"0","":"downstairs","session_id":"bdb0a961-57f6-482c-b37c-a5777ce49cfa"} {"msg":"client set_active_request while in New; waiting...","v":0,"name":"crucible","level":30,"time":"2024-02-12T01:34:51.719602008Z","hostname":"ip-10-150-1-137.us-west-2.compute.internal","pid":1179,"client":"0","":"downstairs","session_id":"bdb0a961-57f6-482c-b37c-a5777ce49cfa"} {"msg":"sending connect oneshot to client","v":0,"name":"crucible","level":30,"time":"2024-02-12T01:34:51.719608098Z","hostname":"ip-10-150-1-137.us-west-2.compute.internal","pid":1179,"client":"1","":"downstairs","session_id":"bdb0a961-57f6-482c-b37c-a5777ce49cfa"} {"msg":"client set_active_request while in New; waiting...","v":0,"name":"crucible","level":30,"time":"2024-02-12T01:34:51.719614217Z","hostname":"ip-10-150-1-137.us-west-2.compute.internal","pid":1179,"client":"1","":"downstairs","session_id":"bdb0a961-57f6-482c-b37c-a5777ce49cfa"} {"msg":"sending connect oneshot to client","v":0,"name":"crucible","level":30,"time":"2024-02-12T01:34:51.719620397Z","hostname":"ip-10-150-1-137.us-west-2.compute.internal","pid":1179,"client":"2","":"downstairs","session_id":"bdb0a961-57f6-482c-b37c-a5777ce49cfa"} {"msg":"client set_active_request while in New; waiting...","v":0,"name":"crucible","level":30,"time":"2024-02-12T01:34:51.719626077Z","hostname":"ip-10-150-1-137.us-west-2.compute.internal","pid":1179,"client":"2","":"downstairs","session_id":"bdb0a961-57f6-482c-b37c-a5777ce49cfa"} {"msg":"connecting to 127.0.0.1:8810","v":0,"name":"crucible","level":30,"time":"2024-02-12T01:34:51.719635877Z","hostname":"ip-10-150-1-137.us-west-2.compute.internal","pid":1179,"":"io task","client":"0","":"downstairs","session_id":"bdb0a961-57f6-482c-b37c-a5777ce49cfa"} {"msg":"connecting to 127.0.0.1:8820","v":0,"name":"crucible","level":30,"time":"2024-02-12T01:34:51.719651516Z","hostname":"ip-10-150-1-137.us-west-2.compute.internal","pid":1179,"":"io task","client":"1","":"downstairs","session_id":"bdb0a961-57f6-482c-b37c-a5777ce49cfa"} {"msg":"connecting to 127.0.0.1:8830","v":0,"name":"crucible","level":30,"time":"2024-02-12T01:34:51.719657356Z","hostname":"ip-10-150-1-137.us-west-2.compute.internal","pid":1179,"":"io task","client":"2","":"downstairs","session_id":"bdb0a961-57f6-482c-b37c-a5777ce49cfa"} {"msg":"ds_connection connected","v":0,"name":"crucible","level":30,"time":"2024-02-12T01:34:51.719755272Z","hostname":"ip-10-150-1-137.us-west-2.compute.internal","pid":1179,"":"io task","client":"2","":"downstairs","session_id":"bdb0a961-57f6-482c-b37c-a5777ce49cfa"} {"msg":"ds_connection connected","v":0,"name":"crucible","level":30,"time":"2024-02-12T01:34:51.719849498Z","hostname":"ip-10-150-1-137.us-west-2.compute.internal","pid":1179,"":"io task","client":"1","":"downstairs","session_id":"bdb0a961-57f6-482c-b37c-a5777ce49cfa"} {"msg":"ds_connection connected","v":0,"name":"crucible","level":30,"time":"2024-02-12T01:34:51.719866098Z","hostname":"ip-10-150-1-137.us-west-2.compute.internal","pid":1179,"":"io task","client":"0","":"downstairs","session_id":"bdb0a961-57f6-482c-b37c-a5777ce49cfa"} {"msg":"ds_transition from New to WaitActive","v":0,"name":"crucible","level":30,"time":"2024-02-12T01:34:51.720162527Z","hostname":"ip-10-150-1-137.us-west-2.compute.internal","pid":1179,"client":"2","":"downstairs","session_id":"bdb0a961-57f6-482c-b37c-a5777ce49cfa"} {"msg":"[2] Transition from New to WaitActive","v":0,"name":"crucible","level":30,"time":"2024-02-12T01:34:51.720182836Z","hostname":"ip-10-150-1-137.us-west-2.compute.internal","pid":1179,"client":"2","":"downstairs","session_id":"bdb0a961-57f6-482c-b37c-a5777ce49cfa"} {"msg":"ds_transition from New to WaitActive","v":0,"name":"crucible","level":30,"time":"2024-02-12T01:34:51.720189176Z","hostname":"ip-10-150-1-137.us-west-2.compute.internal","pid":1179,"client":"0","":"downstairs","session_id":"bdb0a961-57f6-482c-b37c-a5777ce49cfa"} {"msg":"[0] Transition from New to WaitActive","v":0,"name":"crucible","level":30,"time":"2024-02-12T01:34:51.720195286Z","hostname":"ip-10-150-1-137.us-west-2.compute.internal","pid":1179,"client":"0","":"downstairs","session_id":"bdb0a961-57f6-482c-b37c-a5777ce49cfa"} {"msg":"ds_transition from New to WaitActive","v":0,"name":"crucible","level":30,"time":"2024-02-12T01:34:51.720203936Z","hostname":"ip-10-150-1-137.us-west-2.compute.internal","pid":1179,"client":"1","":"downstairs","session_id":"bdb0a961-57f6-482c-b37c-a5777ce49cfa"} {"msg":"[1] Transition from New to WaitActive","v":0,"name":"crucible","level":30,"time":"2024-02-12T01:34:51.720209175Z","hostname":"ip-10-150-1-137.us-west-2.compute.internal","pid":1179,"client":"1","":"downstairs","session_id":"bdb0a961-57f6-482c-b37c-a5777ce49cfa"} {"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-02-12T01:34:51.720402258Z","hostname":"ip-10-150-1-137.us-west-2.compute.internal","pid":1179,"client":"2","":"downstairs","session_id":"bdb0a961-57f6-482c-b37c-a5777ce49cfa"} {"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-02-12T01:34:51.720420017Z","hostname":"ip-10-150-1-137.us-west-2.compute.internal","pid":1179,"client":"1","":"downstairs","session_id":"bdb0a961-57f6-482c-b37c-a5777ce49cfa"} {"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-02-12T01:34:51.720428587Z","hostname":"ip-10-150-1-137.us-west-2.compute.internal","pid":1179,"client":"0","":"downstairs","session_id":"bdb0a961-57f6-482c-b37c-a5777ce49cfa"} {"msg":"ds_transition from WaitActive to WaitQuorum","v":0,"name":"crucible","level":30,"time":"2024-02-12T01:34:51.725912553Z","hostname":"ip-10-150-1-137.us-west-2.compute.internal","pid":1179,"client":"2","":"downstairs","session_id":"bdb0a961-57f6-482c-b37c-a5777ce49cfa"} {"msg":"[2] Transition from WaitActive to WaitQuorum","v":0,"name":"crucible","level":30,"time":"2024-02-12T01:34:51.725929103Z","hostname":"ip-10-150-1-137.us-west-2.compute.internal","pid":1179,"client":"2","":"downstairs","session_id":"bdb0a961-57f6-482c-b37c-a5777ce49cfa"} {"msg":"Waiting for true more clients to be ready","v":0,"name":"crucible","level":30,"time":"2024-02-12T01:34:51.725934052Z","hostname":"ip-10-150-1-137.us-west-2.compute.internal","pid":1179,"session_id":"bdb0a961-57f6-482c-b37c-a5777ce49cfa"} {"msg":"ds_transition from WaitActive to WaitQuorum","v":0,"name":"crucible","level":30,"time":"2024-02-12T01:34:51.72627043Z","hostname":"ip-10-150-1-137.us-west-2.compute.internal","pid":1179,"client":"1","":"downstairs","session_id":"bdb0a961-57f6-482c-b37c-a5777ce49cfa"} {"msg":"[1] Transition from WaitActive to WaitQuorum","v":0,"name":"crucible","level":30,"time":"2024-02-12T01:34:51.726285369Z","hostname":"ip-10-150-1-137.us-west-2.compute.internal","pid":1179,"client":"1","":"downstairs","session_id":"bdb0a961-57f6-482c-b37c-a5777ce49cfa"} {"msg":"Waiting for true more clients to be ready","v":0,"name":"crucible","level":30,"time":"2024-02-12T01:34:51.726289909Z","hostname":"ip-10-150-1-137.us-west-2.compute.internal","pid":1179,"session_id":"bdb0a961-57f6-482c-b37c-a5777ce49cfa"} {"msg":"ds_transition from WaitActive to WaitQuorum","v":0,"name":"crucible","level":30,"time":"2024-02-12T01:34:51.726395725Z","hostname":"ip-10-150-1-137.us-west-2.compute.internal","pid":1179,"client":"0","":"downstairs","session_id":"bdb0a961-57f6-482c-b37c-a5777ce49cfa"} {"msg":"[0] Transition from WaitActive to WaitQuorum","v":0,"name":"crucible","level":30,"time":"2024-02-12T01:34:51.726411725Z","hostname":"ip-10-150-1-137.us-west-2.compute.internal","pid":1179,"client":"0","":"downstairs","session_id":"bdb0a961-57f6-482c-b37c-a5777ce49cfa"} {"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-02-12T01:34:51.726416944Z","hostname":"ip-10-150-1-137.us-west-2.compute.internal","pid":1179,"":"downstairs","":"downstairs","session_id":"bdb0a961-57f6-482c-b37c-a5777ce49cfa"} {"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-02-12T01:34:51.726421584Z","hostname":"ip-10-150-1-137.us-west-2.compute.internal","pid":1179,"":"downstairs","":"downstairs","session_id":"bdb0a961-57f6-482c-b37c-a5777ce49cfa"} {"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-02-12T01:34:51.726425964Z","hostname":"ip-10-150-1-137.us-west-2.compute.internal","pid":1179,"":"downstairs","":"downstairs","session_id":"bdb0a961-57f6-482c-b37c-a5777ce49cfa"} {"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-02-12T01:34:51.726430224Z","hostname":"ip-10-150-1-137.us-west-2.compute.internal","pid":1179,"":"downstairs","":"downstairs","session_id":"bdb0a961-57f6-482c-b37c-a5777ce49cfa"} {"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-02-12T01:34:51.726434334Z","hostname":"ip-10-150-1-137.us-west-2.compute.internal","pid":1179,"":"downstairs","":"downstairs","session_id":"bdb0a961-57f6-482c-b37c-a5777ce49cfa"} {"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-02-12T01:34:51.726439253Z","hostname":"ip-10-150-1-137.us-west-2.compute.internal","pid":1179,"":"downstairs","":"downstairs","session_id":"bdb0a961-57f6-482c-b37c-a5777ce49cfa"} {"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-02-12T01:34:51.726443863Z","hostname":"ip-10-150-1-137.us-west-2.compute.internal","pid":1179,"":"downstairs","":"downstairs","session_id":"bdb0a961-57f6-482c-b37c-a5777ce49cfa"} {"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-02-12T01:34:51.726448063Z","hostname":"ip-10-150-1-137.us-west-2.compute.internal","pid":1179,"":"downstairs","":"downstairs","session_id":"bdb0a961-57f6-482c-b37c-a5777ce49cfa"} {"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-02-12T01:34:51.726452693Z","hostname":"ip-10-150-1-137.us-west-2.compute.internal","pid":1179,"":"downstairs","":"downstairs","session_id":"bdb0a961-57f6-482c-b37c-a5777ce49cfa"} {"msg":"Max found gen is 1","v":0,"name":"crucible","level":30,"time":"2024-02-12T01:34:51.726457043Z","hostname":"ip-10-150-1-137.us-west-2.compute.internal","pid":1179,"":"downstairs","":"downstairs","session_id":"bdb0a961-57f6-482c-b37c-a5777ce49cfa"} {"msg":"Generation requested: 1 >= found:1","v":0,"name":"crucible","level":30,"time":"2024-02-12T01:34:51.726461593Z","hostname":"ip-10-150-1-137.us-west-2.compute.internal","pid":1179,"":"downstairs","":"downstairs","session_id":"bdb0a961-57f6-482c-b37c-a5777ce49cfa"} {"msg":"Next flush: 1","v":0,"name":"crucible","level":30,"time":"2024-02-12T01:34:51.726466352Z","hostname":"ip-10-150-1-137.us-west-2.compute.internal","pid":1179,"":"downstairs","":"downstairs","session_id":"bdb0a961-57f6-482c-b37c-a5777ce49cfa"} {"msg":"All extents match","v":0,"name":"crucible","level":30,"time":"2024-02-12T01:34:51.726470642Z","hostname":"ip-10-150-1-137.us-west-2.compute.internal","pid":1179,"":"downstairs","":"downstairs","session_id":"bdb0a961-57f6-482c-b37c-a5777ce49cfa"} Wait for a query_work_queue command to finish before sending IO {"msg":"No downstairs reconciliation required","v":0,"name":"crucible","level":30,"time":"2024-02-12T01:34:51.726479682Z","hostname":"ip-10-150-1-137.us-west-2.compute.internal","pid":1179,"session_id":"bdb0a961-57f6-482c-b37c-a5777ce49cfa"} {"msg":"Transition from WaitQuorum to Active","v":0,"name":"crucible","level":30,"time":"2024-02-12T01:34:51.726483652Z","hostname":"ip-10-150-1-137.us-west-2.compute.internal","pid":1179,"client":"0","":"downstairs","session_id":"bdb0a961-57f6-482c-b37c-a5777ce49cfa"} {"msg":"Transition from WaitQuorum to Active","v":0,"name":"crucible","level":30,"time":"2024-02-12T01:34:51.726487782Z","hostname":"ip-10-150-1-137.us-west-2.compute.internal","pid":1179,"client":"1","":"downstairs","session_id":"bdb0a961-57f6-482c-b37c-a5777ce49cfa"} {"msg":"Transition from WaitQuorum to Active","v":0,"name":"crucible","level":30,"time":"2024-02-12T01:34:51.726491862Z","hostname":"ip-10-150-1-137.us-west-2.compute.internal","pid":1179,"client":"2","":"downstairs","session_id":"bdb0a961-57f6-482c-b37c-a5777ce49cfa"} {"msg":"All required reconciliation work is completed","v":0,"name":"crucible","level":30,"time":"2024-02-12T01:34:51.726496881Z","hostname":"ip-10-150-1-137.us-west-2.compute.internal","pid":1179,"session_id":"bdb0a961-57f6-482c-b37c-a5777ce49cfa"} {"msg":"Set Downstairs and Upstairs active after reconciliation","v":0,"name":"crucible","level":30,"time":"2024-02-12T01:34:51.726500771Z","hostname":"ip-10-150-1-137.us-west-2.compute.internal","pid":1179,"session_id":"bdb0a961-57f6-482c-b37c-a5777ce49cfa"} {"msg":"703d94cc-db0c-4851-a990-e449b95de1d6 is now active with session: bdb0a961-57f6-482c-b37c-a5777ce49cfa","v":0,"name":"crucible","level":30,"time":"2024-02-12T01:34:51.726504641Z","hostname":"ip-10-150-1-137.us-west-2.compute.internal","pid":1179,"session_id":"bdb0a961-57f6-482c-b37c-a5777ce49cfa"} {"msg":"Set Active after no reconciliation","v":0,"name":"crucible","level":30,"time":"2024-02-12T01:34:51.726509141Z","hostname":"ip-10-150-1-137.us-west-2.compute.internal","pid":1179,"session_id":"bdb0a961-57f6-482c-b37c-a5777ce49cfa"} {"msg":"The guest has finished waiting for activation with:1","v":0,"name":"crucible","level":30,"time":"2024-02-12T01:34:51.726512941Z","hostname":"ip-10-150-1-137.us-west-2.compute.internal","pid":1179} 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 8.49 30000 1 3533.95 0.00028 0.00062 0.00141 0.06780 16384 1280 rwrites 8.55 30000 1 3510.79 0.00028 0.00064 0.00128 0.05980 16384 1280 rreads 5.62 30000 1 5339.63 0.00019 0.00025 0.00029 0.01469 16384 1280 rreads 5.59 30000 1 5370.32 0.00019 0.00025 0.00029 0.01469 16384 1280 Perf test finished on February 12, 2024 at 01:35:25 AM UTC