Perf test begins at February 23, 2024 at 09:59:25 PM UTC A new loop begins at February 23, 2024 at 09:59:32 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-23T21:59:32.540357295Z","hostname":"ip-10-150-1-107.us-west-2.compute.internal","pid":1160} {"msg":"Crucible Version: BuildInfo {\n version: \"0.0.1\",\n git_sha: \"4952adb3d6892f2d87d77c8b3586f0f40cd8c3fc\",\n git_commit_timestamp: \"2024-02-23T21:13:29.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-23T21:59:32.540498766Z","hostname":"ip-10-150-1-107.us-west-2.compute.internal","pid":1160} {"msg":"Upstairs <-> Downstairs Message Version: 5","v":0,"name":"crucible","level":30,"time":"2024-02-23T21:59:32.540506325Z","hostname":"ip-10-150-1-107.us-west-2.compute.internal","pid":1160} {"msg":"Crucible 1888997b-a63d-49cf-bc9a-124d19bddf92 has session id: 7e159c09-76ef-4c47-abbc-726de20c5086","v":0,"name":"crucible","level":30,"time":"2024-02-23T21:59:32.540510825Z","hostname":"ip-10-150-1-107.us-west-2.compute.internal","pid":1160,"session_id":"7e159c09-76ef-4c47-abbc-726de20c5086"} {"msg":"Upstairs opts: Upstairs UUID: 1888997b-a63d-49cf-bc9a-124d19bddf92, 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-23T21:59:32.540554192Z","hostname":"ip-10-150-1-107.us-west-2.compute.internal","pid":1160,"session_id":"7e159c09-76ef-4c47-abbc-726de20c5086"} {"msg":"Crucible stats registered with UUID: 1888997b-a63d-49cf-bc9a-124d19bddf92","v":0,"name":"crucible","level":30,"time":"2024-02-23T21:59:32.540559152Z","hostname":"ip-10-150-1-107.us-west-2.compute.internal","pid":1160,"session_id":"7e159c09-76ef-4c47-abbc-726de20c5086"} Crucible runtime is spawned {"msg":"The guest has requested activation with gen:1","v":0,"name":"crucible","level":30,"time":"2024-02-23T21:59:32.540662954Z","hostname":"ip-10-150-1-107.us-west-2.compute.internal","pid":1160} {"msg":"1888997b-a63d-49cf-bc9a-124d19bddf92 active request set","v":0,"name":"crucible","level":30,"time":"2024-02-23T21:59:32.540878099Z","hostname":"ip-10-150-1-107.us-west-2.compute.internal","pid":1160,"session_id":"7e159c09-76ef-4c47-abbc-726de20c5086"} {"msg":"sending connect oneshot to client","v":0,"name":"crucible","level":30,"time":"2024-02-23T21:59:32.540896848Z","hostname":"ip-10-150-1-107.us-west-2.compute.internal","pid":1160,"client":"0","":"downstairs","session_id":"7e159c09-76ef-4c47-abbc-726de20c5086"} {"msg":"client set_active_request while in New; waiting...","v":0,"name":"crucible","level":30,"time":"2024-02-23T21:59:32.540904727Z","hostname":"ip-10-150-1-107.us-west-2.compute.internal","pid":1160,"client":"0","":"downstairs","session_id":"7e159c09-76ef-4c47-abbc-726de20c5086"} {"msg":"sending connect oneshot to client","v":0,"name":"crucible","level":30,"time":"2024-02-23T21:59:32.540912447Z","hostname":"ip-10-150-1-107.us-west-2.compute.internal","pid":1160,"client":"1","":"downstairs","session_id":"7e159c09-76ef-4c47-abbc-726de20c5086"} {"msg":"client set_active_request while in New; waiting...","v":0,"name":"crucible","level":30,"time":"2024-02-23T21:59:32.540920796Z","hostname":"ip-10-150-1-107.us-west-2.compute.internal","pid":1160,"client":"1","":"downstairs","session_id":"7e159c09-76ef-4c47-abbc-726de20c5086"} {"msg":"sending connect oneshot to client","v":0,"name":"crucible","level":30,"time":"2024-02-23T21:59:32.540928596Z","hostname":"ip-10-150-1-107.us-west-2.compute.internal","pid":1160,"client":"2","":"downstairs","session_id":"7e159c09-76ef-4c47-abbc-726de20c5086"} {"msg":"client set_active_request while in New; waiting...","v":0,"name":"crucible","level":30,"time":"2024-02-23T21:59:32.540935875Z","hostname":"ip-10-150-1-107.us-west-2.compute.internal","pid":1160,"client":"2","":"downstairs","session_id":"7e159c09-76ef-4c47-abbc-726de20c5086"} {"msg":"connecting to 127.0.0.1:8810","v":0,"name":"crucible","level":30,"time":"2024-02-23T21:59:32.540975092Z","hostname":"ip-10-150-1-107.us-west-2.compute.internal","pid":1160,"":"io task","client":"0","":"downstairs","session_id":"7e159c09-76ef-4c47-abbc-726de20c5086"} {"msg":"connecting to 127.0.0.1:8830","v":0,"name":"crucible","level":30,"time":"2024-02-23T21:59:32.54101603Z","hostname":"ip-10-150-1-107.us-west-2.compute.internal","pid":1160,"":"io task","client":"2","":"downstairs","session_id":"7e159c09-76ef-4c47-abbc-726de20c5086"} {"msg":"connecting to 127.0.0.1:8820","v":0,"name":"crucible","level":30,"time":"2024-02-23T21:59:32.541025289Z","hostname":"ip-10-150-1-107.us-west-2.compute.internal","pid":1160,"":"io task","client":"1","":"downstairs","session_id":"7e159c09-76ef-4c47-abbc-726de20c5086"} {"msg":"ds_connection connected","v":0,"name":"crucible","level":30,"time":"2024-02-23T21:59:32.541129622Z","hostname":"ip-10-150-1-107.us-west-2.compute.internal","pid":1160,"":"io task","client":"1","":"downstairs","session_id":"7e159c09-76ef-4c47-abbc-726de20c5086"} {"msg":"ds_connection connected","v":0,"name":"crucible","level":30,"time":"2024-02-23T21:59:32.541190568Z","hostname":"ip-10-150-1-107.us-west-2.compute.internal","pid":1160,"":"io task","client":"2","":"downstairs","session_id":"7e159c09-76ef-4c47-abbc-726de20c5086"} {"msg":"ds_connection connected","v":0,"name":"crucible","level":30,"time":"2024-02-23T21:59:32.541203087Z","hostname":"ip-10-150-1-107.us-west-2.compute.internal","pid":1160,"":"io task","client":"0","":"downstairs","session_id":"7e159c09-76ef-4c47-abbc-726de20c5086"} {"msg":"ds_transition from New to WaitActive","v":0,"name":"crucible","level":30,"time":"2024-02-23T21:59:32.541741239Z","hostname":"ip-10-150-1-107.us-west-2.compute.internal","pid":1160,"client":"1","":"downstairs","session_id":"7e159c09-76ef-4c47-abbc-726de20c5086"} {"msg":"[1] Transition from New to WaitActive","v":0,"name":"crucible","level":30,"time":"2024-02-23T21:59:32.541762038Z","hostname":"ip-10-150-1-107.us-west-2.compute.internal","pid":1160,"client":"1","":"downstairs","session_id":"7e159c09-76ef-4c47-abbc-726de20c5086"} {"msg":"ds_transition from New to WaitActive","v":0,"name":"crucible","level":30,"time":"2024-02-23T21:59:32.541770457Z","hostname":"ip-10-150-1-107.us-west-2.compute.internal","pid":1160,"client":"2","":"downstairs","session_id":"7e159c09-76ef-4c47-abbc-726de20c5086"} {"msg":"[2] Transition from New to WaitActive","v":0,"name":"crucible","level":30,"time":"2024-02-23T21:59:32.541777607Z","hostname":"ip-10-150-1-107.us-west-2.compute.internal","pid":1160,"client":"2","":"downstairs","session_id":"7e159c09-76ef-4c47-abbc-726de20c5086"} {"msg":"ds_transition from New to WaitActive","v":0,"name":"crucible","level":30,"time":"2024-02-23T21:59:32.541784136Z","hostname":"ip-10-150-1-107.us-west-2.compute.internal","pid":1160,"client":"0","":"downstairs","session_id":"7e159c09-76ef-4c47-abbc-726de20c5086"} {"msg":"[0] Transition from New to WaitActive","v":0,"name":"crucible","level":30,"time":"2024-02-23T21:59:32.541798295Z","hostname":"ip-10-150-1-107.us-west-2.compute.internal","pid":1160,"client":"0","":"downstairs","session_id":"7e159c09-76ef-4c47-abbc-726de20c5086"} {"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-23T21:59:32.54201416Z","hostname":"ip-10-150-1-107.us-west-2.compute.internal","pid":1160,"client":"1","":"downstairs","session_id":"7e159c09-76ef-4c47-abbc-726de20c5086"} {"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-23T21:59:32.542068356Z","hostname":"ip-10-150-1-107.us-west-2.compute.internal","pid":1160,"client":"2","":"downstairs","session_id":"7e159c09-76ef-4c47-abbc-726de20c5086"} {"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-23T21:59:32.542114973Z","hostname":"ip-10-150-1-107.us-west-2.compute.internal","pid":1160,"client":"0","":"downstairs","session_id":"7e159c09-76ef-4c47-abbc-726de20c5086"} {"msg":"ds_transition from WaitActive to WaitQuorum","v":0,"name":"crucible","level":30,"time":"2024-02-23T21:59:32.544813176Z","hostname":"ip-10-150-1-107.us-west-2.compute.internal","pid":1160,"client":"2","":"downstairs","session_id":"7e159c09-76ef-4c47-abbc-726de20c5086"} {"msg":"[2] Transition from WaitActive to WaitQuorum","v":0,"name":"crucible","level":30,"time":"2024-02-23T21:59:32.544830714Z","hostname":"ip-10-150-1-107.us-west-2.compute.internal","pid":1160,"client":"2","":"downstairs","session_id":"7e159c09-76ef-4c47-abbc-726de20c5086"} {"msg":"Waiting for true more clients to be ready","v":0,"name":"crucible","level":30,"time":"2024-02-23T21:59:32.544835674Z","hostname":"ip-10-150-1-107.us-west-2.compute.internal","pid":1160,"session_id":"7e159c09-76ef-4c47-abbc-726de20c5086"} {"msg":"ds_transition from WaitActive to WaitQuorum","v":0,"name":"crucible","level":30,"time":"2024-02-23T21:59:32.549117356Z","hostname":"ip-10-150-1-107.us-west-2.compute.internal","pid":1160,"client":"1","":"downstairs","session_id":"7e159c09-76ef-4c47-abbc-726de20c5086"} {"msg":"[1] Transition from WaitActive to WaitQuorum","v":0,"name":"crucible","level":30,"time":"2024-02-23T21:59:32.549134355Z","hostname":"ip-10-150-1-107.us-west-2.compute.internal","pid":1160,"client":"1","":"downstairs","session_id":"7e159c09-76ef-4c47-abbc-726de20c5086"} {"msg":"Waiting for true more clients to be ready","v":0,"name":"crucible","level":30,"time":"2024-02-23T21:59:32.549139604Z","hostname":"ip-10-150-1-107.us-west-2.compute.internal","pid":1160,"session_id":"7e159c09-76ef-4c47-abbc-726de20c5086"} {"msg":"ds_transition from WaitActive to WaitQuorum","v":0,"name":"crucible","level":30,"time":"2024-02-23T21:59:32.55136122Z","hostname":"ip-10-150-1-107.us-west-2.compute.internal","pid":1160,"client":"0","":"downstairs","session_id":"7e159c09-76ef-4c47-abbc-726de20c5086"} {"msg":"[0] Transition from WaitActive to WaitQuorum","v":0,"name":"crucible","level":30,"time":"2024-02-23T21:59:32.551384088Z","hostname":"ip-10-150-1-107.us-west-2.compute.internal","pid":1160,"client":"0","":"downstairs","session_id":"7e159c09-76ef-4c47-abbc-726de20c5086"} {"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-23T21:59:32.551394708Z","hostname":"ip-10-150-1-107.us-west-2.compute.internal","pid":1160,"":"downstairs","":"downstairs","session_id":"7e159c09-76ef-4c47-abbc-726de20c5086"} {"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-23T21:59:32.551404317Z","hostname":"ip-10-150-1-107.us-west-2.compute.internal","pid":1160,"":"downstairs","":"downstairs","session_id":"7e159c09-76ef-4c47-abbc-726de20c5086"} {"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-23T21:59:32.551414136Z","hostname":"ip-10-150-1-107.us-west-2.compute.internal","pid":1160,"":"downstairs","":"downstairs","session_id":"7e159c09-76ef-4c47-abbc-726de20c5086"} {"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-23T21:59:32.551423446Z","hostname":"ip-10-150-1-107.us-west-2.compute.internal","pid":1160,"":"downstairs","":"downstairs","session_id":"7e159c09-76ef-4c47-abbc-726de20c5086"} {"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-23T21:59:32.551432745Z","hostname":"ip-10-150-1-107.us-west-2.compute.internal","pid":1160,"":"downstairs","":"downstairs","session_id":"7e159c09-76ef-4c47-abbc-726de20c5086"} {"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-23T21:59:32.551441354Z","hostname":"ip-10-150-1-107.us-west-2.compute.internal","pid":1160,"":"downstairs","":"downstairs","session_id":"7e159c09-76ef-4c47-abbc-726de20c5086"} {"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-23T21:59:32.551451504Z","hostname":"ip-10-150-1-107.us-west-2.compute.internal","pid":1160,"":"downstairs","":"downstairs","session_id":"7e159c09-76ef-4c47-abbc-726de20c5086"} {"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-23T21:59:32.551460123Z","hostname":"ip-10-150-1-107.us-west-2.compute.internal","pid":1160,"":"downstairs","":"downstairs","session_id":"7e159c09-76ef-4c47-abbc-726de20c5086"} {"msg":"[2]R dirty[0..12]: [false, false, false, false, false, false, false, false, false, false, false, false]","vWait for a query_work_queue command to finish before sending IO ":0,"name":"crucible","level":30,"time":"2024-02-23T21:59:32.551472362Z","hostname":"ip-10-150-1-107.us-west-2.compute.internal","pid":1160,"":"downstairs","":"downstairs","session_id":"7e159c09-76ef-4c47-abbc-726de20c5086"} {"msg":"Max found gen is 1","v":0,"name":"crucible","level":30,"time":"2024-02-23T21:59:32.551481912Z","hostname":"ip-10-150-1-107.us-west-2.compute.internal","pid":1160,"":"downstairs","":"downstairs","session_id":"7e159c09-76ef-4c47-abbc-726de20c5086"} {"msg":"Generation requested: 1 >= found:1","v":0,"name":"crucible","level":30,"time":"2024-02-23T21:59:32.55150133Z","hostname":"ip-10-150-1-107.us-west-2.compute.internal","pid":1160,"":"downstairs","":"downstairs","session_id":"7e159c09-76ef-4c47-abbc-726de20c5086"} {"msg":"Next flush: 1","v":0,"name":"crucible","level":30,"time":"2024-02-23T21:59:32.55151043Z","hostname":"ip-10-150-1-107.us-west-2.compute.internal","pid":1160,"":"downstairs","":"downstairs","session_id":"7e159c09-76ef-4c47-abbc-726de20c5086"} {"msg":"All extents match","v":0,"name":"crucible","level":30,"time":"2024-02-23T21:59:32.551519159Z","hostname":"ip-10-150-1-107.us-west-2.compute.internal","pid":1160,"":"downstairs","":"downstairs","session_id":"7e159c09-76ef-4c47-abbc-726de20c5086"} {"msg":"No downstairs reconciliation required","v":0,"name":"crucible","level":30,"time":"2024-02-23T21:59:32.551528308Z","hostname":"ip-10-150-1-107.us-west-2.compute.internal","pid":1160,"session_id":"7e159c09-76ef-4c47-abbc-726de20c5086"} {"msg":"Transition from WaitQuorum to Active","v":0,"name":"crucible","level":30,"time":"2024-02-23T21:59:32.551535368Z","hostname":"ip-10-150-1-107.us-west-2.compute.internal","pid":1160,"client":"0","":"downstairs","session_id":"7e159c09-76ef-4c47-abbc-726de20c5086"} {"msg":"Transition from WaitQuorum to Active","v":0,"name":"crucible","level":30,"time":"2024-02-23T21:59:32.551544077Z","hostname":"ip-10-150-1-107.us-west-2.compute.internal","pid":1160,"client":"1","":"downstairs","session_id":"7e159c09-76ef-4c47-abbc-726de20c5086"} {"msg":"Transition from WaitQuorum to Active","v":0,"name":"crucible","level":30,"time":"2024-02-23T21:59:32.551552957Z","hostname":"ip-10-150-1-107.us-west-2.compute.internal","pid":1160,"client":"2","":"downstairs","session_id":"7e159c09-76ef-4c47-abbc-726de20c5086"} {"msg":"All required reconciliation work is completed","v":0,"name":"crucible","level":30,"time":"2024-02-23T21:59:32.551562066Z","hostname":"ip-10-150-1-107.us-west-2.compute.internal","pid":1160,"session_id":"7e159c09-76ef-4c47-abbc-726de20c5086"} {"msg":"Set Downstairs and Upstairs active after reconciliation","v":0,"name":"crucible","level":30,"time":"2024-02-23T21:59:32.551570035Z","hostname":"ip-10-150-1-107.us-west-2.compute.internal","pid":1160,"session_id":"7e159c09-76ef-4c47-abbc-726de20c5086"} {"msg":"1888997b-a63d-49cf-bc9a-124d19bddf92 is now active with session: 7e159c09-76ef-4c47-abbc-726de20c5086","v":0,"name":"crucible","level":30,"time":"2024-02-23T21:59:32.551578535Z","hostname":"ip-10-150-1-107.us-west-2.compute.internal","pid":1160,"session_id":"7e159c09-76ef-4c47-abbc-726de20c5086"} {"msg":"Set Active after no reconciliation","v":0,"name":"crucible","level":30,"time":"2024-02-23T21:59:32.551586054Z","hostname":"ip-10-150-1-107.us-west-2.compute.internal","pid":1160,"session_id":"7e159c09-76ef-4c47-abbc-726de20c5086"} {"msg":"The guest has finished waiting for activation with:1","v":0,"name":"crucible","level":30,"time":"2024-02-23T21:59:32.551593914Z","hostname":"ip-10-150-1-107.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 18.60 30000 1 1613.28 0.00062 0.00144 0.00194 0.04315 16384 640 rwrites 7.92 30000 1 3789.15 0.00026 0.00072 0.00157 0.05714 16384 640 rreads 5.62 30000 1 5339.07 0.00019 0.00023 0.00028 0.01834 16384 640 rreads 5.64 30000 1 5322.71 0.00019 0.00024 0.00028 0.01867 16384 640 A new loop begins at February 23, 2024 at 10:00:27 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-23T22:00:27.554246883Z","hostname":"ip-10-150-1-107.us-west-2.compute.internal","pid":1179} {"msg":"Crucible Version: BuildInfo {\n version: \"0.0.1\",\n git_sha: \"4952adb3d6892f2d87d77c8b3586f0f40cd8c3fc\",\n git_commit_timestamp: \"2024-02-23T21:13:29.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-23T22:00:27.554356926Z","hostname":"ip-10-150-1-107.us-west-2.compute.internal","pid":1179} {"msg":"Upstairs <-> Downstairs Message Version: 5","v":0,"name":"crucible","level":30,"time":"2024-02-23T22:00:27.554364025Z","hostname":"ip-10-150-1-107.us-west-2.compute.internal","pid":1179} {"msg":"Crucible e21d430c-d8d0-490a-b43e-b40961b20fb1 has session id: b522d3df-8434-4dcb-9367-8ebeca42faf7","v":0,"name":"crucible","level":30,"time":"2024-02-23T22:00:27.554368525Z","hostname":"ip-10-150-1-107.us-west-2.compute.internal","pid":1179Crucible runtime is spawned ,"session_id":"b522d3df-8434-4dcb-9367-8ebeca42faf7"} {"msg":"Upstairs opts: Upstairs UUID: e21d430c-d8d0-490a-b43e-b40961b20fb1, 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-23T22:00:27.554387264Z","hostname":"ip-10-150-1-107.us-west-2.compute.internal","pid":1179,"session_id":"b522d3df-8434-4dcb-9367-8ebeca42faf7"} {"msg":"Crucible stats registered with UUID: e21d430c-d8d0-490a-b43e-b40961b20fb1","v":0,"name":"crucible","level":30,"time":"2024-02-23T22:00:27.554392333Z","hostname":"ip-10-150-1-107.us-west-2.compute.internal","pid":1179,"session_id":"b522d3df-8434-4dcb-9367-8ebeca42faf7"} {"msg":"The guest has requested activation with gen:1","v":0,"name":"crucible","level":30,"time":"2024-02-23T22:00:27.554397803Z","hostname":"ip-10-150-1-107.us-west-2.compute.internal","pid":1179} {"msg":"e21d430c-d8d0-490a-b43e-b40961b20fb1 active request set","v":0,"name":"crucible","level":30,"time":"2024-02-23T22:00:27.554510165Z","hostname":"ip-10-150-1-107.us-west-2.compute.internal","pid":1179,"session_id":"b522d3df-8434-4dcb-9367-8ebeca42faf7"} {"msg":"sending connect oneshot to client","v":0,"name":"crucible","level":30,"time":"2024-02-23T22:00:27.554524734Z","hostname":"ip-10-150-1-107.us-west-2.compute.internal","pid":1179,"client":"0","":"downstairs","session_id":"b522d3df-8434-4dcb-9367-8ebeca42faf7"} {"msg":"client set_active_request while in New; waiting...","v":0,"name":"crucible","level":30,"time":"2024-02-23T22:00:27.554533953Z","hostname":"ip-10-150-1-107.us-west-2.compute.internal","pid":1179,"client":"0","":"downstairs","session_id":"b522d3df-8434-4dcb-9367-8ebeca42faf7"} {"msg":"sending connect oneshot to client","v":0,"name":"crucible","level":30,"time":"2024-02-23T22:00:27.554540893Z","hostname":"ip-10-150-1-107.us-west-2.compute.internal","pid":1179,"client":"1","":"downstairs","session_id":"b522d3df-8434-4dcb-9367-8ebeca42faf7"} {"msg":"client set_active_request while in New; waiting...","v":0,"name":"crucible","level":30,"time":"2024-02-23T22:00:27.554548522Z","hostname":"ip-10-150-1-107.us-west-2.compute.internal","pid":1179,"client":"1","":"downstairs","session_id":"b522d3df-8434-4dcb-9367-8ebeca42faf7"} {"msg":"sending connect oneshot to client","v":0,"name":"crucible","level":30,"time":"2024-02-23T22:00:27.554555682Z","hostname":"ip-10-150-1-107.us-west-2.compute.internal","pid":1179,"client":"2","":"downstairs","session_id":"b522d3df-8434-4dcb-9367-8ebeca42faf7"} {"msg":"client set_active_request while in New; waiting...","v":0,"name":"crucible","level":30,"time":"2024-02-23T22:00:27.554564851Z","hostname":"ip-10-150-1-107.us-west-2.compute.internal","pid":1179,"client":"2","":"downstairs","session_id":"b522d3df-8434-4dcb-9367-8ebeca42faf7"} {"msg":"connecting to 127.0.0.1:8830","v":0,"name":"crucible","level":30,"time":"2024-02-23T22:00:27.55457338Z","hostname":"ip-10-150-1-107.us-west-2.compute.internal","pid":1179,"":"io task","client":"2","":"downstairs","session_id":"b522d3df-8434-4dcb-9367-8ebeca42faf7"} {"msg":"connecting to 127.0.0.1:8810","v":0,"name":"crucible","level":30,"time":"2024-02-23T22:00:27.55458628Z","hostname":"ip-10-150-1-107.us-west-2.compute.internal","pid":1179,"":"io task","client":"0","":"downstairs","session_id":"b522d3df-8434-4dcb-9367-8ebeca42faf7"} {"msg":"connecting to 127.0.0.1:8820","v":0,"name":"crucible","level":30,"time":"2024-02-23T22:00:27.554593679Z","hostname":"ip-10-150-1-107.us-west-2.compute.internal","pid":1179,"":"io task","client":"1","":"downstairs","session_id":"b522d3df-8434-4dcb-9367-8ebeca42faf7"} {"msg":"ds_connection connected","v":0,"name":"crucible","level":30,"time":"2024-02-23T22:00:27.554738769Z","hostname":"ip-10-150-1-107.us-west-2.compute.internal","pid":1179,"":"io task","client":"0","":"downstairs","session_id":"b522d3df-8434-4dcb-9367-8ebeca42faf7"} {"msg":"ds_connection connected","v":0,"name":"crucible","level":30,"time":"2024-02-23T22:00:27.554838462Z","hostname":"ip-10-150-1-107.us-west-2.compute.internal","pid":1179,"":"io task","client":"1","":"downstairs","session_id":"b522d3df-8434-4dcb-9367-8ebeca42faf7"} {"msg":"ds_connection connected","v":0,"name":"crucible","level":30,"time":"2024-02-23T22:00:27.55486689Z","hostname":"ip-10-150-1-107.us-west-2.compute.internal","pid":1179,"":"io task","client":"2","":"downstairs","session_id":"b522d3df-8434-4dcb-9367-8ebeca42faf7"} {"msg":"ds_transition from New to WaitActive","v":0,"name":"crucible","level":30,"time":"2024-02-23T22:00:27.555127412Z","hostname":"ip-10-150-1-107.us-west-2.compute.internal","pid":1179,"client":"1","":"downstairs","session_id":"b522d3df-8434-4dcb-9367-8ebeca42faf7"} {"msg":"[1] Transition from New to WaitActive","v":0,"name":"crucible","level":30,"time":"2024-02-23T22:00:27.555169889Z","hostname":"ip-10-150-1-107.us-west-2.compute.internal","pid":1179,"client":"1","":"downstairs","session_id":"b522d3df-8434-4dcb-9367-8ebeca42faf7"} {"msg":"ds_transition from New to WaitActive","v":0,"name":"crucible","level":30,"time":"2024-02-23T22:00:27.555178748Z","hostname":"ip-10-150-1-107.us-west-2.compute.internal","pid":1179,"client":"0","":"downstairs","session_id":"b522d3df-8434-4dcb-9367-8ebeca42faf7"} {"msg":"[0] Transition from New to WaitActive","v":0,"name":"crucible","level":30,"time":"2024-02-23T22:00:27.555186248Z","hostname":"ip-10-150-1-107.us-west-2.compute.internal","pid":1179,"client":"0","":"downstairs","session_id":"b522d3df-8434-4dcb-9367-8ebeca42faf7"} {"msg":"ds_transition from New to WaitActive","v":0,"name":"crucible","level":30,"time":"2024-02-23T22:00:27.555193427Z","hostname":"ip-10-150-1-107.us-west-2.compute.internal","pid":1179,"client":"2","":"downstairs","session_id":"b522d3df-8434-4dcb-9367-8ebeca42faf7"} {"msg":"[2] Transition from New to WaitActive","v":0,"name":"crucible","level":30,"time":"2024-02-23T22:00:27.555201397Z","hostname":"ip-10-150-1-107.us-west-2.compute.internal","pid":1179,"client":"2","":"downstairs","session_id":"b522d3df-8434-4dcb-9367-8ebeca42faf7"} {"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-23T22:00:27.555338907Z","hostname":"ip-10-150-1-107.us-west-2.compute.internal","pid":1179,"client":"1","":"downstairs","session_id":"b522d3df-8434-4dcb-9367-8ebeca42faf7"} {"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-23T22:00:27.555371625Z","hostname":"ip-10-150-1-107.us-west-2.compute.internal","pid":1179,"client":"0","":"downstairs","session_id":"b522d3df-8434-4dcb-9367-8ebeca42faf7"} {"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-23T22:00:27.555391354Z","hostname":"ip-10-150-1-107.us-west-2.compute.internal","pid":1179,"client":"2","":"downstairs","session_id":"b522d3df-8434-4dcb-9367-8ebeca42faf7"} {"msg":"ds_transition from WaitActive to WaitQuorum","v":0,"name":"crucible","level":30,"time":"2024-02-23T22:00:27.560965096Z","hostname":"ip-10-150-1-107.us-west-2.compute.internal","pid":1179,"client":"0","":"downstairs","session_id":"b522d3df-8434-4dcb-9367-8ebeca42faf7"} {"msg":"[0] Transition from WaitActive to WaitQuorum","v":0,"name":"crucible","level":30,"time":"2024-02-23T22:00:27.560984905Z","hostname":"ip-10-150-1-107.us-west-2.compute.internal","pid":1179,"client":"0","":"downstairs","session_id":"b522d3df-8434-4dcb-9367-8ebeca42faf7"} {"msg":"Waiting for true more clients to be ready","v":0,"name":"crucible","level":30,"time":"2024-02-23T22:00:27.561007083Z","hostname":"ip-10-150-1-107.us-west-2.compute.internal","pid":1179,"session_id":"b522d3df-8434-4dcb-9367-8ebeca42faf7"} {"msg":"ds_transition from WaitActive to WaitQuorum","v":0,"name":"crucible","level":30,"time":"2024-02-23T22:00:27.561544125Z","hostname":"ip-10-150-1-107.us-west-2.compute.internal","pid":1179,"client":"1","":"downstairs","session_id":"b522d3df-8434-4dcb-9367-8ebeca42faf7"} {"msg":"[1] Transition from WaitActive to WaitQuorum","v":0,"name":"crucible","level":30,"time":"2024-02-23T22:00:27.561564864Z","hostname":"ip-10-150-1-107.us-west-2.compute.internal","pid":1179,"client":"1","":"downstairs","session_id":"b522d3df-8434-4dcb-9367-8ebeca42faf7"} {"msg":"Waiting for true more clients to be ready","v":0,"name":"crucible","level":30,"time":"2024-02-23T22:00:27.561572053Z","hostname":"ip-10-150-1-107.us-west-2.compute.internal","pid":1179,"session_id":"b522d3df-8434-4dcb-9367-8ebeca42faf7"} {"msg":"ds_transition from WaitActive to WaitQuorum","v":0,"name":"crucible","level":30,"time":"2024-02-23T22:00:27.56190327Z","hostname":"ip-10-150-1-107.us-west-2.compute.internal","pid":1179,"client":"2","":"downstairs","session_id":"b522d3df-8434-4dcb-9367-8ebeca42faf7"} {"msg":"[2] Transition from WaitActive to WaitQuorum","v":0,"name":"crucible","level":30,"time":"2024-02-23T22:00:27.561920639Z","hostname":"ip-10-150-1-107.us-west-2.compute.internal","pid":1179,"client":"2","":"downstairs","session_id":"b522d3df-8434-4dcb-9367-8ebeca42faf7"} {"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-23T22:00:27.561926879Z","hostname":"ip-10-150-1-107.us-west-2.compute.internal","pid":1179,"":"downstairs","":"downstairs","session_id":"b522d3df-8434-4dcb-9367-8ebeca42faf7"} {"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-23T22:00:27.561932368Z","hostname":"ip-10-150-1-107.us-west-2.compute.internal","pid":1179,"":"downstairs","":"downstairs","session_id":"b522d3df-8434-4dcb-9367-8ebeca42faf7"} {"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-23T22:00:27.561937758Z","hostname":"ip-10-150-1-107.us-west-2.compute.internal","pid":1179,"":"downstairs","":"downstairs","session_id":"b522d3df-8434-4dcb-9367-8ebeca42faf7"} {"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-23T22:00:27.561943288Z","hostname":"ip-10-150-1-107.us-west-2.compute.internal","pid":1179,"":"downstairs","":"downstairs","session_id":"b522d3df-8434-4dcb-9367-8ebeca42faf7"} {"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-23T22:00:27.561948577Z","hostname":"ip-10-150-1-107.us-west-2.compute.internal","pid":1179,"":"downstairs","":"downstairs","session_id":"b522d3df-8434-4dcb-9367-8ebeca42faf7"} {"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-23T22:00:27.561953697Z","hostname":"ip-10-150-1-107.us-west-2.compute.internal","pid":1179,"":"downstairs","":"downstairs","session_id":"b522d3df-8434-4dcb-9367-8ebeca42faf7"} {"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-23T22:00:27.561959666Z","hostname":"ip-10-150-1-107.us-west-2.compute.internal","pid":1179,"":"downstairs","":"downstairs","session_id":"b522d3df-8434-4dcb-9367-8ebeca42faf7"} {"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-23T22:00:27.561964736Z","hostname":"ip-10-150-1-107.us-west-2.compute.internal","pid":1179,"":"downstairs","":"downstairs","session_id":"b522d3df-8434-4dcb-9367-8ebeca42faf7"} {"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-23T22:00:27.561970536Z","hostname":"ip-10-150-1-107.us-west-2.compute.internal","pid":1179,"":"downstairs","":"downstairs","session_id":"b522d3df-8434-4dcb-9367-8ebeca42faf7"} {"msg":"Max found gen is 1","v":0,"name":"crucible","level":30,"time":"2024-02-23T22:00:27.561976005Z","hostname":"ip-10-150-1-107.us-west-2.compute.internal","pid":1179,"":"downstairs","":"downstairs","session_id":"b522d3df-8434-4dcb-9367-8ebeca42faf7"} {"msg":"Generation requested: 1 >= found:1","v":0,"name":"crucible","level":30,"time":"2024-02-23T22:00:27.561981985Z","hostname":"ip-10-150-1-107.us-west-2.compute.internal","pid":1179,"":"downstairs","":"downstairs","session_id":"b522d3df-8434-4dcb-9367-8ebeca42faf7"} {"msg":"Next flush: 1","v":0,"name":"crucible","level":30,"time":"2024-02-23T22:00:27.561987215Z","hostname":"ip-10-150-1-107.us-west-2.compute.internal","pid":1179,"":"downstairs","":"downstairs","session_id":"b522d3df-8434-4dcb-9367-8ebeca42faf7"} {"msg":"All extents match","v":0,"name":"crucible","level":30,"time":"2024-02-23T22:00:27.561992644Z","hostname":"ip-10-150-1-107.us-west-2.compute.internal","pid":1179,"":"downstairs","":"downstairs","session_id":"b522d3df-8434-4dcb-9367-8ebeca42faf7"} {"msg":"No downstairs reconciliation required","v":0,"name":"crucible","level":30,"time":"2024-02-23T22:00:27.561997964Z","hostname":"ip-10-150-1-107.us-west-2.compute.internal","pid":1179,"session_id":"b522d3df-8434-4dcb-9367-8ebeca42faf7"} {"msg":"Transition from WaitQuorum to Active","v":0,"name":"crucible","level":30,"time":"2024-02-23T22:00:27.562002574Z","hostname":"ip-10-150-1-107.us-west-2.compute.internal","pid":1179,"client":"0","":"downstairs","session_id":"b522d3df-8434-4dcb-9367-8ebeca42faf7"} {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-23T22:00:27.562010873Z","hostname":"ip-10-150-1-107.us-west-2.compute.internal","pid":1179,"client":"1","":"downstairs","session_id":"b522d3df-8434-4dcb-9367-8ebeca42faf7"} {"msg":"Transition from WaitQuorum to Active","v":0,"name":"crucible","level":30,"time":"2024-02-23T22:00:27.562016122Z","hostname":"ip-10-150-1-107.us-west-2.compute.internal","pid":1179,"client":"2","":"downstairs","session_id":"b522d3df-8434-4dcb-9367-8ebeca42faf7"} {"msg":"All required reconciliation work is completed","v":0,"name":"crucible","level":30,"time":"2024-02-23T22:00:27.562021292Z","hostname":"ip-10-150-1-107.us-west-2.compute.internal","pid":1179,"session_id":"b522d3df-8434-4dcb-9367-8ebeca42faf7"} {"msg":"Set Downstairs and Upstairs active after reconciliation","v":0,"name":"crucible","level":30,"time":"2024-02-23T22:00:27.562025902Z","hostname":"ip-10-150-1-107.us-west-2.compute.internal","pid":1179,"session_id":"b522d3df-8434-4dcb-9367-8ebeca42faf7"} {"msg":"e21d430c-d8d0-490a-b43e-b40961b20fb1 is now active with session: b522d3df-8434-4dcb-9367-8ebeca42faf7","v":0,"name":"crucible","level":30,"time":"2024-02-23T22:00:27.562031732Z","hostname":"ip-10-150-1-107.us-west-2.compute.internal","pid":1179,"session_id":"b522d3df-8434-4dcb-9367-8ebeca42faf7"} {"msg":"The guest has finished waiting for activation with:1","v":0,"name":"crucible","level":30,"time":"2024-02-23T22:00:27.562036201Z","hostname":"ip-10-150-1-107.us-west-2.compute.internal","pid":1179} {"msg":"Set Active after no reconciliation","v":0,"name":"crucible","level":30,"time":"2024-02-23T22:00:27.562040611Z","hostname":"ip-10-150-1-107.us-west-2.compute.internal","pid":1179,"session_id":"b522d3df-8434-4dcb-9367-8ebeca42faf7"} Region: es:16384 ec:1280 bs:4096 ts:85899345920 tb:20971520 max_io:256 or 1048576 Perf test TEST SECONDS COUNT DPTH IOPS MEAN P95 P99 MAX ES EC rwrites 8.37 30000 1 3582.45 0.00028 0.00064 0.00136 0.07164 16384 1280 rwrites 8.38 30000 1 3581.72 0.00028 0.00061 0.00110 0.06722 16384 1280 rreads 5.55 30000 1 5405.14 0.00018 0.00023 0.00027 0.01701 16384 1280 rreads 5.59 30000 1 5364.40 0.00019 0.00023 0.00027 0.01701 16384 1280 Perf test finished on February 23, 2024 at 10:01:07 PM UTC