Perf test begins at February 1, 2024 at 05:26:27 PM UTC A new loop begins at February 1, 2024 at 05:26:36 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-01T17:26:36.421452273Z","hostname":"ip-10-150-1-14.us-west-2.compute.internal","pid":1157} {"msg":"Crucible Version: BuildInfo {\n version: \"0.0.1\",\n git_sha: \"c49269318fbfc7a408561fd872515f115027bbe7\",\n git_commit_timestamp: \"2024-02-01T16:48:08.000000000Z\",\n git_branch: \"alan/more-info\",\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-01T17:26:36.421751174Z","hostname":"ip-10-150-1-14.us-west-2.compute.internal","pid":1157} {"msg":"Upstairs <-> Downstairs Message Version: 5","v":0,"name":"crucible","level":30,"time":"2024-02-01T17:26:36.421761854Z","hostname":"ip-10-150-1-14.us-west-2.compute.internal","pid":1157} {"msg":"Crucible aef12dba-1360-4fd7-b532-b8495d21d75d has session id: 148604ea-f3e5-4462-addd-e8dfc3d116b7","v":0,"name":"crucible","level":30,"time":"2024-02-01T17:26:36.421768688Z","hostname":"ip-10-150-1-14.us-west-2.compute.internal","pid":1157,"session_id":"148604ea-f3e5-4462-addd-e8dfc3d116b7"} {"msg":"Upstairs opts: Upstairs UUID: aef12dba-1360-4fd7-b532-b8495d21d75d, 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-01T17:26:36.421874608Z","hostname":"ip-10-150-1-14.us-west-2.compute.internal","pid":1157,"session_id":"148604ea-f3e5-4462-addd-e8dfc3d116b7"} {"msg":"Crucible stats registered with UUID: aef12dba-1360-4fd7-b532-b8495d21d75d","v":0,"name":"crucible","level":30,"time":"2024-02-01T17:26:36.421906058Z","hostname":"ip-10-150-1-14.us-west-2.compute.internal","pid":1157,"session_id":"148604ea-f3e5-4462-addd-e8dfc3d116b7"} Crucible runtime is spawned {"msg":"The guest has requested activation with gen:1","v":0,"name":"crucible","level":30,"time":"2024-02-01T17:26:36.422232744Z","hostname":"ip-10-150-1-14.us-west-2.compute.internal","pid":1157} {"msg":"aef12dba-1360-4fd7-b532-b8495d21d75d active request set","v":0,"name":"crucible","level":30,"time":"2024-02-01T17:26:36.42259718Z","hostname":"ip-10-150-1-14.us-west-2.compute.internal","pid":1157,"session_id":"148604ea-f3e5-4462-addd-e8dfc3d116b7"} {"msg":"sending connect oneshot to client","v":0,"name":"crucible","level":30,"time":"2024-02-01T17:26:36.422633301Z","hostname":"ip-10-150-1-14.us-west-2.compute.internal","pid":1157,"client":"0","":"downstairs","session_id":"148604ea-f3e5-4462-addd-e8dfc3d116b7"} {"msg":"client set_active_request while in New; waiting...","v":0,"name":"crucible","level":30,"time":"2024-02-01T17:26:36.422643266Z","hostname":"ip-10-150-1-14.us-west-2.compute.internal","pid":1157,"client":"0","":"downstairs","session_id":"148604ea-f3e5-4462-addd-e8dfc3d116b7"} {"msg":"sending connect oneshot to client","v":0,"name":"crucible","level":30,"time":"2024-02-01T17:26:36.42265084Z","hostname":"ip-10-150-1-14.us-west-2.compute.internal","pid":1157,"client":"1","":"downstairs","session_id":"148604ea-f3e5-4462-addd-e8dfc3d116b7"} {"msg":"client set_active_request while in New; waiting...","v":0,"name":"crucible","level":30,"time":"2024-02-01T17:26:36.422657896Z","hostname":"ip-10-150-1-14.us-west-2.compute.internal","pid":1157,"client":"1","":"downstairs","session_id":"148604ea-f3e5-4462-addd-e8dfc3d116b7"} {"msg":"sending connect oneshot to client","v":0,"name":"crucible","level":30,"time":"2024-02-01T17:26:36.422665702Z","hostname":"ip-10-150-1-14.us-west-2.compute.internal","pid":1157,"client":"2","":"downstairs","session_id":"148604ea-f3e5-4462-addd-e8dfc3d116b7"} {"msg":"client set_active_request while in New; waiting...","v":0,"name":"crucible","level":30,"time":"2024-02-01T17:26:36.422700059Z","hostname":"ip-10-150-1-14.us-west-2.compute.internal","pid":1157,"client":"2","":"downstairs","session_id":"148604ea-f3e5-4462-addd-e8dfc3d116b7"} {"msg":"connecting to 127.0.0.1:8830","v":0,"name":"crucible","level":30,"time":"2024-02-01T17:26:36.422714143Z","hostname":"ip-10-150-1-14.us-west-2.compute.internal","pid":1157,"":"io task","client":"2","":"downstairs","session_id":"148604ea-f3e5-4462-addd-e8dfc3d116b7"} {"msg":"connecting to 127.0.0.1:8810","v":0,"name":"crucible","level":30,"time":"2024-02-01T17:26:36.422728701Z","hostname":"ip-10-150-1-14.us-west-2.compute.internal","pid":1157,"":"io task","client":"0","":"downstairs","session_id":"148604ea-f3e5-4462-addd-e8dfc3d116b7"} {"msg":"connecting to 127.0.0.1:8820","v":0,"name":"crucible","level":30,"time":"2024-02-01T17:26:36.42274765Z","hostname":"ip-10-150-1-14.us-west-2.compute.internal","pid":1157,"":"io task","client":"1","":"downstairs","session_id":"148604ea-f3e5-4462-addd-e8dfc3d116b7"} {"msg":"ds_connection connected","v":0,"name":"crucible","level":30,"time":"2024-02-01T17:26:36.422924047Z","hostname":"ip-10-150-1-14.us-west-2.compute.internal","pid":1157,"":"io task","client":"2","":"downstairs","session_id":"148604ea-f3e5-4462-addd-e8dfc3d116b7"} {"msg":"ds_connection connected","v":0,"name":"crucible","level":30,"time":"2024-02-01T17:26:36.423170954Z","hostname":"ip-10-150-1-14.us-west-2.compute.internal","pid":1157,"":"io task","client":"1","":"downstairs","session_id":"148604ea-f3e5-4462-addd-e8dfc3d116b7"} {"msg":"ds_connection connected","v":0,"name":"crucible","level":30,"time":"2024-02-01T17:26:36.423189677Z","hostname":"ip-10-150-1-14.us-west-2.compute.internal","pid":1157,"":"io task","client":"0","":"downstairs","session_id":"148604ea-f3e5-4462-addd-e8dfc3d116b7"} {"msg":"ds_transition from New to WaitActive","v":0,"name":"crucible","level":30,"time":"2024-02-01T17:26:36.423969792Z","hostname":"ip-10-150-1-14.us-west-2.compute.internal","pid":1157,"client":"1","":"downstairs","session_id":"148604ea-f3e5-4462-addd-e8dfc3d116b7"} {"msg":"[1] Transition from New to WaitActive","v":0,"name":"crucible","level":30,"time":"2024-02-01T17:26:36.424010067Z","hostname":"ip-10-150-1-14.us-west-2.compute.internal","pid":1157,"client":"1","":"downstairs","session_id":"148604ea-f3e5-4462-addd-e8dfc3d116b7"} {"msg":"ds_transition from New to WaitActive","v":0,"name":"crucible","level":30,"time":"2024-02-01T17:26:36.424023189Z","hostname":"ip-10-150-1-14.us-west-2.compute.internal","pid":1157,"client":"2","":"downstairs","session_id":"148604ea-f3e5-4462-addd-e8dfc3d116b7"} {"msg":"[2] Transition from New to WaitActive","v":0,"name":"crucible","level":30,"time":"2024-02-01T17:26:36.424030658Z","hostname":"ip-10-150-1-14.us-west-2.compute.internal","pid":1157,"client":"2","":"downstairs","session_id":"148604ea-f3e5-4462-addd-e8dfc3d116b7"} {"msg":"ds_transition from New to WaitActive","v":0,"name":"crucible","level":30,"time":"2024-02-01T17:26:36.424043771Z","hostname":"ip-10-150-1-14.us-west-2.compute.internal","pid":1157,"client":"0","":"downstairs","session_id":"148604ea-f3e5-4462-addd-e8dfc3d116b7"} {"msg":"[0] Transition from New to WaitActive","v":0,"name":"crucible","level":30,"time":"2024-02-01T17:26:36.424052433Z","hostname":"ip-10-150-1-14.us-west-2.compute.internal","pid":1157,"client":"0","":"downstairs","session_id":"148604ea-f3e5-4462-addd-e8dfc3d116b7"} {"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-01T17:26:36.42460346Z","hostname":"ip-10-150-1-14.us-west-2.compute.internal","pid":1157,"client":"2","":"downstairs","session_id":"148604ea-f3e5-4462-addd-e8dfc3d116b7"} {"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-01T17:26:36.424642491Z","hostname":"ip-10-150-1-14.us-west-2.compute.internal","pid":1157,"client":"1","":"downstairs","session_id":"148604ea-f3e5-4462-addd-e8dfc3d116b7"} {"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-01T17:26:36.424662509Z","hostname":"ip-10-150-1-14.us-west-2.compute.internal","pid":1157,"client":"0","":"downstairs","session_id":"148604ea-f3e5-4462-addd-e8dfc3d116b7"} {"msg":"ds_transition from WaitActive to WaitQuorum","v":0,"name":"crucible","level":30,"time":"2024-02-01T17:26:36.429855038Z","hostname":"ip-10-150-1-14.us-west-2.compute.internal","pid":1157,"client":"0","":"downstairs","session_id":"148604ea-f3e5-4462-addd-e8dfc3d116b7"} {"msg":"[0] Transition from WaitActive to WaitQuorum","v":0,"name":"crucible","level":30,"time":"2024-02-01T17:26:36.429886781Z","hostname":"ip-10-150-1-14.us-west-2.compute.internal","pid":1157,"client":"0","":"downstairs","session_id":"148604ea-f3e5-4462-addd-e8dfc3d116b7"} {"msg":"Waiting for true more clients to be ready","v":0,"name":"crucible","level":30,"time":"2024-02-01T17:26:36.429894472Z","hostname":"ip-10-150-1-14.us-west-2.compute.internal","pid":1157,"session_id":"148604ea-f3e5-4462-addd-e8dfc3d116b7"} {"msg":"ds_transition from WaitActive to WaitQuorum","v":0,"name":"crucible","level":30,"time":"2024-02-01T17:26:36.430893219Z","hostname":"ip-10-150-1-14.us-west-2.compute.internal","pid":1157,"client":"2","":"downstairs","session_id":"148604ea-f3e5-4462-addd-e8dfc3d116b7"} {"msg":"[2] Transition from WaitActive to WaitQuorum","v":0,"name":"crucible","level":30,"time":"2024-02-01T17:26:36.430979786Z","hostname":"ip-10-150-1-14.us-west-2.compute.internal","pid":1157,"client":"2","":"downstairs","session_id":"148604ea-f3e5-4462-addd-e8dfc3d116b7"} {"msg":"Waiting for true more clients to be ready","v":0,"name":"crucible","level":30,"time":"2024-02-01T17:26:36.430987936Z","hostname":"ip-10-150-1-14.us-west-2.compute.internal","pid":1157,"session_id":"148604ea-f3e5-4462-addd-e8dfc3d116b7"} {"msg":"ds_transition from WaitActive to WaitQuorum","v":0,"name":"crucible","level":30,"time":"2024-02-01T17:26:36.430994457Z","hostname":"ip-10-150-1-14.us-west-2.compute.internal","pid":1157,"client":"1","":"downstairs","session_id":"148604ea-f3e5-4462-addd-e8dfc3d116b7"} {"msg":"[1] Transition from WaitActive to WaitQuorum","v":0,"name":"crucible","level":30,"time":"2024-02-01T17:26:36.431001903Z","hostname":"ip-10-150-1-14.us-west-2.compute.internal","pid":1157,"client":"1","":"downstairs","session_id":"148604ea-f3e5-4462-addd-e8dfc3d116b7"} {"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-01T17:26:36.431009471Z","hostname":"ip-10-150-1-14.us-west-2.compute.internal","pid":1157,"":"downstairs","":"downstairs","session_id":"148604ea-f3e5-4462-addd-e8dfc3d116b7"} {"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-01T17:26:36.431017045Z","hostname":"ip-10-150-1-14.us-west-2.compute.internal","pid":1157,"":"downstairs","":"downstairs","session_id":"148604ea-f3e5-4462-addd-e8dfc3d116b7"} {"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-01T17:26:36.431024359Z","hostname":"ip-10-150-1-14.us-west-2.compute.internal","pid":1157,"":"downstairs","":"downstairs","session_id":"148604ea-f3e5-4462-addd-e8dfc3d116b7"} {"msg":"[1]R flush_numbers[0..12]: [0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0]","v":0,"name":"crucible","level":30Wait for a query_work_queue command to finish before sending IO ,"time":"2024-02-01T17:26:36.431059245Z","hostname":"ip-10-150-1-14.us-west-2.compute.internal","pid":1157,"":"downstairs","":"downstairs","session_id":"148604ea-f3e5-4462-addd-e8dfc3d116b7"} {"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-01T17:26:36.43107377Z","hostname":"ip-10-150-1-14.us-west-2.compute.internal","pid":1157,"":"downstairs","":"downstairs","session_id":"148604ea-f3e5-4462-addd-e8dfc3d116b7"} {"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-01T17:26:36.43111021Z","hostname":"ip-10-150-1-14.us-west-2.compute.internal","pid":1157,"":"downstairs","":"downstairs","session_id":"148604ea-f3e5-4462-addd-e8dfc3d116b7"} {"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-01T17:26:36.431119801Z","hostname":"ip-10-150-1-14.us-west-2.compute.internal","pid":1157,"":"downstairs","":"downstairs","session_id":"148604ea-f3e5-4462-addd-e8dfc3d116b7"} {"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-01T17:26:36.431126964Z","hostname":"ip-10-150-1-14.us-west-2.compute.internal","pid":1157,"":"downstairs","":"downstairs","session_id":"148604ea-f3e5-4462-addd-e8dfc3d116b7"} {"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-01T17:26:36.431133972Z","hostname":"ip-10-150-1-14.us-west-2.compute.internal","pid":1157,"":"downstairs","":"downstairs","session_id":"148604ea-f3e5-4462-addd-e8dfc3d116b7"} {"msg":"Max found gen is 1","v":0,"name":"crucible","level":30,"time":"2024-02-01T17:26:36.43114301Z","hostname":"ip-10-150-1-14.us-west-2.compute.internal","pid":1157,"":"downstairs","":"downstairs","session_id":"148604ea-f3e5-4462-addd-e8dfc3d116b7"} {"msg":"Generation requested: 1 >= found:1","v":0,"name":"crucible","level":30,"time":"2024-02-01T17:26:36.431151331Z","hostname":"ip-10-150-1-14.us-west-2.compute.internal","pid":1157,"":"downstairs","":"downstairs","session_id":"148604ea-f3e5-4462-addd-e8dfc3d116b7"} {"msg":"Next flush: 1","v":0,"name":"crucible","level":30,"time":"2024-02-01T17:26:36.431195791Z","hostname":"ip-10-150-1-14.us-west-2.compute.internal","pid":1157,"":"downstairs","":"downstairs","session_id":"148604ea-f3e5-4462-addd-e8dfc3d116b7"} {"msg":"All extents match","v":0,"name":"crucible","level":30,"time":"2024-02-01T17:26:36.43121141Z","hostname":"ip-10-150-1-14.us-west-2.compute.internal","pid":1157,"":"downstairs","":"downstairs","session_id":"148604ea-f3e5-4462-addd-e8dfc3d116b7"} {"msg":"No downstairs reconciliation required","v":0,"name":"crucible","level":30,"time":"2024-02-01T17:26:36.43124699Z","hostname":"ip-10-150-1-14.us-west-2.compute.internal","pid":1157,"session_id":"148604ea-f3e5-4462-addd-e8dfc3d116b7"} {"msg":"Transition from WaitQuorum to Active","v":0,"name":"crucible","level":30,"time":"2024-02-01T17:26:36.431254909Z","hostname":"ip-10-150-1-14.us-west-2.compute.internal","pid":1157,"client":"0","":"downstairs","session_id":"148604ea-f3e5-4462-addd-e8dfc3d116b7"} {"msg":"Transition from WaitQuorum to Active","v":0,"name":"crucible","level":30,"time":"2024-02-01T17:26:36.431261817Z","hostname":"ip-10-150-1-14.us-west-2.compute.internal","pid":1157,"client":"1","":"downstairs","session_id":"148604ea-f3e5-4462-addd-e8dfc3d116b7"} {"msg":"Transition from WaitQuorum to Active","v":0,"name":"crucible","level":30,"time":"2024-02-01T17:26:36.431268627Z","hostname":"ip-10-150-1-14.us-west-2.compute.internal","pid":1157,"client":"2","":"downstairs","session_id":"148604ea-f3e5-4462-addd-e8dfc3d116b7"} {"msg":"All required reconciliation work is completed","v":0,"name":"crucible","level":30,"time":"2024-02-01T17:26:36.431277114Z","hostname":"ip-10-150-1-14.us-west-2.compute.internal","pid":1157,"session_id":"148604ea-f3e5-4462-addd-e8dfc3d116b7"} {"msg":"Set Downstairs and Upstairs active after reconciliation","v":0,"name":"crucible","level":30,"time":"2024-02-01T17:26:36.431286135Z","hostname":"ip-10-150-1-14.us-west-2.compute.internal","pid":1157,"session_id":"148604ea-f3e5-4462-addd-e8dfc3d116b7"} {"msg":"aef12dba-1360-4fd7-b532-b8495d21d75d is now active with session: 148604ea-f3e5-4462-addd-e8dfc3d116b7","v":0,"name":"crucible","level":30,"time":"2024-02-01T17:26:36.431325969Z","hostname":"ip-10-150-1-14.us-west-2.compute.internal","pid":1157,"session_id":"148604ea-f3e5-4462-addd-e8dfc3d116b7"} {"msg":"Set Active after no reconciliation","v":0,"name":"crucible","level":30,"time":"2024-02-01T17:26:36.431340405Z","hostname":"ip-10-150-1-14.us-west-2.compute.internal","pid":1157,"session_id":"148604ea-f3e5-4462-addd-e8dfc3d116b7"} {"msg":"The guest has finished waiting for activation with:1","v":0,"name":"crucible","level":30,"time":"2024-02-01T17:26:36.431351252Z","hostname":"ip-10-150-1-14.us-west-2.compute.internal","pid":1157} 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.17 30000 1 1487.59 0.00067 0.00167 0.00255 0.08382 16384 640 rwrites 14.90 30000 1 2013.28 0.00050 0.00116 0.00261 0.07836 16384 640 rreads 10.46 30000 1 2868.83 0.00035 0.00047 0.00060 0.01656 16384 640 rreads 10.40 30000 1 2883.26 0.00035 0.00046 0.00059 0.01758 16384 640 {"msg":"Guest handle has been dropped","v":0,"name":"crucible","level":40,"time":"2024-02-01T17:27:34.812508742Z","hostname":"ip-10-150-1-14.us-west-2.compute.internal","pid":1157} A new loop begins at February 1, 2024 at 05:27:45 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-01T17:27:45.390304843Z","hostname":"ip-10-150-1-14.us-west-2.compute.internal","pid":1176} {"msg":"Crucible Version: BuildInfo {\n version: \"0.0.1\",\n git_sha: \"c49269318fbfc7a408561fd872515f115027bbe7\",\n git_commit_timestamp: \"2024-02-01T16:48:08.000000000Z\",\n git_branch: \"alan/more-info\",\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-01T17:27:45.390550415Z","hostname":"ip-10-150-1-14.us-west-2.compute.internal","pid":1176} {"msg":"Upstairs <-> Downstairs Message Version: 5","v":0,"name":"crucible","level":30Crucible runtime is spawned ,"time":"2024-02-01T17:27:45.390560929Z","hostname":"ip-10-150-1-14.us-west-2.compute.internal","pid":1176} {"msg":"Crucible aeed4ae0-681f-499d-8be8-c0480b90062c has session id: 083b5e56-34f3-4bd5-bd37-76b8e9378a72","v":0,"name":"crucible","level":30,"time":"2024-02-01T17:27:45.390653545Z","hostname":"ip-10-150-1-14.us-west-2.compute.internal","pid":1176,"session_id":"083b5e56-34f3-4bd5-bd37-76b8e9378a72"} {"msg":"Upstairs opts: Upstairs UUID: aeed4ae0-681f-499d-8be8-c0480b90062c, 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-01T17:27:45.390697127Z","hostname":"ip-10-150-1-14.us-west-2.compute.internal","pid":1176,"session_id":"083b5e56-34f3-4bd5-bd37-76b8e9378a72"} {"msg":"Crucible stats registered with UUID: aeed4ae0-681f-499d-8be8-c0480b90062c","v":0,"name":"crucible","level":30,"time":"2024-02-01T17:27:45.390705718Z","hostname":"ip-10-150-1-14.us-west-2.compute.internal","pid":1176,"session_id":"083b5e56-34f3-4bd5-bd37-76b8e9378a72"} {"msg":"The guest has requested activation with gen:1","v":0,"name":"crucible","level":30,"time":"2024-02-01T17:27:45.390712746Z","hostname":"ip-10-150-1-14.us-west-2.compute.internal","pid":1176} {"msg":"aeed4ae0-681f-499d-8be8-c0480b90062c active request set","v":0,"name":"crucible","level":30,"time":"2024-02-01T17:27:45.390719116Z","hostname":"ip-10-150-1-14.us-west-2.compute.internal","pid":1176,"session_id":"083b5e56-34f3-4bd5-bd37-76b8e9378a72"} {"msg":"sending connect oneshot to client","v":0,"name":"crucible","level":30,"time":"2024-02-01T17:27:45.390727127Z","hostname":"ip-10-150-1-14.us-west-2.compute.internal","pid":1176,"client":"0","":"downstairs","session_id":"083b5e56-34f3-4bd5-bd37-76b8e9378a72"} {"msg":"client set_active_request while in New; waiting...","v":0,"name":"crucible","level":30,"time":"2024-02-01T17:27:45.390738594Z","hostname":"ip-10-150-1-14.us-west-2.compute.internal","pid":1176,"client":"0","":"downstairs","session_id":"083b5e56-34f3-4bd5-bd37-76b8e9378a72"} {"msg":"sending connect oneshot to client","v":0,"name":"crucible","level":30,"time":"2024-02-01T17:27:45.390746722Z","hostname":"ip-10-150-1-14.us-west-2.compute.internal","pid":1176,"client":"1","":"downstairs","session_id":"083b5e56-34f3-4bd5-bd37-76b8e9378a72"} {"msg":"client set_active_request while in New; waiting...","v":0,"name":"crucible","level":30,"time":"2024-02-01T17:27:45.390754304Z","hostname":"ip-10-150-1-14.us-west-2.compute.internal","pid":1176,"client":"1","":"downstairs","session_id":"083b5e56-34f3-4bd5-bd37-76b8e9378a72"} {"msg":"sending connect oneshot to client","v":0,"name":"crucible","level":30,"time":"2024-02-01T17:27:45.39076299Z","hostname":"ip-10-150-1-14.us-west-2.compute.internal","pid":1176,"client":"2","":"downstairs","session_id":"083b5e56-34f3-4bd5-bd37-76b8e9378a72"} {"msg":"client set_active_request while in New; waiting...","v":0,"name":"crucible","level":30,"time":"2024-02-01T17:27:45.390770489Z","hostname":"ip-10-150-1-14.us-west-2.compute.internal","pid":1176,"client":"2","":"downstairs","session_id":"083b5e56-34f3-4bd5-bd37-76b8e9378a72"} {"msg":"connecting to 127.0.0.1:8810","v":0,"name":"crucible","level":30,"time":"2024-02-01T17:27:45.390919782Z","hostname":"ip-10-150-1-14.us-west-2.compute.internal","pid":1176,"":"io task","client":"0","":"downstairs","session_id":"083b5e56-34f3-4bd5-bd37-76b8e9378a72"} {"msg":"connecting to 127.0.0.1:8830","v":0,"name":"crucible","level":30,"time":"2024-02-01T17:27:45.390969877Z","hostname":"ip-10-150-1-14.us-west-2.compute.internal","pid":1176,"":"io task","client":"2","":"downstairs","session_id":"083b5e56-34f3-4bd5-bd37-76b8e9378a72"} {"msg":"connecting to 127.0.0.1:8820","v":0,"name":"crucible","level":30,"time":"2024-02-01T17:27:45.390984349Z","hostname":"ip-10-150-1-14.us-west-2.compute.internal","pid":1176,"":"io task","client":"1","":"downstairs","session_id":"083b5e56-34f3-4bd5-bd37-76b8e9378a72"} {"msg":"ds_connection connected","v":0,"name":"crucible","level":30,"time":"2024-02-01T17:27:45.391192186Z","hostname":"ip-10-150-1-14.us-west-2.compute.internal","pid":1176,"":"io task","client":"0","":"downstairs","session_id":"083b5e56-34f3-4bd5-bd37-76b8e9378a72"} {"msg":"ds_connection connected","v":0,"name":"crucible","level":30,"time":"2024-02-01T17:27:45.39121599Z","hostname":"ip-10-150-1-14.us-west-2.compute.internal","pid":1176,"":"io task","client":"1","":"downstairs","session_id":"083b5e56-34f3-4bd5-bd37-76b8e9378a72"} {"msg":"ds_connection connected","v":0,"name":"crucible","level":30,"time":"2024-02-01T17:27:45.391234909Z","hostname":"ip-10-150-1-14.us-west-2.compute.internal","pid":1176,"":"io task","client":"2","":"downstairs","session_id":"083b5e56-34f3-4bd5-bd37-76b8e9378a72"} {"msg":"ds_transition from New to WaitActive","v":0,"name":"crucible","level":30,"time":"2024-02-01T17:27:45.391808109Z","hostname":"ip-10-150-1-14.us-west-2.compute.internal","pid":1176,"client":"1","":"downstairs","session_id":"083b5e56-34f3-4bd5-bd37-76b8e9378a72"} {"msg":"[1] Transition from New to WaitActive","v":0,"name":"crucible","level":30,"time":"2024-02-01T17:27:45.391837539Z","hostname":"ip-10-150-1-14.us-west-2.compute.internal","pid":1176,"client":"1","":"downstairs","session_id":"083b5e56-34f3-4bd5-bd37-76b8e9378a72"} {"msg":"ds_transition from New to WaitActive","v":0,"name":"crucible","level":30,"time":"2024-02-01T17:27:45.391845072Z","hostname":"ip-10-150-1-14.us-west-2.compute.internal","pid":1176,"client":"0","":"downstairs","session_id":"083b5e56-34f3-4bd5-bd37-76b8e9378a72"} {"msg":"[0] Transition from New to WaitActive","v":0,"name":"crucible","level":30,"time":"2024-02-01T17:27:45.391852103Z","hostname":"ip-10-150-1-14.us-west-2.compute.internal","pid":1176,"client":"0","":"downstairs","session_id":"083b5e56-34f3-4bd5-bd37-76b8e9378a72"} {"msg":"ds_transition from New to WaitActive","v":0,"name":"crucible","level":30,"time":"2024-02-01T17:27:45.391864733Z","hostname":"ip-10-150-1-14.us-west-2.compute.internal","pid":1176,"client":"2","":"downstairs","session_id":"083b5e56-34f3-4bd5-bd37-76b8e9378a72"} {"msg":"[2] Transition from New to WaitActive","v":0,"name":"crucible","level":30,"time":"2024-02-01T17:27:45.3918721Z","hostname":"ip-10-150-1-14.us-west-2.compute.internal","pid":1176,"client":"2","":"downstairs","session_id":"083b5e56-34f3-4bd5-bd37-76b8e9378a72"} {"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-01T17:27:45.392535772Z","hostname":"ip-10-150-1-14.us-west-2.compute.internal","pid":1176,"client":"1","":"downstairs","session_id":"083b5e56-34f3-4bd5-bd37-76b8e9378a72"} {"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-01T17:27:45.392575589Z","hostname":"ip-10-150-1-14.us-west-2.compute.internal","pid":1176,"client":"0","":"downstairs","session_id":"083b5e56-34f3-4bd5-bd37-76b8e9378a72"} {"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-01T17:27:45.392803416Z","hostname":"ip-10-150-1-14.us-west-2.compute.internal","pid":1176,"client":"2","":"downstairs","session_id":"083b5e56-34f3-4bd5-bd37-76b8e9378a72"} {"msg":"ds_transition from WaitActive to WaitQuorum","v":0,"name":"crucible","level":30,"time":"2024-02-01T17:27:45.402915199Z","hostname":"ip-10-150-1-14.us-west-2.compute.internal","pid":1176,"client":"2","":"downstairs","session_id":"083b5e56-34f3-4bd5-bd37-76b8e9378a72"} {"msg":"[2] Transition from WaitActive to WaitQuorum","v":0,"name":"crucible","level":30,"time":"2024-02-01T17:27:45.402939516Z","hostname":"ip-10-150-1-14.us-west-2.compute.internal","pid":1176,"client":"2","":"downstairs","session_id":"083b5e56-34f3-4bd5-bd37-76b8e9378a72"} {"msg":"Waiting for true more clients to be ready","v":0,"name":"crucible","level":30,"time":"2024-02-01T17:27:45.402953101Z","hostname":"ip-10-150-1-14.us-west-2.compute.internal","pid":1176,"session_id":"083b5e56-34f3-4bd5-bd37-76b8e9378a72"} {"msg":"ds_transition from WaitActive to WaitQuorum","v":0,"name":"crucible","level":30,"time":"2024-02-01T17:27:45.403137299Z","hostname":"ip-10-150-1-14.us-west-2.compute.internal","pid":1176,"client":"0","":"downstairs","session_id":"083b5e56-34f3-4bd5-bd37-76b8e9378a72"} {"msg":"[0] Transition from WaitActive to WaitQuorum","v":0,"name":"crucible","level":30,"time":"2024-02-01T17:27:45.403176296Z","hostname":"ip-10-150-1-14.us-west-2.compute.internal","pid":1176,"client":"0","":"downstairs","session_id":"083b5e56-34f3-4bd5-bd37-76b8e9378a72"} {"msg":"Waiting for true more clients to be ready","v":0,"name":"crucible","level":30,"time":"2024-02-01T17:27:45.403189704Z","hostname":"ip-10-150-1-14.us-west-2.compute.internal","pid":1176,"session_id":"083b5e56-34f3-4bd5-bd37-76b8e9378a72"} {"msg":"ds_transition from WaitActive to WaitQuorum","v":0,"name":"crucible","level":30,"time":"2024-02-01T17:27:45.403261351Z","hostname":"ip-10-150-1-14.us-west-2.compute.internal","pid":1176,"client":"1","":"downstairs","session_id":"083b5e56-34f3-4bd5-bd37-76b8e9378a72"} {"msg":"[1] Transition from WaitActive to WaitQuorum","v":0,"name":"crucible","level":30,"time":"2024-02-01T17:27:45.403275638Z","hostname":"ip-10-150-1-14.us-west-2.compute.internal","pid":1176,"client":"1","":"downstairs","session_id":"083b5e56-34f3-4bd5-bd37-76b8e9378a72"} {"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-01T17:27:45.403315278Z","hostname":"ip-10-150-1-14.us-west-2.compute.internal","pid":1176,"":"downstairs","":"downstairs","session_id":"083b5e56-34f3-4bd5-bd37-76b8e9378a72"} {"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-01T17:27:45.403329196Z","hostname":"ip-10-150-1-14.us-west-2.compute.internal","pid":1176,"":"downstairs","":"downstairs","session_id":"083b5e56-34f3-4bd5-bd37-76b8e9378a72"} {"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-01T17:27:45.403341802Z","hostname":"ip-10-150-1-14.us-west-2.compute.internal","pid":1176,"":"downstairs","":"downstairs","session_id":"083b5e56-34f3-4bd5-bd37-76b8e9378a72"} {"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-01T17:27:45.403354617Z","hostname":"ip-10-150-1-14.us-west-2.compute.internal","pid":1176,"":"downstairs","":"downstairs","session_id":"083b5e56-34f3-4bd5-bd37-76b8e9378a72"} {"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-01T17:27:45.403367759Z","hostname":"ip-10-150-1-14.us-west-2.compute.internal","pid":1176,"":"downstairs","":"downstairs","session_id":"083b5e56-34f3-4bd5-bd37-76b8e9378a72"} {"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-01T17:27:45.40338079Z","hostname":"ip-10-150-1-14.us-west-2.compute.internal","pid":1176,"":"downstairs","":"downstairs","session_id":"083b5e56-34f3-4bd5-bd37-76b8e9378a72"} {"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-01T17:27:45.403394387Z","hostname":"ip-10-150-1-14.us-west-2.compute.internal","pid":1176,"":"downstairs","":"downstairs","session_id":"083b5e56-34f3-4bd5-bd37-76b8e9378a72"} {"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-01T17:27:45.403406323Z","hostname":"ip-10-150-1-14.us-west-2.compute.internal","pid":1176,"":"downstairs","":"downstairs","session_id":"083b5e56-34f3-4bd5-bd37-76b8e9378a72"} {"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-01T17:27:45.403418253Z","hostname":"ip-10-150-1-14.us-west-2.compute.internal","pid":1176,"":"downstairs","":"downstairs","session_id":"083b5e56-34f3-4bd5-bd37-76b8e9378a72"} {"msg":"Max found gen is 1","v":0,"name":"crucible","level":30,"time":"2024-02-01T17:27:45.403430638Z","hostname":"ip-10-150-1-14.us-west-2.compute.internal","pid":1176,"":"downstairs","":"downstairs","session_id":"083b5e56-34f3-4bd5-bd37-76b8e9378a72"} {"msg":"Generation requested: 1 >= found:1","v":0,"name":"crucible","levelWait for a query_work_queue command to finish before sending IO ":30,"time":"2024-02-01T17:27:45.403446199Z","hostname":"ip-10-150-1-14.us-west-2.compute.internal","pid":1176,"":"downstairs","":"downstairs","session_id":"083b5e56-34f3-4bd5-bd37-76b8e9378a72"} {"msg":"Next flush: 1","v":0,"name":"crucible","level":30,"time":"2024-02-01T17:27:45.403454075Z","hostname":"ip-10-150-1-14.us-west-2.compute.internal","pid":1176,"":"downstairs","":"downstairs","session_id":"083b5e56-34f3-4bd5-bd37-76b8e9378a72"} {"msg":"All extents match","v":0,"name":"crucible","level":30,"time":"2024-02-01T17:27:45.40346144Z","hostname":"ip-10-150-1-14.us-west-2.compute.internal","pid":1176,"":"downstairs","":"downstairs","session_id":"083b5e56-34f3-4bd5-bd37-76b8e9378a72"} {"msg":"No downstairs reconciliation required","v":0,"name":"crucible","level":30,"time":"2024-02-01T17:27:45.403469Z","hostname":"ip-10-150-1-14.us-west-2.compute.internal","pid":1176,"session_id":"083b5e56-34f3-4bd5-bd37-76b8e9378a72"} {"msg":"Transition from WaitQuorum to Active","v":0,"name":"crucible","level":30,"time":"2024-02-01T17:27:45.403475702Z","hostname":"ip-10-150-1-14.us-west-2.compute.internal","pid":1176,"client":"0","":"downstairs","session_id":"083b5e56-34f3-4bd5-bd37-76b8e9378a72"} {"msg":"Transition from WaitQuorum to Active","v":0,"name":"crucible","level":30,"time":"2024-02-01T17:27:45.403483298Z","hostname":"ip-10-150-1-14.us-west-2.compute.internal","pid":1176,"client":"1","":"downstairs","session_id":"083b5e56-34f3-4bd5-bd37-76b8e9378a72"} {"msg":"Transition from WaitQuorum to Active","v":0,"name":"crucible","level":30,"time":"2024-02-01T17:27:45.403490258Z","hostname":"ip-10-150-1-14.us-west-2.compute.internal","pid":1176,"client":"2","":"downstairs","session_id":"083b5e56-34f3-4bd5-bd37-76b8e9378a72"} {"msg":"All required reconciliation work is completed","v":0,"name":"crucible","level":30,"time":"2024-02-01T17:27:45.40349734Z","hostname":"ip-10-150-1-14.us-west-2.compute.internal","pid":1176,"session_id":"083b5e56-34f3-4bd5-bd37-76b8e9378a72"} {"msg":"Set Downstairs and Upstairs active after reconciliation","v":0,"name":"crucible","level":30,"time":"2024-02-01T17:27:45.40350382Z","hostname":"ip-10-150-1-14.us-west-2.compute.internal","pid":1176,"session_id":"083b5e56-34f3-4bd5-bd37-76b8e9378a72"} {"msg":"aeed4ae0-681f-499d-8be8-c0480b90062c is now active with session: 083b5e56-34f3-4bd5-bd37-76b8e9378a72","v":0,"name":"crucible","level":30,"time":"2024-02-01T17:27:45.403510005Z","hostname":"ip-10-150-1-14.us-west-2.compute.internal","pid":1176,"session_id":"083b5e56-34f3-4bd5-bd37-76b8e9378a72"} {"msg":"Set Active after no reconciliation","v":0,"name":"crucible","level":30,"time":"2024-02-01T17:27:45.403515939Z","hostname":"ip-10-150-1-14.us-west-2.compute.internal","pid":1176,"session_id":"083b5e56-34f3-4bd5-bd37-76b8e9378a72"} {"msg":"The guest has finished waiting for activation with:1","v":0,"name":"crucible","level":30,"time":"2024-02-01T17:27:45.40352226Z","hostname":"ip-10-150-1-14.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.22 30000 1 1849.57 0.00054 0.00123 0.00232 0.08207 16384 1280 rwrites 16.45 30000 1 1823.22 0.00055 0.00132 0.00259 0.05957 16384 1280 rreads 10.20 30000 1 2940.67 0.00034 0.00045 0.00059 0.01758 16384 1280 rreads 10.19 30000 1 2944.55 0.00034 0.00045 0.00058 0.01758 16384 1280 {"msg":"Guest handle has been dropped","v":0,"name":"crucible","level":40,"time":"2024-02-01T17:28:40.990715047Z","hostname":"ip-10-150-1-14.us-west-2.compute.internal","pid":1176} Perf test finished on February 1, 2024 at 05:28:42 PM UTC