Perf test begins at February 3, 2024 at 04:13:10 PM UTC A new loop begins at February 3, 2024 at 04:13:20 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":"Upstairs starts","v":0,"name":"crucible","level":30,"time":"2024-02-03T16:13:20.212706881Z","hostname":"ip-10-150-1-241.us-west-2.compute.internal","pid":1157} {"msg":"Crucible Version: BuildInfo {\n version: \"0.0.1\",\n git_sha: \"85ad6bd3639073b418f2b23f55877174588f0947\",\n git_commit_timestamp: \"2024-02-03T15:18:54.000000000Z\",\n git_branch: \"renovate/async-trait-0.x\",\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-03T16:13:20.212949619Z","hostname":"ip-10-150-1-241.us-west-2.compute.internal","pid":1157} {"msg":"Upstairs <-> Downstairs Message Version: 5","v":0,"name":"crucible","level":30,"time":"2024-02-03T16:13:20.212960102Z","hostname":"ip-10-150-1-241.us-west-2.compute.internal","pid":1157} {"msg":"Crucible 474a90e6-b9f0-4c48-9469-fa0f0ab833cc has session id: 64633632-6be8-49e5-8371-1c7ecf5383b3","v":0,"name":"crucible","level":30,"time":"2024-02-03T16:13:20.213027662Z","hostname":"ip-10-150-1-241.us-west-2.compute.internal","pid":1157,"session_id":"64633632-6be8-49e5-8371-1c7ecf5383b3"} {"msg":"Upstairs opts: Upstairs UUID: 474a90e6-b9f0-4c48-9469-fa0f0ab833cc, 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-03T16:13:20.213154828Z","hostname":"ip-10-150-1-241.us-west-2.compute.internal","pid":1157,"session_id":"64633632-6be8-49e5-8371-1c7ecf5383b3"} {"msg":"Crucible stats registered with UUID: 474a90e6-b9f0-4c48-9469-fa0f0ab833cc","v":0,"name":"crucible","level":30,"time":"2024-02-03T16:13:20.213183753Z","hostname":"ip-10-150-1-241.us-west-2.compute.internal","pid":1157,"session_id":"64633632-6be8-49e5-8371-1c7ecf5383b3"} Crucible runtime is spawned {"msg":"The guest has requested activation with gen:1","v":0,"name":"crucible","level":30,"time":"2024-02-03T16:13:20.21346226Z","hostname":"ip-10-150-1-241.us-west-2.compute.internal","pid":1157} {"msg":"474a90e6-b9f0-4c48-9469-fa0f0ab833cc active request set","v":0,"name":"crucible","level":30,"time":"2024-02-03T16:13:20.213808995Z","hostname":"ip-10-150-1-241.us-west-2.compute.internal","pid":1157,"session_id":"64633632-6be8-49e5-8371-1c7ecf5383b3"} {"msg":"sending connect oneshot to client","v":0,"name":"crucible","level":30,"time":"2024-02-03T16:13:20.213852463Z","hostname":"ip-10-150-1-241.us-west-2.compute.internal","pid":1157,"client":"0","":"downstairs","session_id":"64633632-6be8-49e5-8371-1c7ecf5383b3"} {"msg":"client set_active_request while in New; waiting...","v":0,"name":"crucible","level":30,"time":"2024-02-03T16:13:20.213931678Z","hostname":"ip-10-150-1-241.us-west-2.compute.internal","pid":1157,"client":"0","":"downstairs","session_id":"64633632-6be8-49e5-8371-1c7ecf5383b3"} {"msg":"sending connect oneshot to client","v":0,"name":"crucible","level":30,"time":"2024-02-03T16:13:20.213947078Z","hostname":"ip-10-150-1-241.us-west-2.compute.internal","pid":1157,"client":"1","":"downstairs","session_id":"64633632-6be8-49e5-8371-1c7ecf5383b3"} {"msg":"client set_active_request while in New; waiting...","v":0,"name":"crucible","level":30,"time":"2024-02-03T16:13:20.213961445Z","hostname":"ip-10-150-1-241.us-west-2.compute.internal","pid":1157,"client":"1","":"downstairs","session_id":"64633632-6be8-49e5-8371-1c7ecf5383b3"} {"msg":"sending connect oneshot to client","v":0,"name":"crucible","level":30,"time":"2024-02-03T16:13:20.213973555Z","hostname":"ip-10-150-1-241.us-west-2.compute.internal","pid":1157,"client":"2","":"downstairs","session_id":"64633632-6be8-49e5-8371-1c7ecf5383b3"} {"msg":"client set_active_request while in New; waiting...","v":0,"name":"crucible","level":30,"time":"2024-02-03T16:13:20.214018773Z","hostname":"ip-10-150-1-241.us-west-2.compute.internal","pid":1157,"client":"2","":"downstairs","session_id":"64633632-6be8-49e5-8371-1c7ecf5383b3"} {"msg":"connecting to 127.0.0.1:8820","v":0,"name":"crucible","level":30,"time":"2024-02-03T16:13:20.214032717Z","hostname":"ip-10-150-1-241.us-west-2.compute.internal","pid":1157,"":"io task","client":"1","":"downstairs","session_id":"64633632-6be8-49e5-8371-1c7ecf5383b3"} {"msg":"connecting to 127.0.0.1:8810","v":0,"name":"crucible","level":30,"time":"2024-02-03T16:13:20.214046628Z","hostname":"ip-10-150-1-241.us-west-2.compute.internal","pid":1157,"":"io task","client":"0","":"downstairs","session_id":"64633632-6be8-49e5-8371-1c7ecf5383b3"} {"msg":"connecting to 127.0.0.1:8830","v":0,"name":"crucible","level":30,"time":"2024-02-03T16:13:20.214061387Z","hostname":"ip-10-150-1-241.us-west-2.compute.internal","pid":1157,"":"io task","client":"2","":"downstairs","session_id":"64633632-6be8-49e5-8371-1c7ecf5383b3"} {"msg":"ds_connection connected","v":0,"name":"crucible","level":30,"time":"2024-02-03T16:13:20.214360767Z","hostname":"ip-10-150-1-241.us-west-2.compute.internal","pid":1157,"":"io task","client":"2","":"downstairs","session_id":"64633632-6be8-49e5-8371-1c7ecf5383b3"} {"msg":"ds_connection connected","v":0,"name":"crucible","level":30,"time":"2024-02-03T16:13:20.214383972Z","hostname":"ip-10-150-1-241.us-west-2.compute.internal","pid":1157,"":"io task","client":"1","":"downstairs","session_id":"64633632-6be8-49e5-8371-1c7ecf5383b3"} {"msg":"ds_connection connected","v":0,"name":"crucible","level":30,"time":"2024-02-03T16:13:20.214421315Z","hostname":"ip-10-150-1-241.us-west-2.compute.internal","pid":1157,"":"io task","client":"0","":"downstairs","session_id":"64633632-6be8-49e5-8371-1c7ecf5383b3"} {"msg":"ds_transition from New to WaitActive","v":0,"name":"crucible","level":30,"time":"2024-02-03T16:13:20.215936297Z","hostname":"ip-10-150-1-241.us-west-2.compute.internal","pid":1157,"client":"2","":"downstairs","session_id":"64633632-6be8-49e5-8371-1c7ecf5383b3"} {"msg":"[2] Transition from New to WaitActive","v":0,"name":"crucible","level":30,"time":"2024-02-03T16:13:20.215985145Z","hostname":"ip-10-150-1-241.us-west-2.compute.internal","pid":1157,"client":"2","":"downstairs","session_id":"64633632-6be8-49e5-8371-1c7ecf5383b3"} {"msg":"ds_transition from New to WaitActive","v":0,"name":"crucible","level":30,"time":"2024-02-03T16:13:20.215998667Z","hostname":"ip-10-150-1-241.us-west-2.compute.internal","pid":1157,"client":"0","":"downstairs","session_id":"64633632-6be8-49e5-8371-1c7ecf5383b3"} {"msg":"[0] Transition from New to WaitActive","v":0,"name":"crucible","level":30,"time":"2024-02-03T16:13:20.216011097Z","hostname":"ip-10-150-1-241.us-west-2.compute.internal","pid":1157,"client":"0","":"downstairs","session_id":"64633632-6be8-49e5-8371-1c7ecf5383b3"} {"msg":"ds_transition from New to WaitActive","v":0,"name":"crucible","level":30,"time":"2024-02-03T16:13:20.216073622Z","hostname":"ip-10-150-1-241.us-west-2.compute.internal","pid":1157,"client":"1","":"downstairs","session_id":"64633632-6be8-49e5-8371-1c7ecf5383b3"} {"msg":"[1] Transition from New to WaitActive","v":0,"name":"crucible","level":30,"time":"2024-02-03T16:13:20.216082241Z","hostname":"ip-10-150-1-241.us-west-2.compute.internal","pid":1157,"client":"1","":"downstairs","session_id":"64633632-6be8-49e5-8371-1c7ecf5383b3"} {"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-03T16:13:20.216565844Z","hostname":"ip-10-150-1-241.us-west-2.compute.internal","pid":1157,"client":"2","":"downstairs","session_id":"64633632-6be8-49e5-8371-1c7ecf5383b3"} {"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-03T16:13:20.216610072Z","hostname":"ip-10-150-1-241.us-west-2.compute.internal","pid":1157,"client":"0","":"downstairs","session_id":"64633632-6be8-49e5-8371-1c7ecf5383b3"} {"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-03T16:13:20.216759467Z","hostname":"ip-10-150-1-241.us-west-2.compute.internal","pid":1157,"client":"1","":"downstairs","session_id":"64633632-6be8-49e5-8371-1c7ecf5383b3"} {"msg":"ds_transition from WaitActive to WaitQuorum","v":0,"name":"crucible","level":30,"time":"2024-02-03T16:13:20.221714076Z","hostname":"ip-10-150-1-241.us-west-2.compute.internal","pid":1157,"client":"2","":"downstairs","session_id":"64633632-6be8-49e5-8371-1c7ecf5383b3"} {"msg":"[2] Transition from WaitActive to WaitQuorum","v":0,"name":"crucible","level":30,"time":"2024-02-03T16:13:20.221749816Z","hostname":"ip-10-150-1-241.us-west-2.compute.internal","pid":1157,"client":"2","":"downstairs","session_id":"64633632-6be8-49e5-8371-1c7ecf5383b3"} {"msg":"Waiting for true more clients to be ready","v":0,"name":"crucible","level":30,"time":"2024-02-03T16:13:20.221762917Z","hostname":"ip-10-150-1-241.us-west-2.compute.internal","pid":1157,"session_id":"64633632-6be8-49e5-8371-1c7ecf5383b3"} {"msg":"ds_transition from WaitActive to WaitQuorum","v":0,"name":"crucible","level":30,"time":"2024-02-03T16:13:20.222710082Z","hostname":"ip-10-150-1-241.us-west-2.compute.internal","pid":1157,"client":"0","":"downstairs","session_id":"64633632-6be8-49e5-8371-1c7ecf5383b3"} {"msg":"[0] Transition from WaitActive to WaitQuorum","v":0,"name":"crucible","level":30,"time":"2024-02-03T16:13:20.22281449Z","hostname":"ip-10-150-1-241.us-west-2.compute.internal","pid":1157,"client":"0","":"downstairs","session_id":"64633632-6be8-49e5-8371-1c7ecf5383b3"} {"msg":"Waiting for true more clients to be ready","v":0,"name":"crucible","level":30,"time":"2024-02-03T16:13:20.222826477Z","hostname":"ip-10-150-1-241.us-west-2.compute.internal","pid":1157,"session_id":"64633632-6be8-49e5-8371-1c7ecf5383b3"} {"msg":"ds_transition from WaitActive to WaitQuorum","v":0,"name":"crucible","level":30,"time":"2024-02-03T16:13:20.222890497Z","hostname":"ip-10-150-1-241.us-west-2.compute.internal","pid":1157,"client":"1","":"downstairs","session_id":"64633632-6be8-49e5-8371-1c7ecf5383b3"} {"msg":"[1] Transition from WaitActive to WaitQuorum","v":0,"name":"crucible","level":30,"time":"2024-02-03T16:13:20.222924164Z","hostname":"ip-10-150-1-241.us-west-2.compute.internal","pid":1157,"client":"1","":"downstairs","session_id":"64633632-6be8-49e5-8371-1c7ecf5383b3"} {"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-03T16:13:20.222932072Z","hostname":"ip-10-150-1-241.us-west-2.compute.internal","pid":1157,"":"downstairs","":"downstairs","session_id":"64633632-6be8-49e5-8371-1c7ecf5383b3"} {"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-03T16:13:20.222939586Z","hostname":"ip-10-150-1-241.us-west-2.compute.internal","pid":1157,"":"downstairs","":"downstairs","session_id":"64633632-6be8-49e5-8371-1c7ecf5383b3"} {"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-03T16:13:20.222947157Z","hostname":"ip-10-150-1-241.us-west-2.compute.internal","pid":1157,"":"downstairs","":"downstairs","session_id":"64633632-6be8-49e5-8371-1c7ecf5383b3"} {"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-03T16:13:20.222954796Z","hostname":"ip-10-150-1-241.us-west-2.compute.internal","pid":1157,"":"downstairs","":"downstairs","session_id":"64633632-6be8-49e5-8371-1c7ecf5383b3"} {"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-03T16:13:20.222963324Z","hostname":"ip-10-150-1-241.us-west-2.compute.internal","pid":1157,"":"downstairs","":"downstairs","session_id":"64633632-6be8-49e5-8371-1c7ecf5383b3"} {"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-03T16:13:20.222970729Z","hostname":"ip-10-150-1-241.us-west-2.compute.internal","pid":1157,"":"downstairs","":"downstairs","session_id":"64633632-6be8-49e5-8371-1c7ecf5383b3"} {"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-03T16:13:20.222978144Z","hostname":"ip-10-150-1-241.us-west-2.compute.internal","pid":1157,"":"downstairs","":"downstairs","session_id":"64633632-6be8-49e5-8371-1c7ecf5383b3"} {"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-03T16:13:20.223002159Z","hostname":"ip-10-150-1-241.us-west-2.compute.internal","pid":1157,"":"downstairs","":"downstairs","session_id":"64633632-6be8-49e5-8371-1c7ecf5383b3"} {"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-03T16:13:20.223009789Z","hostname":"ip-10-150-1-241.us-west-2.compute.internal","pid":1157,"":"downstairs","":"downstairs","session_id":"64633632-6be8-49e5-8371-1c7ecf5383b3"} {"msg":"Max found gen is 1","v":0,"name":"crucible","level":30,"time":"2024-02-03T16:13:20.223024171Z","hostname":"ip-10-150-1-241.us-west-2.compute.internal","pid":1157,"":"downstairs","":"downstairs","session_id":"64633632-6be8-49e5-8371-1c7ecf5383b3"} {"msg":"Generation requested: 1 >= found:1","v":0,"name":"crucible","level":30,"time":"2024-02-03T16:13:20.223033263Z","hostname":"ip-10-150-1-241.us-west-2.compute.internal","pid":1157,"":"downstairs","":"downstairs","session_id":"64633632-6be8-49e5-8371-1c7ecf5383b3"} {"msg":"Next flush: 1","v":0,"name":"crucible","level":30,"time":"2024-02-03T16:13:20.223040284Z","hostname":"ip-10-150-1-241.us-west-2.compute.internal","pid":1157,"":"downstairs","":"downstairs","session_id":"64633632-6be8-49e5-8371-1c7ecf5383b3"} {"msg":"All extents match","v":0,"name":"crucible","level":30,"time":"2024-02-03T16:13:20.223083837Z","hostname":"ip-10-150-1-241.us-west-2.compute.internal","pid":1157,"":"downstairs","":"downstairs","session_id":"64633632-6be8-49e5-8371-1c7ecf5383b3"} {"msg":"No downstairs reconciliation required","v":0,"name":"crucible","level":30,"time":"2024-02-03T16:13:20.223124628Z","hostname":"ip-10-150-1-241.us-west-2.compute.internal","pid":1157,"session_id":"64633632-6be8-49e5-8371-1c7ecf5383b3"} {"msg":"Transition from WaitQuorum to Active","v":0,"name":"crucible","level":30,"time":"2024-02-03T16:13:20.223164256Z","hostname":"ip-10-150-1-241.us-west-2.compute.internal","pid":1157,"client":"0","":"downstairs","session_id":"64633632-6be8-49e5-8371-1c7ecf5383b3"} {"msg":"Transition from WaitQuorum to Active","v":0,"name":"crucible","level":30,"time":"2024-02-03T16:13:20.223204089Z","hostname":"ip-10-150-1-241.us-west-2.compute.internal","pid":1157,"client":"1","":"downstairs","session_id":"64633632-6be8-49e5-8371-1c7ecf5383b3"} {"msg":"Transition from WaitQuorum to Active","v":0,"name":"crucible","level":30,"time":"2024-02-03T16:13:20.223245211Z","hostname":"ip-10-150-1-241.us-west-2.compute.internal","pid":1157,"client":"2","":"downstairs","session_id":"64633632-6be8-49e5-8371-1c7ecf5383b3"} {"msg":"All required reconciliation work is completed","v":0,"name":"crucible","level":30,"time":"2024-02-03T16:13:20.223285097Z","hostname":"ip-10-150-1-241.us-west-2.compute.internal","pid":1157,"session_id":"64633632-6be8-49e5-8371-1c7ecf5383b3"} {"msg":"Set Downstairs and Upstairs active after reconciliation","v":0,"name":"crucible","level":30,"time":"2024-02-03T16:13:20.223324611Z","hostname":"ip-10-150-1-241.us-west-2.compute.internal","pid":1157,"session_id":"64633632-6be8-49e5-8371-1c7ecf5383b3"} {"msg":"474a90e6-b9f0-4c48-9469-fa0f0ab833cc is now active with session: 64633632-6be8-49e5-8371-1c7ecf5383b3","v":0,"name":"crucible","level":30,"time":"2024-02-03T16:13:20.223364064Z","hostname":"ip-10-150-1-241.us-west-2.compute.internal","pid":1157,"session_id":"64633632-6be8-49e5-8371-1c7ecf5383b3"} {"msg":"Set Active after no reconciliation","v":0,"name":"crucible","level":30,"time":"2024-02-03T16:13:20.223402918Z","hostname":"ip-10-150-1-241.us-west-2.compute.internal","pid":1157,"session_id":"64633632-6be8-49e5-8371-1c7ecf5383b3"} {"msg":"The guest has finished waiting for activation with:1","v":0,"name":"crucible","level":30,"time":"2024-02-03T16:13:20.223442173Z","hostname":"ip-10-150-1-241.us-west-2.compute.internal","pid":1157} Wait for a query_work_queue command to finish before sending IO Region: es:16384 ec:640 bs:4096 ts:42949672960 tb:10485760 max_io:256 or 1048576 Perf test TEST SECONDS COUNT DPTH IOPS MEAN P95 P99 MAX ES EC rwrites 18.66 30000 1 1607.97 0.00062 0.00153 0.00244 0.07306 16384 640 rwrites 14.41 30000 1 2081.60 0.00048 0.00110 0.00228 0.06547 16384 640 rreads 10.89 30000 1 2755.76 0.00036 0.00048 0.00061 0.01718 16384 640 rreads 10.80 30000 1 2777.41 0.00036 0.00048 0.00060 0.01825 16384 640 {"msg":"Guest handle has been dropped","v":0,"name":"crucible","level":40,"time":"2024-02-03T16:14:19.410560002Z","hostname":"ip-10-150-1-241.us-west-2.compute.internal","pid":1157} A new loop begins at February 3, 2024 at 04:14:30 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":"Upstairs starts","v":0,"name":"crucible","level":30,"time":"2024-02-03T16:14:30.099413211Z","hostname":"ip-10-150-1-241.us-west-2.compute.internal","pid":1176} {"msg":"Crucible Version: BuildInfo {\n version: \"0.0.1\",\n git_sha: \"85ad6bd3639073b418f2b23f55877174588f0947\",\n git_commit_timestamp: \"2024-02-03T15:18:54.000000000Z\",\n git_branch: \"renovate/async-trait-0.x\",\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-03T16:14:30.099618259Z","hostname":"ip-10-150-1-241.us-west-2.compute.internal","pid":1176} {"msg":"Upstairs <-> Downstairs Message Version: 5","v":0,"name":"crucible","level":30,"time":"2024-02-03T16:14:30.099628373Z","hostname":"ip-10-150-1-241.us-west-2.compute.internal","pid":1176} {"msg":"Crucible 4d326dc8-9d3c-4505-a4b8-3cb907196d6e has session id: ce838409-dbfb-4c8e-ad6b-1dc820bc6fb2","v":0,"name":"crucible","level":30,"time":"2024-02-03T16:14:30.099635469Z","hostname":"ip-10-150-1-241.us-west-2.compute.internal","pid":1176,"session_id":"ce838409-dbfb-4c8e-ad6b-1dc820bc6fb2"} {"msg":"Upstairs opts: Upstairs UUID: 4d326dc8-9d3c-4505-a4b8-3cb907196d6e, 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-03T16:14:30.099651614Z","hostname":"ip-10-150-1-241.us-west-2.compute.internal","pid":1176,"session_id":Crucible runtime is spawned "ce838409-dbfb-4c8e-ad6b-1dc820bc6fb2"} {"msg":"Crucible stats registered with UUID: 4d326dc8-9d3c-4505-a4b8-3cb907196d6e","v":0,"name":"crucible","level":30,"time":"2024-02-03T16:14:30.099789751Z","hostname":"ip-10-150-1-241.us-west-2.compute.internal","pid":1176,"session_id":"ce838409-dbfb-4c8e-ad6b-1dc820bc6fb2"} {"msg":"The guest has requested activation with gen:1","v":0,"name":"crucible","level":30,"time":"2024-02-03T16:14:30.099799389Z","hostname":"ip-10-150-1-241.us-west-2.compute.internal","pid":1176} {"msg":"4d326dc8-9d3c-4505-a4b8-3cb907196d6e active request set","v":0,"name":"crucible","level":30,"time":"2024-02-03T16:14:30.09980918Z","hostname":"ip-10-150-1-241.us-west-2.compute.internal","pid":1176,"session_id":"ce838409-dbfb-4c8e-ad6b-1dc820bc6fb2"} {"msg":"sending connect oneshot to client","v":0,"name":"crucible","level":30,"time":"2024-02-03T16:14:30.099816359Z","hostname":"ip-10-150-1-241.us-west-2.compute.internal","pid":1176,"client":"0","":"downstairs","session_id":"ce838409-dbfb-4c8e-ad6b-1dc820bc6fb2"} {"msg":"client set_active_request while in New; waiting...","v":0,"name":"crucible","level":30,"time":"2024-02-03T16:14:30.099830546Z","hostname":"ip-10-150-1-241.us-west-2.compute.internal","pid":1176,"client":"0","":"downstairs","session_id":"ce838409-dbfb-4c8e-ad6b-1dc820bc6fb2"} {"msg":"sending connect oneshot to client","v":0,"name":"crucible","level":30,"time":"2024-02-03T16:14:30.099838169Z","hostname":"ip-10-150-1-241.us-west-2.compute.internal","pid":1176,"client":"1","":"downstairs","session_id":"ce838409-dbfb-4c8e-ad6b-1dc820bc6fb2"} {"msg":"client set_active_request while in New; waiting...","v":0,"name":"crucible","level":30,"time":"2024-02-03T16:14:30.099864379Z","hostname":"ip-10-150-1-241.us-west-2.compute.internal","pid":1176,"client":"1","":"downstairs","session_id":"ce838409-dbfb-4c8e-ad6b-1dc820bc6fb2"} {"msg":"sending connect oneshot to client","v":0,"name":"crucible","level":30,"time":"2024-02-03T16:14:30.099872012Z","hostname":"ip-10-150-1-241.us-west-2.compute.internal","pid":1176,"client":"2","":"downstairs","session_id":"ce838409-dbfb-4c8e-ad6b-1dc820bc6fb2"} {"msg":"client set_active_request while in New; waiting...","v":0,"name":"crucible","level":30,"time":"2024-02-03T16:14:30.099879394Z","hostname":"ip-10-150-1-241.us-west-2.compute.internal","pid":1176,"client":"2","":"downstairs","session_id":"ce838409-dbfb-4c8e-ad6b-1dc820bc6fb2"} {"msg":"connecting to 127.0.0.1:8810","v":0,"name":"crucible","level":30,"time":"2024-02-03T16:14:30.099961585Z","hostname":"ip-10-150-1-241.us-west-2.compute.internal","pid":1176,"":"io task","client":"0","":"downstairs","session_id":"ce838409-dbfb-4c8e-ad6b-1dc820bc6fb2"} {"msg":"connecting to 127.0.0.1:8820","v":0,"name":"crucible","level":30,"time":"2024-02-03T16:14:30.099994525Z","hostname":"ip-10-150-1-241.us-west-2.compute.internal","pid":1176,"":"io task","client":"1","":"downstairs","session_id":"ce838409-dbfb-4c8e-ad6b-1dc820bc6fb2"} {"msg":"connecting to 127.0.0.1:8830","v":0,"name":"crucible","level":30,"time":"2024-02-03T16:14:30.100003154Z","hostname":"ip-10-150-1-241.us-west-2.compute.internal","pid":1176,"":"io task","client":"2","":"downstairs","session_id":"ce838409-dbfb-4c8e-ad6b-1dc820bc6fb2"} {"msg":"ds_connection connected","v":0,"name":"crucible","level":30,"time":"2024-02-03T16:14:30.100147808Z","hostname":"ip-10-150-1-241.us-west-2.compute.internal","pid":1176,"":"io task","client":"0","":"downstairs","session_id":"ce838409-dbfb-4c8e-ad6b-1dc820bc6fb2"} {"msg":"ds_connection connected","v":0,"name":"crucible","level":30,"time":"2024-02-03T16:14:30.100207024Z","hostname":"ip-10-150-1-241.us-west-2.compute.internal","pid":1176,"":"io task","client":"2","":"downstairs","session_id":"ce838409-dbfb-4c8e-ad6b-1dc820bc6fb2"} {"msg":"ds_connection connected","v":0,"name":"crucible","level":30,"time":"2024-02-03T16:14:30.100223841Z","hostname":"ip-10-150-1-241.us-west-2.compute.internal","pid":1176,"":"io task","client":"1","":"downstairs","session_id":"ce838409-dbfb-4c8e-ad6b-1dc820bc6fb2"} {"msg":"ds_transition from New to WaitActive","v":0,"name":"crucible","level":30,"time":"2024-02-03T16:14:30.100663357Z","hostname":"ip-10-150-1-241.us-west-2.compute.internal","pid":1176,"client":"1","":"downstairs","session_id":"ce838409-dbfb-4c8e-ad6b-1dc820bc6fb2"} {"msg":"[1] Transition from New to WaitActive","v":0,"name":"crucible","level":30,"time":"2024-02-03T16:14:30.100708593Z","hostname":"ip-10-150-1-241.us-west-2.compute.internal","pid":1176,"client":"1","":"downstairs","session_id":"ce838409-dbfb-4c8e-ad6b-1dc820bc6fb2"} {"msg":"ds_transition from New to WaitActive","v":0,"name":"crucible","level":30,"time":"2024-02-03T16:14:30.100763048Z","hostname":"ip-10-150-1-241.us-west-2.compute.internal","pid":1176,"client":"0","":"downstairs","session_id":"ce838409-dbfb-4c8e-ad6b-1dc820bc6fb2"} {"msg":"[0] Transition from New to WaitActive","v":0,"name":"crucible","level":30,"time":"2024-02-03T16:14:30.100777708Z","hostname":"ip-10-150-1-241.us-west-2.compute.internal","pid":1176,"client":"0","":"downstairs","session_id":"ce838409-dbfb-4c8e-ad6b-1dc820bc6fb2"} {"msg":"ds_transition from New to WaitActive","v":0,"name":"crucible","level":30,"time":"2024-02-03T16:14:30.100785077Z","hostname":"ip-10-150-1-241.us-west-2.compute.internal","pid":1176,"client":"2","":"downstairs","session_id":"ce838409-dbfb-4c8e-ad6b-1dc820bc6fb2"} {"msg":"[2] Transition from New to WaitActive","v":0,"name":"crucible","level":30,"time":"2024-02-03T16:14:30.100792241Z","hostname":"ip-10-150-1-241.us-west-2.compute.internal","pid":1176,"client":"2","":"downstairs","session_id":"ce838409-dbfb-4c8e-ad6b-1dc820bc6fb2"} {"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-03T16:14:30.101486578Z","hostname":"ip-10-150-1-241.us-west-2.compute.internal","pid":1176,"client":"1","":"downstairs","session_id":"ce838409-dbfb-4c8e-ad6b-1dc820bc6fb2"} {"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-03T16:14:30.101522854Z","hostname":"ip-10-150-1-241.us-west-2.compute.internal","pid":1176,"client":"0","":"downstairs","session_id":"ce838409-dbfb-4c8e-ad6b-1dc820bc6fb2"} {"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-03T16:14:30.101633215Z","hostname":"ip-10-150-1-241.us-west-2.compute.internal","pid":1176,"client":"2","":"downstairs","session_id":"ce838409-dbfb-4c8e-ad6b-1dc820bc6fb2"} {"msg":"ds_transition from WaitActive to WaitQuorum","v":0,"name":"crucible","level":30,"time":"2024-02-03T16:14:30.111302689Z","hostname":"ip-10-150-1-241.us-west-2.compute.internal","pid":1176,"client":"0","":"downstairs","session_id":"ce838409-dbfb-4c8e-ad6b-1dc820bc6fb2"} {"msg":"[0] Transition from WaitActive to WaitQuorum","v":0,"name":"crucible","level":30,"time":"2024-02-03T16:14:30.111325636Z","hostname":"ip-10-150-1-241.us-west-2.compute.internal","pid":1176,"client":"0","":"downstairs","session_id":"ce838409-dbfb-4c8e-ad6b-1dc820bc6fb2"} {"msg":"Waiting for true more clients to be ready","v":0,"name":"crucible","level":30,"time":"2024-02-03T16:14:30.111338762Z","hostname":"ip-10-150-1-241.us-west-2.compute.internal","pid":1176,"session_id":"ce838409-dbfb-4c8e-ad6b-1dc820bc6fb2"} {"msg":"ds_transition from WaitActive to WaitQuorum","v":0,"name":"crucible","level":30,"time":"2024-02-03T16:14:30.111427891Z","hostname":"ip-10-150-1-241.us-west-2.compute.internal","pid":1176,"client":"2","":"downstairs","session_id":"ce838409-dbfb-4c8e-ad6b-1dc820bc6fb2"} {"msg":"[2] Transition from WaitActive to WaitQuorum","v":0,"name":"crucible","level":30,"time":"2024-02-03T16:14:30.111445259Z","hostname":"ip-10-150-1-241.us-west-2.compute.internal","pid":1176,"client":"2","":"downstairs","session_id":"ce838409-dbfb-4c8e-ad6b-1dc820bc6fb2"} {"msg":"Waiting for true more clients to be ready","v":0,"name":"crucible","level":30,"time":"2024-02-03T16:14:30.111457309Z","hostname":"ip-10-150-1-241.us-west-2.compute.internal","pid":1176,"session_id":"ce838409-dbfb-4c8e-ad6b-1dc820bc6fb2"} {"msg":"ds_transition from WaitActive to WaitQuorum","v":0,"name":"crucible","level":30,"time":"2024-02-03T16:14:30.111620541Z","hostname":"ip-10-150-1-241.us-west-2.compute.internal","pid":1176,"client":"1","":"downstairs","session_id":"ce838409-dbfb-4c8e-ad6b-1dc820bc6fb2"} {"msg":"[1] Transition from WaitActive to WaitQuorum","v":0,"name":"crucible","level":30,"time":"2024-02-03T16:14:30.111637789Z","hostname":"ip-10-150-1-241.us-west-2.compute.internal","pid":1176,"client":"1","":"downstairs","session_id":"ce838409-dbfb-4c8e-ad6b-1dc820bc6fb2"} {"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-03T16:14:30.111698618Z","hostname":"ip-10-150-1-241.us-west-2.compute.internal","pid":1176,"":"downstairs","":"downstairs","session_id":"ce838409-dbfb-4c8e-ad6b-1dc820bc6fb2"} {"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-03T16:14:30.111742065Z","hostname":"ip-10-150-1-241.us-west-2.compute.internal","pid":1176,"":"downstairs","":"downstairs","session_id":"ce838409-dbfb-4c8e-ad6b-1dc820bc6fb2"} {"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-03T16:14:30.111755446Z","hostname":"ip-10-150-1-241.us-west-2.compute.internal","pid":1176,"":"downstairs","":"downstairs","session_id":"ce838409-dbfb-4c8e-ad6b-1dc820bc6fb2"} {"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-03T16:14:30.111767585Z","hostname":"ip-10-150-1-241.us-west-2.compute.internal","pid":1176,"":"downstairs","":"downstairs","session_id":"ce838409-dbfb-4c8e-ad6b-1dc820bc6fb2"} {"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-03T16:14:30.111779777Z","hostname":"ip-10-150-1-241.us-west-2.compute.internal","pid":1176,"":"downstairs","":"downstairs","session_id":"ce838409-dbfb-4c8e-ad6b-1dc820bc6fb2"} {"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-03T16:14:30.111791958Z"Wait for a query_work_queue command to finish before sending IO ,"hostname":"ip-10-150-1-241.us-west-2.compute.internal","pid":1176,"":"downstairs","":"downstairs","session_id":"ce838409-dbfb-4c8e-ad6b-1dc820bc6fb2"} {"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-03T16:14:30.111808415Z","hostname":"ip-10-150-1-241.us-west-2.compute.internal","pid":1176,"":"downstairs","":"downstairs","session_id":"ce838409-dbfb-4c8e-ad6b-1dc820bc6fb2"} {"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-03T16:14:30.111820425Z","hostname":"ip-10-150-1-241.us-west-2.compute.internal","pid":1176,"":"downstairs","":"downstairs","session_id":"ce838409-dbfb-4c8e-ad6b-1dc820bc6fb2"} {"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-03T16:14:30.111833721Z","hostname":"ip-10-150-1-241.us-west-2.compute.internal","pid":1176,"":"downstairs","":"downstairs","session_id":"ce838409-dbfb-4c8e-ad6b-1dc820bc6fb2"} {"msg":"Max found gen is 1","v":0,"name":"crucible","level":30,"time":"2024-02-03T16:14:30.111847169Z","hostname":"ip-10-150-1-241.us-west-2.compute.internal","pid":1176,"":"downstairs","":"downstairs","session_id":"ce838409-dbfb-4c8e-ad6b-1dc820bc6fb2"} {"msg":"Generation requested: 1 >= found:1","v":0,"name":"crucible","level":30,"time":"2024-02-03T16:14:30.111859684Z","hostname":"ip-10-150-1-241.us-west-2.compute.internal","pid":1176,"":"downstairs","":"downstairs","session_id":"ce838409-dbfb-4c8e-ad6b-1dc820bc6fb2"} {"msg":"Next flush: 1","v":0,"name":"crucible","level":30,"time":"2024-02-03T16:14:30.111872751Z","hostname":"ip-10-150-1-241.us-west-2.compute.internal","pid":1176,"":"downstairs","":"downstairs","session_id":"ce838409-dbfb-4c8e-ad6b-1dc820bc6fb2"} {"msg":"All extents match","v":0,"name":"crucible","level":30,"time":"2024-02-03T16:14:30.111885159Z","hostname":"ip-10-150-1-241.us-west-2.compute.internal","pid":1176,"":"downstairs","":"downstairs","session_id":"ce838409-dbfb-4c8e-ad6b-1dc820bc6fb2"} {"msg":"No downstairs reconciliation required","v":0,"name":"crucible","level":30,"time":"2024-02-03T16:14:30.111897625Z","hostname":"ip-10-150-1-241.us-west-2.compute.internal","pid":1176,"session_id":"ce838409-dbfb-4c8e-ad6b-1dc820bc6fb2"} {"msg":"Transition from WaitQuorum to Active","v":0,"name":"crucible","level":30,"time":"2024-02-03T16:14:30.111908516Z","hostname":"ip-10-150-1-241.us-west-2.compute.internal","pid":1176,"client":"0","":"downstairs","session_id":"ce838409-dbfb-4c8e-ad6b-1dc820bc6fb2"} {"msg":"Transition from WaitQuorum to Active","v":0,"name":"crucible","level":30,"time":"2024-02-03T16:14:30.111917103Z","hostname":"ip-10-150-1-241.us-west-2.compute.internal","pid":1176,"client":"1","":"downstairs","session_id":"ce838409-dbfb-4c8e-ad6b-1dc820bc6fb2"} {"msg":"Transition from WaitQuorum to Active","v":0,"name":"crucible","level":30,"time":"2024-02-03T16:14:30.111923883Z","hostname":"ip-10-150-1-241.us-west-2.compute.internal","pid":1176,"client":"2","":"downstairs","session_id":"ce838409-dbfb-4c8e-ad6b-1dc820bc6fb2"} {"msg":"All required reconciliation work is completed","v":0,"name":"crucible","level":30,"time":"2024-02-03T16:14:30.111930686Z","hostname":"ip-10-150-1-241.us-west-2.compute.internal","pid":1176,"session_id":"ce838409-dbfb-4c8e-ad6b-1dc820bc6fb2"} {"msg":"Set Downstairs and Upstairs active after reconciliation","v":0,"name":"crucible","level":30,"time":"2024-02-03T16:14:30.111937797Z","hostname":"ip-10-150-1-241.us-west-2.compute.internal","pid":1176,"session_id":"ce838409-dbfb-4c8e-ad6b-1dc820bc6fb2"} {"msg":"4d326dc8-9d3c-4505-a4b8-3cb907196d6e is now active with session: ce838409-dbfb-4c8e-ad6b-1dc820bc6fb2","v":0,"name":"crucible","level":30,"time":"2024-02-03T16:14:30.111944178Z","hostname":"ip-10-150-1-241.us-west-2.compute.internal","pid":1176,"session_id":"ce838409-dbfb-4c8e-ad6b-1dc820bc6fb2"} {"msg":"Set Active after no reconciliation","v":0,"name":"crucible","level":30,"time":"2024-02-03T16:14:30.111950166Z","hostname":"ip-10-150-1-241.us-west-2.compute.internal","pid":1176,"session_id":"ce838409-dbfb-4c8e-ad6b-1dc820bc6fb2"} {"msg":"The guest has finished waiting for activation with:1","v":0,"name":"crucible","level":30,"time":"2024-02-03T16:14:30.111956877Z","hostname":"ip-10-150-1-241.us-west-2.compute.internal","pid":1176} 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 16.64 30000 1 1802.46 0.00055 0.00132 0.00239 0.07247 16384 1280 rwrites 17.26 30000 1 1738.41 0.00057 0.00141 0.00264 0.06638 16384 1280 rreads 10.78 30000 1 2784.06 0.00036 0.00047 0.00061 0.02218 16384 1280 rreads 10.68 30000 1 2809.73 0.00036 0.00047 0.00060 0.02218 16384 1280 Perf test finished on February 3, 2024 at 04:15:29 PM UTC