Perf test begins at February 15, 2024 at 02:55:36 AM UTC A new loop begins at February 15, 2024 at 02:55:43 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-15T02:55:43.581274645Z","hostname":"ip-10-150-1-195.us-west-2.compute.internal","pid":1160} {"msg":"Crucible Version: BuildInfo {\n version: \"0.0.1\",\n git_sha: \"56eb785b9570b1bd468a7aafe9af80e337a7fae9\",\n git_commit_timestamp: \"2024-02-15T02:33:40.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-15T02:55:43.581454645Z","hostname":"ip-10-150-1-195.us-west-2.compute.internal","pid":1160} {"msg":"Upstairs <-> Downstairs Message Version: 5","v":0,"name":"crucible","level":30,"time":"2024-02-15T02:55:43.581462634Z","hostname":"ip-10-150-1-195.us-west-2.compute.internal","pid":1160} {"msg":"Crucible 98c8105a-e246-4e01-9853-61babd1c52be has session id: 73ee2047-65f9-46df-80dd-7f5fc13549cd","v":0,"name":"crucible","level":30,"time":"2024-02-15T02:55:43.581468004Z","hostname":"ip-10-150-1-195.us-west-2.compute.internal","pid":1160,"session_id":"73ee2047-65f9-46df-80dd-7f5fc13549cd"} {"msg":"Upstairs opts: Upstairs UUID: 98c8105a-e246-4e01-9853-61babd1c52be, 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-15T02:55:43.581568658Z","hostname":"ip-10-150-1-195.us-west-2.compute.internal","pid":1160,"session_id":"73ee2047-65f9-46df-80dd-7f5fc13549cd"} {"msg":"Crucible stats registered with UUID: 98c8105a-e246-4e01-9853-61babd1c52be","v":0,"name":"crucible","level":30,"time":"2024-02-15T02:55:43.581576438Z","hostname":"ip-10-150-1-195.us-west-2.compute.internal","pid":1160,"session_id":"73ee2047-65f9-46df-80dd-7f5fc13549cd"} Crucible runtime is spawned {"msg":"The guest has requested activation with gen:1","v":0,"name":"crucible","level":30,"time":"2024-02-15T02:55:43.581679352Z","hostname":"ip-10-150-1-195.us-west-2.compute.internal","pid":1160} {"msg":"98c8105a-e246-4e01-9853-61babd1c52be active request set","v":0,"name":"crucible","level":30,"time":"2024-02-15T02:55:43.58186957Z","hostname":"ip-10-150-1-195.us-west-2.compute.internal","pid":1160,"session_id":"73ee2047-65f9-46df-80dd-7f5fc13549cd"} {"msg":"sending connect oneshot to client","v":0,"name":"crucible","level":30,"time":"2024-02-15T02:55:43.581891779Z","hostname":"ip-10-150-1-195.us-west-2.compute.internal","pid":1160,"client":"0","":"downstairs","session_id":"73ee2047-65f9-46df-80dd-7f5fc13549cd"} {"msg":"client set_active_request while in New; waiting...","v":0,"name":"crucible","level":30,"time":"2024-02-15T02:55:43.581902739Z","hostname":"ip-10-150-1-195.us-west-2.compute.internal","pid":1160,"client":"0","":"downstairs","session_id":"73ee2047-65f9-46df-80dd-7f5fc13549cd"} {"msg":"sending connect oneshot to client","v":0,"name":"crucible","level":30,"time":"2024-02-15T02:55:43.581912638Z","hostname":"ip-10-150-1-195.us-west-2.compute.internal","pid":1160,"client":"1","":"downstairs","session_id":"73ee2047-65f9-46df-80dd-7f5fc13549cd"} {"msg":"client set_active_request while in New; waiting...","v":0,"name":"crucible","level":30,"time":"2024-02-15T02:55:43.581922258Z","hostname":"ip-10-150-1-195.us-west-2.compute.internal","pid":1160,"client":"1","":"downstairs","session_id":"73ee2047-65f9-46df-80dd-7f5fc13549cd"} {"msg":"sending connect oneshot to client","v":0,"name":"crucible","level":30,"time":"2024-02-15T02:55:43.581931117Z","hostname":"ip-10-150-1-195.us-west-2.compute.internal","pid":1160,"client":"2","":"downstairs","session_id":"73ee2047-65f9-46df-80dd-7f5fc13549cd"} {"msg":"client set_active_request while in New; waiting...","v":0,"name":"crucible","level":30,"time":"2024-02-15T02:55:43.581940716Z","hostname":"ip-10-150-1-195.us-west-2.compute.internal","pid":1160,"client":"2","":"downstairs","session_id":"73ee2047-65f9-46df-80dd-7f5fc13549cd"} {"msg":"connecting to 127.0.0.1:8830","v":0,"name":"crucible","level":30,"time":"2024-02-15T02:55:43.581950886Z","hostname":"ip-10-150-1-195.us-west-2.compute.internal","pid":1160,"":"io task","client":"2","":"downstairs","session_id":"73ee2047-65f9-46df-80dd-7f5fc13549cd"} {"msg":"connecting to 127.0.0.1:8820","v":0,"name":"crucible","level":30,"time":"2024-02-15T02:55:43.581982674Z","hostname":"ip-10-150-1-195.us-west-2.compute.internal","pid":1160,"":"io task","client":"1","":"downstairs","session_id":"73ee2047-65f9-46df-80dd-7f5fc13549cd"} {"msg":"connecting to 127.0.0.1:8810","v":0,"name":"crucible","level":30,"time":"2024-02-15T02:55:43.581993133Z","hostname":"ip-10-150-1-195.us-west-2.compute.internal","pid":1160,"":"io task","client":"0","":"downstairs","session_id":"73ee2047-65f9-46df-80dd-7f5fc13549cd"} {"msg":"ds_connection connected","v":0,"name":"crucible","level":30,"time":"2024-02-15T02:55:43.582072849Z","hostname":"ip-10-150-1-195.us-west-2.compute.internal","pid":1160,"":"io task","client":"0","":"downstairs","session_id":"73ee2047-65f9-46df-80dd-7f5fc13549cd"} {"msg":"ds_connection connected","v":0,"name":"crucible","level":30,"time":"2024-02-15T02:55:43.582183352Z","hostname":"ip-10-150-1-195.us-west-2.compute.internal","pid":1160,"":"io task","client":"1","":"downstairs","session_id":"73ee2047-65f9-46df-80dd-7f5fc13549cd"} {"msg":"ds_connection connected","v":0,"name":"crucible","level":30,"time":"2024-02-15T02:55:43.582195591Z","hostname":"ip-10-150-1-195.us-west-2.compute.internal","pid":1160,"":"io task","client":"2","":"downstairs","session_id":"73ee2047-65f9-46df-80dd-7f5fc13549cd"} {"msg":"ds_transition from New to WaitActive","v":0,"name":"crucible","level":30,"time":"2024-02-15T02:55:43.582642586Z","hostname":"ip-10-150-1-195.us-west-2.compute.internal","pid":1160,"client":"1","":"downstairs","session_id":"73ee2047-65f9-46df-80dd-7f5fc13549cd"} {"msg":"[1] Transition from New to WaitActive","v":0,"name":"crucible","level":30,"time":"2024-02-15T02:55:43.582658915Z","hostname":"ip-10-150-1-195.us-west-2.compute.internal","pid":1160,"client":"1","":"downstairs","session_id":"73ee2047-65f9-46df-80dd-7f5fc13549cd"} {"msg":"ds_transition from New to WaitActive","v":0,"name":"crucible","level":30,"time":"2024-02-15T02:55:43.582691783Z","hostname":"ip-10-150-1-195.us-west-2.compute.internal","pid":1160,"client":"2","":"downstairs","session_id":"73ee2047-65f9-46df-80dd-7f5fc13549cd"} {"msg":"[2] Transition from New to WaitActive","v":0,"name":"crucible","level":30,"time":"2024-02-15T02:55:43.582698762Z","hostname":"ip-10-150-1-195.us-west-2.compute.internal","pid":1160,"client":"2","":"downstairs","session_id":"73ee2047-65f9-46df-80dd-7f5fc13549cd"} {"msg":"ds_transition from New to WaitActive","v":0,"name":"crucible","level":30,"time":"2024-02-15T02:55:43.582706502Z","hostname":"ip-10-150-1-195.us-west-2.compute.internal","pid":1160,"client":"0","":"downstairs","session_id":"73ee2047-65f9-46df-80dd-7f5fc13549cd"} {"msg":"[0] Transition from New to WaitActive","v":0,"name":"crucible","level":30,"time":"2024-02-15T02:55:43.582714661Z","hostname":"ip-10-150-1-195.us-west-2.compute.internal","pid":1160,"client":"0","":"downstairs","session_id":"73ee2047-65f9-46df-80dd-7f5fc13549cd"} {"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-15T02:55:43.583039262Z","hostname":"ip-10-150-1-195.us-west-2.compute.internal","pid":1160,"client":"0","":"downstairs","session_id":"73ee2047-65f9-46df-80dd-7f5fc13549cd"} {"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-15T02:55:43.583059661Z","hostname":"ip-10-150-1-195.us-west-2.compute.internal","pid":1160,"client":"2","":"downstairs","session_id":"73ee2047-65f9-46df-80dd-7f5fc13549cd"} {"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-15T02:55:43.58309113Z","hostname":"ip-10-150-1-195.us-west-2.compute.internal","pid":1160,"client":"1","":"downstairs","session_id":"73ee2047-65f9-46df-80dd-7f5fc13549cd"} {"msg":"ds_transition from WaitActive to WaitQuorum","v":0,"name":"crucible","level":30,"time":"2024-02-15T02:55:43.586977154Z","hostname":"ip-10-150-1-195.us-west-2.compute.internal","pid":1160,"client":"2","":"downstairs","session_id":"73ee2047-65f9-46df-80dd-7f5fc13549cd"} {"msg":"[2] Transition from WaitActive to WaitQuorum","v":0,"name":"crucible","level":30,"time":"2024-02-15T02:55:43.586998592Z","hostname":"ip-10-150-1-195.us-west-2.compute.internal","pid":1160,"client":"2","":"downstairs","session_id":"73ee2047-65f9-46df-80dd-7f5fc13549cd"} {"msg":"Waiting for true more clients to be ready","v":0,"name":"crucible","level":30,"time":"2024-02-15T02:55:43.587004962Z","hostname":"ip-10-150-1-195.us-west-2.compute.internal","pid":1160,"session_id":"73ee2047-65f9-46df-80dd-7f5fc13549cd"} {"msg":"ds_transition from WaitActive to WaitQuorum","v":0,"name":"crucible","level":30,"time":"2024-02-15T02:55:43.58722155Z","hostname":"ip-10-150-1-195.us-west-2.compute.internal","pid":1160,"client":"1","":"downstairs","session_id":"73ee2047-65f9-46df-80dd-7f5fc13549cd"} {"msg":"[1] Transition from WaitActive to WaitQuorum","v":0,"name":"crucible","level":30,"time":"2024-02-15T02:55:43.587236659Z","hostname":"ip-10-150-1-195.us-west-2.compute.internal","pid":1160,"client":"1","":"downstairs","session_id":"73ee2047-65f9-46df-80dd-7f5fc13549cd"} {"msg":"Waiting for true more clients to be ready","v":0,"name":"crucible","level":30,"time":"2024-02-15T02:55:43.587241628Z","hostname":"ip-10-150-1-195.us-west-2.compute.internal","pid":1160,"session_id":"73ee2047-65f9-46df-80dd-7f5fc13549cd"} {"msg":"ds_transition from WaitActive to WaitQuorum","v":0,"name":"crucible","level":30,"time":"2024-02-15T02:55:43.593077559Z","hostname":"ip-10-150-1-195.us-west-2.compute.internal","pid":1160,"client":"0","":"downstairs","session_id":"73ee2047-65f9-46df-80dd-7f5fc13549cd"} {"msg":"[0] Transition from WaitActive to WaitQuorum","v":0,"name":"crucible","level":30,"time":"2024-02-15T02:55:43.593094668Z","hostname":"ip-10-150-1-195.us-west-2.compute.internal","pid":1160,"client":"0","":"downstairs","session_id":"73ee2047-65f9-46df-80dd-7f5fc13549cd"} {"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-15T02:55:43.593133226Z","hostname":"ip-10-150-1-195.us-west-2.compute.internal","pid":1160,"":"downstairs","":"downstairs","session_id":"73ee2047-65f9-46df-80dd-7f5fc13549cd"} {"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-15T02:55:43.593146855Z","hostname":"ip-10-150-1-195.us-west-2.compute.internal","pid":1160,"":"downstairs","":"downstairs","session_id":"73ee2047-65f9-46df-80dd-7f5fc13549cd"} {"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-15T02:55:43.593151985Z","hostname":"ip-10-150-1-195.us-west-2.compute.internal","pid":1160,"":"downstairs","":"downstairs","session_id":"73ee2047-65f9-46df-80dd-7f5fc13549cd"} {"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-15T02:55:43.593156825Z","hostname":"ip-10-150-1-195.us-west-2.compute.internal","pid":1160,"":"downstairs","":"downstairs","session_id":"73ee2047-65f9-46df-80dd-7f5fc13549cd"} {"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-15T02:55:43.593161794Z","hostname":"ip-10-150-1-195.us-west-2.compute.internal","pid":1160,"":"downstairs","":"downstairs","session_id":"73ee2047-65f9-46df-80dd-7f5fc13549cd"} {"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-15T02:55:43.593165974Z","hostname":"ip-10-150-1-195.us-west-2.compute.internal","pid":1160,"":"downstairs","":"downstairs","session_id":"73ee2047-65f9-46df-80dd-7f5fc13549cd"} {"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-15T02:55:43.593170464Z","hostname":"ip-10-150-1-195.us-west-2.compute.internal","pid":1160,"":"downstairs","":"downstairs","session_id":"73ee2047-65f9-46df-80dd-7f5fc13549cd"} {"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-15T02:55:43.593174713Z","hostname":"ip-10-150-1-195.us-west-2.compute.internal","pid":1160,"":"downstairs","":"downstairs","session_id":"73ee2047-65f9-46df-80dd-7f5fc13549cd"} {"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-15T02:55:43.593179383Z","hostname":"ip-10-150-1-195.us-west-2.compute.internal","pid":1160,"":"downstairs","":"downstairs","session_id":"73ee2047-65f9-46df-80dd-7f5fc13549cd"} {"msg":"Max found gen is 1","v":0,"name":"crucible","level":30,"time":"2024-02-15T02:55:43.593183763Z","hostname":"ip-10-150-1-195.us-west-2.compute.internal","pid":1160,"":"downstairs","":"downstairs","session_id":"73ee2047-65f9-46df-80dd-7f5fc13549cd"} {"msg":"Generation requested: 1 >= found:1","v":0,"name":"crucible","level":30,"time":"2024-02-15T02:55:43.593188223Z","hostname":"ip-10-150-1-195.us-west-2.compute.internal","pid":1160,"":"downstairs","":"downstairs","session_id":"73ee2047-65f9-46df-80dd-7f5fc13549cd"} {"msg":"Next flush: 1","v":0,"name":"crucible","level":30,"time":"2024-02-15T02:55:43.593192992Z","hostname":"ip-10-150-1-195.us-west-2.compute.internal","pid":1160,"":"downstairs","":"downstairs","session_id":"73ee2047-65f9-46df-80dd-7f5fc13549cd"} {"msg":"All extents match","v":0,"name":"crucible","level":30,"time":"2024-02-15T02:55:43.593197972Z","hostname":"ip-10-150-1-195.us-west-2.compute.internal","pid":1160,"":"downstairs","":"downstairs","session_id":"73ee2047-65f9-46df-80dd-7f5fc13549cd"} {"msg":"No downstairs reconciliation required","v":0,"name":"crucible","level":30,"time":"2024-02-15T02:55:43.593202962Z","hostname":"ip-10-150-1-195.us-west-2.compute.internal","pid":1160,"session_id":"73ee2047-65f9-46df-80dd-7f5fc13549cd"} {"msg":"Transition from WaitQuorum to Active","v":0,"name":"crucible","level":30,"time":"2024-02-15T02:55:43.593207402Z","hostname":"ip-10-150-1-195.us-west-2.compute.internal","pid":1160,"client":"0","":"downstairs","session_id":"73ee2047-65f9-46df-80dd-7f5fc13549cd"} Wait for a query_work_queue command to finish before sending IO {"msg":"Transition from WaitQuorum to Active","v":0,"name":"crucible","level":30,"time":"2024-02-15T02:55:43.593214171Z","hostname":"ip-10-150-1-195.us-west-2.compute.internal","pid":1160,"client":"1","":"downstairs","session_id":"73ee2047-65f9-46df-80dd-7f5fc13549cd"} {"msg":"Transition from WaitQuorum to Active","v":0,"name":"crucible","level":30,"time":"2024-02-15T02:55:43.593219031Z","hostname":"ip-10-150-1-195.us-west-2.compute.internal","pid":1160,"client":"2","":"downstairs","session_id":"73ee2047-65f9-46df-80dd-7f5fc13549cd"} {"msg":"All required reconciliation work is completed","v":0,"name":"crucible","level":30,"time":"2024-02-15T02:55:43.593223221Z","hostname":"ip-10-150-1-195.us-west-2.compute.internal","pid":1160,"session_id":"73ee2047-65f9-46df-80dd-7f5fc13549cd"} {"msg":"Set Downstairs and Upstairs active after reconciliation","v":0,"name":"crucible","level":30,"time":"2024-02-15T02:55:43.59322701Z","hostname":"ip-10-150-1-195.us-west-2.compute.internal","pid":1160,"session_id":"73ee2047-65f9-46df-80dd-7f5fc13549cd"} {"msg":"98c8105a-e246-4e01-9853-61babd1c52be is now active with session: 73ee2047-65f9-46df-80dd-7f5fc13549cd","v":0,"name":"crucible","level":30,"time":"2024-02-15T02:55:43.59323131Z","hostname":"ip-10-150-1-195.us-west-2.compute.internal","pid":1160,"session_id":"73ee2047-65f9-46df-80dd-7f5fc13549cd"} {"msg":"Set Active after no reconciliation","v":0,"name":"crucible","level":30,"time":"2024-02-15T02:55:43.5932355Z","hostname":"ip-10-150-1-195.us-west-2.compute.internal","pid":1160,"session_id":"73ee2047-65f9-46df-80dd-7f5fc13549cd"} {"msg":"The guest has finished waiting for activation with:1","v":0,"name":"crucible","level":30,"time":"2024-02-15T02:55:43.59323936Z","hostname":"ip-10-150-1-195.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.31 30000 1 1477.02 0.00068 0.00139 0.00187 0.05806 16384 640 rwrites 6.76 30000 1 4438.51 0.00023 0.00056 0.00141 0.04359 16384 640 rreads 5.67 30000 1 5290.72 0.00019 0.00024 0.00029 0.01292 16384 640 rreads 5.63 30000 1 5324.77 0.00019 0.00024 0.00029 0.01292 16384 640 A new loop begins at February 15, 2024 at 02:56:36 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-15T02:56:36.709376237Z","hostname":"ip-10-150-1-195.us-west-2.compute.internal","pid":1179} {"msg":"Crucible Version: BuildInfo {\n version: \"0.0.1\",\n git_sha: \"56eb785b9570b1bd468a7aafe9af80e337a7fae9\",\n git_commit_timestamp: \"2024-02-15T02:33:40.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-15T02:56:36.709535288Z","hostname":"ip-10-150-1-195.us-west-2.compute.internal","pid":1179} {"msg":"Upstairs <-> Downstairs Message Version: 5","v":0,"name":"crucible","level":30,"time":"2024-02-15T02:56:36.709542337Z","hostname":"ip-10-150-1-195.us-west-2.compute.internal","pid":1179} Crucible runtime is spawned {"msg":"Crucible f77e66f8-3ed4-418b-881f-d4364fe39b3a has session id: 523cdddc-1d08-4651-98cd-fde7417a1470","v":0,"name":"crucible","level":30,"time":"2024-02-15T02:56:36.709559976Z","hostname":"ip-10-150-1-195.us-west-2.compute.internal","pid":1179,"session_id":"523cdddc-1d08-4651-98cd-fde7417a1470"} {"msg":"Upstairs opts: Upstairs UUID: f77e66f8-3ed4-418b-881f-d4364fe39b3a, 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-15T02:56:36.709569555Z","hostname":"ip-10-150-1-195.us-west-2.compute.internal","pid":1179,"session_id":"523cdddc-1d08-4651-98cd-fde7417a1470"} {"msg":"Crucible stats registered with UUID: f77e66f8-3ed4-418b-881f-d4364fe39b3a","v":0,"name":"crucible","level":30,"time":"2024-02-15T02:56:36.709573975Z","hostname":"ip-10-150-1-195.us-west-2.compute.internal","pid":1179,"session_id":"523cdddc-1d08-4651-98cd-fde7417a1470"} {"msg":"The guest has requested activation with gen:1","v":0,"name":"crucible","level":30,"time":"2024-02-15T02:56:36.709579255Z","hostname":"ip-10-150-1-195.us-west-2.compute.internal","pid":1179} {"msg":"f77e66f8-3ed4-418b-881f-d4364fe39b3a active request set","v":0,"name":"crucible","level":30,"time":"2024-02-15T02:56:36.709605424Z","hostname":"ip-10-150-1-195.us-west-2.compute.internal","pid":1179,"session_id":"523cdddc-1d08-4651-98cd-fde7417a1470"} {"msg":"sending connect oneshot to client","v":0,"name":"crucible","level":30,"time":"2024-02-15T02:56:36.709618303Z","hostname":"ip-10-150-1-195.us-west-2.compute.internal","pid":1179,"client":"0","":"downstairs","session_id":"523cdddc-1d08-4651-98cd-fde7417a1470"} {"msg":"client set_active_request while in New; waiting...","v":0,"name":"crucible","level":30,"time":"2024-02-15T02:56:36.709626622Z","hostname":"ip-10-150-1-195.us-west-2.compute.internal","pid":1179,"client":"0","":"downstairs","session_id":"523cdddc-1d08-4651-98cd-fde7417a1470"} {"msg":"sending connect oneshot to client","v":0,"name":"crucible","level":30,"time":"2024-02-15T02:56:36.709631502Z","hostname":"ip-10-150-1-195.us-west-2.compute.internal","pid":1179,"client":"1","":"downstairs","session_id":"523cdddc-1d08-4651-98cd-fde7417a1470"} {"msg":"client set_active_request while in New; waiting...","v":0,"name":"crucible","level":30,"time":"2024-02-15T02:56:36.709636152Z","hostname":"ip-10-150-1-195.us-west-2.compute.internal","pid":1179,"client":"1","":"downstairs","session_id":"523cdddc-1d08-4651-98cd-fde7417a1470"} {"msg":"sending connect oneshot to client","v":0,"name":"crucible","level":30,"time":"2024-02-15T02:56:36.709640521Z","hostname":"ip-10-150-1-195.us-west-2.compute.internal","pid":1179,"client":"2","":"downstairs","session_id":"523cdddc-1d08-4651-98cd-fde7417a1470"} {"msg":"client set_active_request while in New; waiting...","v":0,"name":"crucible","level":30,"time":"2024-02-15T02:56:36.709645341Z","hostname":"ip-10-150-1-195.us-west-2.compute.internal","pid":1179,"client":"2","":"downstairs","session_id":"523cdddc-1d08-4651-98cd-fde7417a1470"} {"msg":"connecting to 127.0.0.1:8810","v":0,"name":"crucible","level":30,"time":"2024-02-15T02:56:36.709675239Z","hostname":"ip-10-150-1-195.us-west-2.compute.internal","pid":1179,"":"io task","client":"0","":"downstairs","session_id":"523cdddc-1d08-4651-98cd-fde7417a1470"} {"msg":"connecting to 127.0.0.1:8830","v":0,"name":"crucible","level":30,"time":"2024-02-15T02:56:36.709695878Z","hostname":"ip-10-150-1-195.us-west-2.compute.internal","pid":1179,"":"io task","client":"2","":"downstairs","session_id":"523cdddc-1d08-4651-98cd-fde7417a1470"} {"msg":"connecting to 127.0.0.1:8820","v":0,"name":"crucible","level":30,"time":"2024-02-15T02:56:36.709700958Z","hostname":"ip-10-150-1-195.us-west-2.compute.internal","pid":1179,"":"io task","client":"1","":"downstairs","session_id":"523cdddc-1d08-4651-98cd-fde7417a1470"} {"msg":"ds_connection connected","v":0,"name":"crucible","level":30,"time":"2024-02-15T02:56:36.709770934Z","hostname":"ip-10-150-1-195.us-west-2.compute.internal","pid":1179,"":"io task","client":"0","":"downstairs","session_id":"523cdddc-1d08-4651-98cd-fde7417a1470"} {"msg":"ds_connection connected","v":0,"name":"crucible","level":30,"time":"2024-02-15T02:56:36.709791893Z","hostname":"ip-10-150-1-195.us-west-2.compute.internal","pid":1179,"":"io task","client":"1","":"downstairs","session_id":"523cdddc-1d08-4651-98cd-fde7417a1470"} {"msg":"ds_connection connected","v":0,"name":"crucible","level":30,"time":"2024-02-15T02:56:36.709800442Z","hostname":"ip-10-150-1-195.us-west-2.compute.internal","pid":1179,"":"io task","client":"2","":"downstairs","session_id":"523cdddc-1d08-4651-98cd-fde7417a1470"} {"msg":"ds_transition from New to WaitActive","v":0,"name":"crucible","level":30,"time":"2024-02-15T02:56:36.710107754Z","hostname":"ip-10-150-1-195.us-west-2.compute.internal","pid":1179,"client":"1","":"downstairs","session_id":"523cdddc-1d08-4651-98cd-fde7417a1470"} {"msg":"[1] Transition from New to WaitActive","v":0,"name":"crucible","level":30,"time":"2024-02-15T02:56:36.710149552Z","hostname":"ip-10-150-1-195.us-west-2.compute.internal","pid":1179,"client":"1","":"downstairs","session_id":"523cdddc-1d08-4651-98cd-fde7417a1470"} {"msg":"ds_transition from New to WaitActive","v":0,"name":"crucible","level":30,"time":"2024-02-15T02:56:36.710170491Z","hostname":"ip-10-150-1-195.us-west-2.compute.internal","pid":1179,"client":"0","":"downstairs","session_id":"523cdddc-1d08-4651-98cd-fde7417a1470"} {"msg":"[0] Transition from New to WaitActive","v":0,"name":"crucible","level":30,"time":"2024-02-15T02:56:36.71017633Z","hostname":"ip-10-150-1-195.us-west-2.compute.internal","pid":1179,"client":"0","":"downstairs","session_id":"523cdddc-1d08-4651-98cd-fde7417a1470"} {"msg":"ds_transition from New to WaitActive","v":0,"name":"crucible","level":30,"time":"2024-02-15T02:56:36.7101808Z","hostname":"ip-10-150-1-195.us-west-2.compute.internal","pid":1179,"client":"2","":"downstairs","session_id":"523cdddc-1d08-4651-98cd-fde7417a1470"} {"msg":"[2] Transition from New to WaitActive","v":0,"name":"crucible","level":30,"time":"2024-02-15T02:56:36.71018543Z","hostname":"ip-10-150-1-195.us-west-2.compute.internal","pid":1179,"client":"2","":"downstairs","session_id":"523cdddc-1d08-4651-98cd-fde7417a1470"} {"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-15T02:56:36.710477593Z","hostname":"ip-10-150-1-195.us-west-2.compute.internal","pid":1179,"client":"1","":"downstairs","session_id":"523cdddc-1d08-4651-98cd-fde7417a1470"} {"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-15T02:56:36.71052789Z","hostname":"ip-10-150-1-195.us-west-2.compute.internal","pid":1179,"client":"0","":"downstairs","session_id":"523cdddc-1d08-4651-98cd-fde7417a1470"} {"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-15T02:56:36.710540999Z","hostname":"ip-10-150-1-195.us-west-2.compute.internal","pid":1179,"client":"2","":"downstairs","session_id":"523cdddc-1d08-4651-98cd-fde7417a1470"} {"msg":"ds_transition from WaitActive to WaitQuorum","v":0,"name":"crucible","level":30,"time":"2024-02-15T02:56:36.716684872Z","hostname":"ip-10-150-1-195.us-west-2.compute.internal","pid":1179,"client":"0","":"downstairs","session_id":"523cdddc-1d08-4651-98cd-fde7417a1470"} {"msg":"[0] Transition from WaitActive to WaitQuorum","v":0,"name":"crucible","level":30,"time":"2024-02-15T02:56:36.716702901Z","hostname":"ip-10-150-1-195.us-west-2.compute.internal","pid":1179,"client":"0","":"downstairs","session_id":"523cdddc-1d08-4651-98cd-fde7417a1470"} {"msg":"Waiting for true more clients to be ready","v":0,"name":"crucible","level":30,"time":"2024-02-15T02:56:36.716708811Z","hostname":"ip-10-150-1-195.us-west-2.compute.internal","pid":1179,"session_id":"523cdddc-1d08-4651-98cd-fde7417a1470"} {"msg":"ds_transition from WaitActive to WaitQuorum","v":0,"name":"crucible","level":30,"time":"2024-02-15T02:56:36.717622787Z","hostname":"ip-10-150-1-195.us-west-2.compute.internal","pid":1179,"client":"1","":"downstairs","session_id":"523cdddc-1d08-4651-98cd-fde7417a1470"} {"msg":"[1] Transition from WaitActive to WaitQuorum","v":0,"name":"crucible","level":30,"time":"2024-02-15T02:56:36.717644036Z","hostname":"ip-10-150-1-195.us-west-2.compute.internal","pid":1179,"client":"1","":"downstairs","session_id":"523cdddc-1d08-4651-98cd-fde7417a1470"} {"msg":"Waiting for true more clients to be ready","v":0,"name":"crucible","level":30,"time":"2024-02-15T02:56:36.717651236Z","hostname":"ip-10-150-1-195.us-west-2.compute.internal","pid":1179,"session_id":"523cdddc-1d08-4651-98cd-fde7417a1470"} {"msg":"ds_transition from WaitActive to WaitQuorum","v":0,"name":"crucible","level":30,"time":"2024-02-15T02:56:36.717703293Z","hostname":"ip-10-150-1-195.us-west-2.compute.internal","pid":1179,"client":"2","":"downstairs","session_id":"523cdddc-1d08-4651-98cd-fde7417a1470"} {"msg":"[2] Transition from WaitActive to WaitQuorum","v":0,"name":"crucible","level":30,"time":"2024-02-15T02:56:36.717721922Z","hostname":"ip-10-150-1-195.us-west-2.compute.internal","pid":1179,"client":"2","":"downstairs","session_id":"523cdddc-1d08-4651-98cd-fde7417a1470"} {"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-15T02:56:36.717728181Z","hostname":"ip-10-150-1-195.us-west-2.compute.internal","pid":1179,"":"downstairs","":"downstairs","session_id":"523cdddc-1d08-4651-98cd-fde7417a1470"} {"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-15T02:56:36.717733851Z","hostname":"ip-10-150-1-195.us-west-2.compute.internal","pid":1179,"":"downstairs","":"downstairs","session_id":"523cdddc-1d08-4651-98cd-fde7417a1470"} {"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-15T02:56:36.717738341Z","hostname":"ip-10-150-1-195.us-west-2.compute.internal","pid":1179,"":"downstairs","":"downstairs","session_id":"523cdddc-1d08-4651-98cd-fde7417a1470"} {"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-15T02:56:36.71774296Z","hostname":"ip-10-150-1-195.us-west-2.compute.internal","pid":1179,"":"downstairs","":"downstairs","session_id":"523cdddc-1d08-4651-98cd-fde7417a1470"} {"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-15T02:56:36.71774724Z","hostname":"ip-10-150-1-195.us-west-2.compute.internal","pid":1179,"":"downstairs","":"downstairs","session_id":"523cdddc-1d08-4651-98cd-fde7417a1470"} {"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-15T02:56:36.71775143Z","hostname":"ip-10-150-1-195.us-west-2.compute.internal","pid":1179,"":"downstairs","":"downstairs","session_id":"523cdddc-1d08-4651-98cd-fde7417a1470"} {"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-15T02:56:36.7177562Z","hostname":"ip-10-150-1-195.us-west-2.compute.internal","pid":1179,"":"downstairs","":"downstairs","session_id":"523cdddc-1d08-4651-98cd-fde7417a1470"} {"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-15T02:56:36.717761739Z","hostname":"ip-10-150-1-195.us-west-2.compute.internal","pid":1179,"":"downstairs","":"downstairs","session_id":"523cdddc-1d08-4651-98cd-fde7417a1470"} {"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-15T02:56:36.717769309Z","hostname":"ip-10-150-1-195.us-west-2.compute.internal","pid":1179,"":"downstairs","":"downstairs","session_id":"523cdddc-1d08-4651-98cd-fde7417a1470"} {"msg":"Max found gen is 1","v":0,"name":"crucible","level":30,"time":"2024-02-15T02:56:36.717778029Z","hostname":"ip-10-150-1-195.us-west-2.compute.internal","pid":1179,"":"downstairs","":"downstairs","session_id":"523cdddc-1d08-4651-98cd-fde7417a1470"} {"msg":"Generation requested: 1 >= found:1","v":0,"name":"crucible","level":30,"time":"2024-02-15T02:56:36.717785388Z","hostname":"ip-10-150-1-195.us-west-2.compute.internal","pid":1179,"":"downstairs","":"downstairs","session_id":"523cdddc-1d08-4651-98cd-fde7417a1470"} {"msg":"Next flush: 1","v":0,"name":"crucible","level":30,"time":"2024-02-15T02:56:36.717792388Z","hostname":"ip-10-150-1-195.us-west-2.compute.internal"Wait for a query_work_queue command to finish before sending IO ,"pid":1179,"":"downstairs","":"downstairs","session_id":"523cdddc-1d08-4651-98cd-fde7417a1470"} {"msg":"All extents match","v":0,"name":"crucible","level":30,"time":"2024-02-15T02:56:36.717803357Z","hostname":"ip-10-150-1-195.us-west-2.compute.internal","pid":1179,"":"downstairs","":"downstairs","session_id":"523cdddc-1d08-4651-98cd-fde7417a1470"} {"msg":"No downstairs reconciliation required","v":0,"name":"crucible","level":30,"time":"2024-02-15T02:56:36.717810507Z","hostname":"ip-10-150-1-195.us-west-2.compute.internal","pid":1179,"session_id":"523cdddc-1d08-4651-98cd-fde7417a1470"} {"msg":"Transition from WaitQuorum to Active","v":0,"name":"crucible","level":30,"time":"2024-02-15T02:56:36.717834695Z","hostname":"ip-10-150-1-195.us-west-2.compute.internal","pid":1179,"client":"0","":"downstairs","session_id":"523cdddc-1d08-4651-98cd-fde7417a1470"} {"msg":"Transition from WaitQuorum to Active","v":0,"name":"crucible","level":30,"time":"2024-02-15T02:56:36.717852964Z","hostname":"ip-10-150-1-195.us-west-2.compute.internal","pid":1179,"client":"1","":"downstairs","session_id":"523cdddc-1d08-4651-98cd-fde7417a1470"} {"msg":"Transition from WaitQuorum to Active","v":0,"name":"crucible","level":30,"time":"2024-02-15T02:56:36.717859864Z","hostname":"ip-10-150-1-195.us-west-2.compute.internal","pid":1179,"client":"2","":"downstairs","session_id":"523cdddc-1d08-4651-98cd-fde7417a1470"} {"msg":"All required reconciliation work is completed","v":0,"name":"crucible","level":30,"time":"2024-02-15T02:56:36.717866143Z","hostname":"ip-10-150-1-195.us-west-2.compute.internal","pid":1179,"session_id":"523cdddc-1d08-4651-98cd-fde7417a1470"} {"msg":"Set Downstairs and Upstairs active after reconciliation","v":0,"name":"crucible","level":30,"time":"2024-02-15T02:56:36.717871743Z","hostname":"ip-10-150-1-195.us-west-2.compute.internal","pid":1179,"session_id":"523cdddc-1d08-4651-98cd-fde7417a1470"} {"msg":"f77e66f8-3ed4-418b-881f-d4364fe39b3a is now active with session: 523cdddc-1d08-4651-98cd-fde7417a1470","v":0,"name":"crucible","level":30,"time":"2024-02-15T02:56:36.717877033Z","hostname":"ip-10-150-1-195.us-west-2.compute.internal","pid":1179,"session_id":"523cdddc-1d08-4651-98cd-fde7417a1470"} {"msg":"Set Active after no reconciliation","v":0,"name":"crucible","level":30,"time":"2024-02-15T02:56:36.717882332Z","hostname":"ip-10-150-1-195.us-west-2.compute.internal","pid":1179,"session_id":"523cdddc-1d08-4651-98cd-fde7417a1470"} {"msg":"The guest has finished waiting for activation with:1","v":0,"name":"crucible","level":30,"time":"2024-02-15T02:56:36.717887372Z","hostname":"ip-10-150-1-195.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 7.88 30000 1 3805.34 0.00026 0.00061 0.00121 0.05711 16384 1280 rwrites 8.18 30000 1 3668.09 0.00027 0.00060 0.00112 0.06201 16384 1280 rreads 5.66 30000 1 5296.79 0.00019 0.00023 0.00028 0.01347 16384 1280 rreads 5.68 30000 1 5281.03 0.00019 0.00023 0.00028 0.01388 16384 1280 Perf test finished on February 15, 2024 at 02:57:12 AM UTC