Perf test begins at August 5, 2024 at 07:06:50 PM UTC A new loop begins at August 5, 2024 at 07:06:58 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-08-05T19:06:58.227796099Z","hostname":"w-01J4HYXJ15GWTB3A0BGQ511MRA","pid":1195} {"msg":"Crucible Version: BuildInfo {\n version: \"0.0.1\",\n git_sha: \"955d5f2fb08fa12300fcdaa7dafdc9edb7db9942\",\n git_commit_timestamp: \"2024-08-01T19:59:22.000000000Z\",\n git_branch: \"fioffs-redux\",\n rustc_semver: \"1.76.0\",\n rustc_channel: \"stable\",\n rustc_host_triple: \"x86_64-unknown-illumos\",\n rustc_commit_sha: \"07dca489ac2d933c78d3c5158e3f43beefeb02ce\",\n cargo_triple: \"x86_64-unknown-illumos\",\n debug: false,\n opt_level: 3,\n}","v":0,"name":"crucible","level":30,"time":"2024-08-05T19:06:58.22797955Z","hostname":"w-01J4HYXJ15GWTB3A0BGQ511MRA","pid":1195} {"msg":"Upstairs <-> Downstairs Message Version: 11","v":0,"name":"crucible","level":30,"time":"2024-08-05T19:06:58.227987479Z","hostname":"w-01J4HYXJ15GWTB3A0BGQ511MRA","pid":1195} {"msg":"Crucible 51ff50e9-67c0-4f7c-b5cc-3cabaf94e1ae has session id: fa4ca208-59ca-43a9-82f5-a9c03ac5f395","v":0,"name":"crucible","level":30,"time":"2024-08-05T19:06:58.228372538Z","hostname":"w-01J4HYXJ15GWTB3A0BGQ511MRA","pid":1195,"session_id":"fa4ca208-59ca-43a9-82f5-a9c03ac5f395"} {"msg":"Upstairs opts: Upstairs UUID: 51ff50e9-67c0-4f7c-b5cc-3cabaf94e1ae, 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-08-05T19:06:58.228475522Z","hostname":"w-01J4HYXJ15GWTB3A0BGQ511MRA","pid":1195,"session_id":"fa4ca208-59ca-43a9-82f5-a9c03ac5f395"} {"msg":"Crucible stats registered with UUID: 51ff50e9-67c0-4f7c-b5cc-3cabaf94e1ae","v":0,"name":"crucible","level":30,"time":"2024-08-05T19:06:58.228492959Z","hostname":"w-01J4HYXJ15GWTB3A0BGQ511MRA","pid":1195,"session_id":"fa4ca208-59ca-43a9-82f5-a9c03ac5f395"} Crucible runtime is spawned {"msg":"The guest has requested activation with gen:1","v":0,"name":"crucible","level":30,"time":"2024-08-05T19:06:58.265947862Z","hostname":"w-01J4HYXJ15GWTB3A0BGQ511MRA","pid":1195} {"msg":"51ff50e9-67c0-4f7c-b5cc-3cabaf94e1ae active request set","v":0,"name":"crucible","level":30,"time":"2024-08-05T19:06:58.265971318Z","hostname":"w-01J4HYXJ15GWTB3A0BGQ511MRA","pid":1195,"session_id":"fa4ca208-59ca-43a9-82f5-a9c03ac5f395"} {"msg":"sending connect oneshot to client","v":0,"name":"crucible","level":30,"time":"2024-08-05T19:06:58.266039027Z","hostname":"w-01J4HYXJ15GWTB3A0BGQ511MRA","pid":1195,"client":"0","":"downstairs","session_id":"fa4ca208-59ca-43a9-82f5-a9c03ac5f395"} {"msg":"client set_active_request while in New; waiting...","v":0,"name":"crucible","level":30,"time":"2024-08-05T19:06:58.266055815Z","hostname":"w-01J4HYXJ15GWTB3A0BGQ511MRA","pid":1195,"client":"0","":"downstairs","session_id":"fa4ca208-59ca-43a9-82f5-a9c03ac5f395"} {"msg":"sending connect oneshot to client","v":0,"name":"crucible","level":30,"time":"2024-08-05T19:06:58.266062103Z","hostname":"w-01J4HYXJ15GWTB3A0BGQ511MRA","pid":1195,"client":"1","":"downstairs","session_id":"fa4ca208-59ca-43a9-82f5-a9c03ac5f395"} {"msg":"client set_active_request while in New; waiting...","v":0,"name":"crucible","level":30,"time":"2024-08-05T19:06:58.266067603Z","hostname":"w-01J4HYXJ15GWTB3A0BGQ511MRA","pid":1195,"client":"1","":"downstairs","session_id":"fa4ca208-59ca-43a9-82f5-a9c03ac5f395"} {"msg":"sending connect oneshot to client","v":0,"name":"crucible","level":30,"time":"2024-08-05T19:06:58.266073512Z","hostname":"w-01J4HYXJ15GWTB3A0BGQ511MRA","pid":1195,"client":"2","":"downstairs","session_id":"fa4ca208-59ca-43a9-82f5-a9c03ac5f395"} {"msg":"client set_active_request while in New; waiting...","v":0,"name":"crucible","level":30,"time":"2024-08-05T19:06:58.266079671Z","hostname":"w-01J4HYXJ15GWTB3A0BGQ511MRA","pid":1195,"client":"2","":"downstairs","session_id":"fa4ca208-59ca-43a9-82f5-a9c03ac5f395"} {"msg":"connecting to 127.0.0.1:8810","v":0,"name":"crucible","level":30,"time":"2024-08-05T19:06:58.266188084Z","hostname":"w-01J4HYXJ15GWTB3A0BGQ511MRA","pid":1195,"":"io task","client":"0","":"downstairs","session_id":"fa4ca208-59ca-43a9-82f5-a9c03ac5f395"} {"msg":"connecting to 127.0.0.1:8820","v":0,"name":"crucible","level":30,"time":"2024-08-05T19:06:58.266204971Z","hostname":"w-01J4HYXJ15GWTB3A0BGQ511MRA","pid":1195,"":"io task","client":"1","":"downstairs","session_id":"fa4ca208-59ca-43a9-82f5-a9c03ac5f395"} {"msg":"connecting to 127.0.0.1:8830","v":0,"name":"crucible","level":30,"time":"2024-08-05T19:06:58.26621093Z","hostname":"w-01J4HYXJ15GWTB3A0BGQ511MRA","pid":1195,"":"io task","client":"2","":"downstairs","session_id":"fa4ca208-59ca-43a9-82f5-a9c03ac5f395"} {"msg":"ds_connection connected from Ok(127.0.0.1:58903)","v":0,"name":"crucible","level":30,"time":"2024-08-05T19:06:58.266292217Z","hostname":"w-01J4HYXJ15GWTB3A0BGQ511MRA","pid":1195,"":"io task","client":"0","":"downstairs","session_id":"fa4ca208-59ca-43a9-82f5-a9c03ac5f395"} {"msg":"ds_connection connected from Ok(127.0.0.1:37729)","v":0,"name":"crucible","level":30,"time":"2024-08-05T19:06:58.266316283Z","hostname":"w-01J4HYXJ15GWTB3A0BGQ511MRA","pid":1195,"":"io task","client":"2","":"downstairs","session_id":"fa4ca208-59ca-43a9-82f5-a9c03ac5f395"} {"msg":"ds_connection connected from Ok(127.0.0.1:61924)","v":0,"name":"crucible","level":30,"time":"2024-08-05T19:06:58.266367305Z","hostname":"w-01J4HYXJ15GWTB3A0BGQ511MRA","pid":1195,"":"io task","client":"1","":"downstairs","session_id":"fa4ca208-59ca-43a9-82f5-a9c03ac5f395"} {"msg":"ds_transition from New to WaitActive","v":0,"name":"crucible","level":30,"time":"2024-08-05T19:06:58.266998335Z","hostname":"w-01J4HYXJ15GWTB3A0BGQ511MRA","pid":1195,"client":"1","":"downstairs","session_id":"fa4ca208-59ca-43a9-82f5-a9c03ac5f395"} {"msg":"[1] Transition from New to WaitActive","v":0,"name":"crucible","level":30,"time":"2024-08-05T19:06:58.267015503Z","hostname":"w-01J4HYXJ15GWTB3A0BGQ511MRA","pid":1195,"client":"1","":"downstairs","session_id":"fa4ca208-59ca-43a9-82f5-a9c03ac5f395"} {"msg":"ds_transition from New to WaitActive","v":0,"name":"crucible","level":30,"time":"2024-08-05T19:06:58.267020522Z","hostname":"w-01J4HYXJ15GWTB3A0BGQ511MRA","pid":1195,"client":"2","":"downstairs","session_id":"fa4ca208-59ca-43a9-82f5-a9c03ac5f395"} {"msg":"[2] Transition from New to WaitActive","v":0,"name":"crucible","level":30,"time":"2024-08-05T19:06:58.267044768Z","hostname":"w-01J4HYXJ15GWTB3A0BGQ511MRA","pid":1195,"client":"2","":"downstairs","session_id":"fa4ca208-59ca-43a9-82f5-a9c03ac5f395"} {"msg":"ds_transition from New to WaitActive","v":0,"name":"crucible","level":30,"time":"2024-08-05T19:06:58.267057536Z","hostname":"w-01J4HYXJ15GWTB3A0BGQ511MRA","pid":1195,"client":"0","":"downstairs","session_id":"fa4ca208-59ca-43a9-82f5-a9c03ac5f395"} {"msg":"[0] Transition from New to WaitActive","v":0,"name":"crucible","level":30,"time":"2024-08-05T19:06:58.267064755Z","hostname":"w-01J4HYXJ15GWTB3A0BGQ511MRA","pid":1195,"client":"0","":"downstairs","session_id":"fa4ca208-59ca-43a9-82f5-a9c03ac5f395"} {"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-08-05T19:06:58.267174778Z","hostname":"w-01J4HYXJ15GWTB3A0BGQ511MRA","pid":1195,"client":"1","":"downstairs","session_id":"fa4ca208-59ca-43a9-82f5-a9c03ac5f395"} {"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-08-05T19:06:58.267212361Z","hostname":"w-01J4HYXJ15GWTB3A0BGQ511MRA","pid":1195,"client":"2","":"downstairs","session_id":"fa4ca208-59ca-43a9-82f5-a9c03ac5f395"} {"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-08-05T19:06:58.267266263Z","hostname":"w-01J4HYXJ15GWTB3A0BGQ511MRA","pid":1195,"client":"0","":"downstairs","session_id":"fa4ca208-59ca-43a9-82f5-a9c03ac5f395"} {"msg":"ds_transition from WaitActive to WaitQuorum","v":0,"name":"crucible","level":30,"time":"2024-08-05T19:06:58.269458306Z","hostname":"w-01J4HYXJ15GWTB3A0BGQ511MRA","pid":1195,"client":"1","":"downstairs","session_id":"fa4ca208-59ca-43a9-82f5-a9c03ac5f395"} {"msg":"[1] Transition from WaitActive to WaitQuorum","v":0,"name":"crucible","level":30,"time":"2024-08-05T19:06:58.269475334Z","hostname":"w-01J4HYXJ15GWTB3A0BGQ511MRA","pid":1195,"client":"1","":"downstairs","session_id":"fa4ca208-59ca-43a9-82f5-a9c03ac5f395"} {"msg":"Waiting for more clients to be ready","v":0,"name":"crucible","level":30,"time":"2024-08-05T19:06:58.269480953Z","hostname":"w-01J4HYXJ15GWTB3A0BGQ511MRA","pid":1195,"session_id":"fa4ca208-59ca-43a9-82f5-a9c03ac5f395"} {"msg":"ds_transition from WaitActive to WaitQuorum","v":0,"name":"crucible","level":30,"time":"2024-08-05T19:06:58.270281306Z","hostname":"w-01J4HYXJ15GWTB3A0BGQ511MRA","pid":1195,"client":"2","":"downstairs","session_id":"fa4ca208-59ca-43a9-82f5-a9c03ac5f395"} {"msg":"[2] Transition from WaitActive to WaitQuorum","v":0,"name":"crucible","level":30,"time":"2024-08-05T19:06:58.270294954Z","hostname":"w-01J4HYXJ15GWTB3A0BGQ511MRA","pid":1195,"client":"2","":"downstairs","session_id":"fa4ca208-59ca-43a9-82f5-a9c03ac5f395"} {"msg":"Waiting for more clients to be ready","v":0,"name":"crucible","level":30,"time":"2024-08-05T19:06:58.270299593Z","hostname":"w-01J4HYXJ15GWTB3A0BGQ511MRA","pid":1195,"session_id":"fa4ca208-59ca-43a9-82f5-a9c03ac5f395"} {"msg":"ds_transition from WaitActive to WaitQuorum","v":0,"name":"crucible","level":30,"time":"2024-08-05T19:06:58.270304742Z","hostname":"w-01J4HYXJ15GWTB3A0BGQ511MRA","pid":1195,"client":"0","":"downstairs","session_id":"fa4ca208-59ca-43a9-82f5-a9c03ac5f395"} {"msg":"[0] Transition from WaitActive to WaitQuorum","v":0,"name":"crucible","level":30,"time":"2024-08-05T19:06:58.270309231Z","hostname":"w-01J4HYXJ15GWTB3A0BGQ511MRA","pid":1195,"client":"0","":"downstairs","session_id":"fa4ca208-59ca-43a9-82f5-a9c03ac5f395"} {"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-08-05T19:06:58.270313951Z","hostname":"w-01J4HYXJ15GWTB3A0BGQ511MRA","pid":1195,"":"downstairs","":"downstairs","session_id":"fa4ca208-59ca-43a9-82f5-a9c03ac5f395"} {"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-08-05T19:06:58.27031839Z","hostname":"w-01J4HYXJ15GWTB3A0BGQ511MRA","pid":1195,"":"downstairs","":"downstairs","session_id":"fa4ca208-59ca-43a9-82f5-a9c03ac5f395"} {"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-08-05T19:06:58.270323219Z","hostname":"w-01J4HYXJ15GWTB3A0BGQ511MRA","pid":1195,"":"downstairs","":"downstairs","session_id":"fa4ca208-59ca-43a9-82f5-a9c03ac5f395"} {"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-08-05T19:06:58.270327368Z","hostname":"w-01J4HYXJ15GWTB3A0BGQ511MRA","pid":1195,"":"downstairs","":"downstairs","session_id":"fa4ca208-59ca-43a9-82f5-a9c03ac5f395"} {"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-08-05T19:06:58.270331898Z","hostname":"w-01J4HYXJ15GWTB3A0BGQ511MRA","pid":1195,"":"downstairs","":"downstairs","session_id":"fa4ca208-59ca-43a9-82f5-a9c03ac5f395"} {"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-08-05T19:06:58.270336287Z","hostname":"w-01J4HYXJ15GWTB3A0BGQ511MRA","pid":1195,"":"downstairs","":"downstairs","session_id":"fa4ca208-59ca-43a9-82f5-a9c03ac5f395"} {"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-08-05T19:06:58.270340226Z","hostname":"w-01J4HYXJ15GWTB3A0BGQ511MRA","pid":1195,"":"downstairs","":"downstairs","session_id":"fa4ca208-59ca-43a9-82f5-a9c03ac5f395"} {"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-08-05T19:06:58.270344676Z","hostname":"w-01J4HYXJ15GWTB3A0BGQ511MRA","pid":1195,"":"downstairs","":"downstairs","session_id":"fa4ca208-59ca-43a9-82f5-a9c03ac5f395"} {"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-08-05T19:06:58.270348805Z","hostname":"w-01J4HYXJ15GWTB3A0BGQ511MRA","pid":1195,"":"downstairs","":"downstairs","session_id":"fa4ca208-59ca-43a9-82f5-a9c03ac5f395"} {"msg":"Max found gen is 1","v":0,"name":"crucible","level":30,"time":"2024-08-05T19:06:58.270352884Z","hostname":"w-01J4HYXJ15GWTB3A0BGQ511MRA","pid":1195,"":"downstairs","":"downstairs","session_id":"fa4ca208-59ca-43a9-82f5-a9c03ac5f395"} {"msg":"Generation requested: 1 >= found:1","v":0,"name":"crucible","level":30,"time":"2024-08-05T19:06:58.270356934Z","hostname":"w-01J4HYXJ15GWTB3A0BGQ511MRA","pid":1195,"":"downstairs","":"downstairs","session_id":"fa4ca208-59ca-43a9-82f5-a9c03ac5f395"} {"msg":"Next flush: 1","v":0,"name":"crucible","level":30,"time":"2024-08-05T19:06:58.270361493Z","hostname":"w-01J4HYXJ15GWTB3A0BGQ511MRA","pid":1195,"":"downstairs","":"downstairs","session_id":"fa4ca208-59ca-43a9-82f5-a9c03ac5f395"} {"msg":"All extents match","v":0,"name":"crucible","level":30,"time":"2024-08-05T19:06:58.270365442Z","hostname":"w-01J4HYXJ15GWTB3A0BGQ511MRA","pid":1195,"":"downstairs","":"downstairs","session_id":"fa4ca208-59ca-43a9-82f5-a9c03ac5f395"} {"msg":"No downstairs reconciliation required","v":0,"name":"crucible","level":30,"time":"2024-08-05T19:06:58.270369422Z","hostname":"w-01J4HYXJ15GWTB3A0BGQ511MRA","pid":1195,"session_id":"fa4ca208-59ca-43a9-82f5-a9c03ac5f395"} {"msg":"Transition from WaitQuorum to Active","v":0,"name":"crucible","level":30,"time":"2024-08-05T19:06:58.270372981Z","hostname":"w-01J4HYXJ15GWTB3A0BGQ511MRA","pid":1195,"client":"0","":"downstairs","session_id":"fa4ca208-59ca-43a9-82f5-a9c03ac5f395"} {"msg":"Transition from WaitQuorum to Active","v":0,"name":"crucible","level":30,"time":"2024-08-05T19:06:58.270377451Z","hostname":"w-01J4HYXJ15GWTB3A0BGQ511MRA","pid":1195,"client":"1","":"downstairs","session_id":"fa4ca208-59ca-43a9-82f5-a9c03ac5f395"} {"msg":"Transition from WaitQuorum to Active","v":0,"name":"crucible","level":30,"time":"2024-08-05T19:06:58.27038149Z","hostname":"w-01J4HYXJ15GWTB3A0BGQ511MRA","pid":1195,"client":"2","":"downstairs","session_id":"fa4ca208-59ca-43a9-82f5-a9c03ac5f395"} {"msg":"All required reconciliation work is completed","v":0,"name":"crucible","level":30,"time":"2024-08-05T19:06:58.270385939Z","hostname":"w-01J4HYXJ15GWTB3A0BGQ511MRA","pid":1195,"session_id":"fa4ca208-59ca-43a9-82f5-a9c03ac5f395"} {"msg":"Set Downstairs and Upstairs active after reconciliation","v":0,"name":"crucible","level":30,"time":"2024-08-05T19:06:58.270389479Z","hostname":"w-01J4HYXJ15GWTB3A0BGQ511MRA","pid":1195,"session_id":"fa4ca208-59ca-43a9-82f5-a9c03ac5f395"} {"msg":"51ff50e9-67c0-4f7c-b5cc-3cabaf94e1ae is now active with session: fa4ca208-59ca-43a9-82f5-a9c03ac5f395",Wait for a query_work_queue command to finish before sending IO "v":0,"name":"crucible","level":30,"time":"2024-08-05T19:06:58.270402267Z","hostname":"w-01J4HYXJ15GWTB3A0BGQ511MRA","pid":1195,"session_id":"fa4ca208-59ca-43a9-82f5-a9c03ac5f395"} {"msg":"Set Active after no reconciliation","v":0,"name":"crucible","level":30,"time":"2024-08-05T19:06:58.270406596Z","hostname":"w-01J4HYXJ15GWTB3A0BGQ511MRA","pid":1195,"session_id":"fa4ca208-59ca-43a9-82f5-a9c03ac5f395"} {"msg":"The guest has finished waiting for activation with:1","v":0,"name":"crucible","level":30,"time":"2024-08-05T19:06:58.270410295Z","hostname":"w-01J4HYXJ15GWTB3A0BGQ511MRA","pid":1195} 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 5.96 30000 1 5032.57 0.00020 0.00062 0.00122 0.04485 16384 640 rwrites 5.73 30000 1 5233.58 0.00019 0.00055 0.00128 0.03544 16384 640 rreads 5.65 30000 1 5306.35 0.00019 0.00024 0.00030 0.01266 16384 640 rreads 5.58 30000 1 5372.95 0.00019 0.00024 0.00029 0.01303 16384 640 A new loop begins at August 5, 2024 at 07:07: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-1280.csv {"msg":"Upstairs starts","v":0,"name":"crucible","level":30,"time":"2024-08-05T19:07:36.203824108Z","hostname":"w-01J4HYXJ15GWTB3A0BGQ511MRA","pid":1214} {"msg":"Crucible Version: BuildInfo {\n version: \"0.0.1\",\n git_sha: \"955d5f2fb08fa12300fcdaa7dafdc9edb7db9942\",\n git_commit_timestamp: \"2024-08-01T19:59:22.000000000Z\",\n git_branch: \"fioffs-redux\",\n rustc_semver: \"1.76.0\",\n rustc_channel: \"stable\",\n rustc_host_triple: \"x86_64-unknown-illumos\",\n rustc_commit_sha: \"07dca489ac2d933c78d3c5158e3f43beefeb02ce\",\n cargo_triple: \"x86_64-unknown-illumos\",\n debug: false,\n opt_level: 3,\n}","v":0,"name":"crucible","level":30,"time":"2024-08-05T19:07:36.203969085Z","hostname":"w-01J4HYXJ15GWTB3A0BGQ511MRA","pid":1214} {"msg":"Upstairs <-> Downstairs Message Version: 11","v":0,"name":"crucible","level":30,"time":"2024-08-05T19:07:36.203975704Z","hostname":"w-01J4HYXJ15GWTB3A0BGQ511MRA","pid":1214} {"msg":"Crucible 1dec929f-9aa9-4bff-8ed2-9b6227b68c62 has session id: a212636b-66dd-44bc-8595-2836ecba2d02","v":0,"name":"crucible","level":30,"time":"2024-08-05T19:07:36.204324109Z","hostname":"w-01J4HYXJ15GWTB3A0BGQ511MRA","pid":1214,"session_id":"a212636b-66dd-44bc-8595-2836ecba2d02"} {"msg":"Upstairs opts: Upstairs UUID: 1dec929f-9aa9-4bff-8ed2-9b6227b68c62, 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-08-05T19:07:36.204348935Z","hostname":"w-01J4HYXJ15GWTB3A0BGQ511MRA","pid":1214,"session_id":"a212636b-66dd-44bc-8595-2836ecba2d02"} {"msg":"Crucible stats registered with UUID: 1dec929f-9aa9-4bff-8ed2-9b6227b68c62","v":0,"name":"crucible","level":30,"time":"2024-08-05T19:07:36.204354184Z","hostname":"w-01J4HYXJ15GWTB3A0BGQ511MRA","pid":1214,"session_id":"a212636b-66dd-44bc-8595-2836ecba2d02"} Crucible runtime is spawned {"msg":"The guest has requested activation with gen:1","v":0,"name":"crucible","level":30,"time":"2024-08-05T19:07:36.240503863Z","hostname":"w-01J4HYXJ15GWTB3A0BGQ511MRA","pid":1214} {"msg":"1dec929f-9aa9-4bff-8ed2-9b6227b68c62 active request set","v":0,"name":"crucible","level":30,"time":"2024-08-05T19:07:36.240529279Z","hostname":"w-01J4HYXJ15GWTB3A0BGQ511MRA","pid":1214,"session_id":"a212636b-66dd-44bc-8595-2836ecba2d02"} {"msg":"sending connect oneshot to client","v":0,"name":"crucible","level":30,"time":"2024-08-05T19:07:36.240538148Z","hostname":"w-01J4HYXJ15GWTB3A0BGQ511MRA","pid":1214,"client":"0","":"downstairs","session_id":"a212636b-66dd-44bc-8595-2836ecba2d02"} {"msg":"client set_active_request while in New; waiting...","v":0,"name":"crucible","level":30,"time":"2024-08-05T19:07:36.240566813Z","hostname":"w-01J4HYXJ15GWTB3A0BGQ511MRA","pid":1214,"client":"0","":"downstairs","session_id":"a212636b-66dd-44bc-8595-2836ecba2d02"} {"msg":"sending connect oneshot to client","v":0,"name":"crucible","level":30,"time":"2024-08-05T19:07:36.240576812Z","hostname":"w-01J4HYXJ15GWTB3A0BGQ511MRA","pid":1214,"client":"1","":"downstairs","session_id":"a212636b-66dd-44bc-8595-2836ecba2d02"} {"msg":"client set_active_request while in New; waiting...","v":0,"name":"crucible","level":30,"time":"2024-08-05T19:07:36.24058755Z","hostname":"w-01J4HYXJ15GWTB3A0BGQ511MRA","pid":1214,"client":"1","":"downstairs","session_id":"a212636b-66dd-44bc-8595-2836ecba2d02"} {"msg":"sending connect oneshot to client","v":0,"name":"crucible","level":30,"time":"2024-08-05T19:07:36.240599268Z","hostname":"w-01J4HYXJ15GWTB3A0BGQ511MRA","pid":1214,"client":"2","":"downstairs","session_id":"a212636b-66dd-44bc-8595-2836ecba2d02"} {"msg":"client set_active_request while in New; waiting...","v":0,"name":"crucible","level":30,"time":"2024-08-05T19:07:36.240608746Z","hostname":"w-01J4HYXJ15GWTB3A0BGQ511MRA","pid":1214,"client":"2","":"downstairs","session_id":"a212636b-66dd-44bc-8595-2836ecba2d02"} {"msg":"connecting to 127.0.0.1:8830","v":0,"name":"crucible","level":30,"time":"2024-08-05T19:07:36.240618195Z","hostname":"w-01J4HYXJ15GWTB3A0BGQ511MRA","pid":1214,"":"io task","client":"2","":"downstairs","session_id":"a212636b-66dd-44bc-8595-2836ecba2d02"} {"msg":"connecting to 127.0.0.1:8810","v":0,"name":"crucible","level":30,"time":"2024-08-05T19:07:36.240628534Z","hostname":"w-01J4HYXJ15GWTB3A0BGQ511MRA","pid":1214,"":"io task","client":"0","":"downstairs","session_id":"a212636b-66dd-44bc-8595-2836ecba2d02"} {"msg":"connecting to 127.0.0.1:8820","v":0,"name":"crucible","level":30,"time":"2024-08-05T19:07:36.240638032Z","hostname":"w-01J4HYXJ15GWTB3A0BGQ511MRA","pid":1214,"":"io task","client":"1","":"downstairs","session_id":"a212636b-66dd-44bc-8595-2836ecba2d02"} {"msg":"ds_connection connected from Ok(127.0.0.1:47133)","v":0,"name":"crucible","level":30,"time":"2024-08-05T19:07:36.240722309Z","hostname":"w-01J4HYXJ15GWTB3A0BGQ511MRA","pid":1214,"":"io task","client":"2","":"downstairs","session_id":"a212636b-66dd-44bc-8595-2836ecba2d02"} {"msg":"ds_connection connected from Ok(127.0.0.1:33773)","v":0,"name":"crucible","level":30,"time":"2024-08-05T19:07:36.240745695Z","hostname":"w-01J4HYXJ15GWTB3A0BGQ511MRA","pid":1214,"":"io task","client":"1","":"downstairs","session_id":"a212636b-66dd-44bc-8595-2836ecba2d02"} {"msg":"ds_connection connected from Ok(127.0.0.1:35356)","v":0,"name":"crucible","level":30,"time":"2024-08-05T19:07:36.240754114Z","hostname":"w-01J4HYXJ15GWTB3A0BGQ511MRA","pid":1214,"":"io task","client":"0","":"downstairs","session_id":"a212636b-66dd-44bc-8595-2836ecba2d02"} {"msg":"ds_transition from New to WaitActive","v":0,"name":"crucible","level":30,"time":"2024-08-05T19:07:36.241151751Z","hostname":"w-01J4HYXJ15GWTB3A0BGQ511MRA","pid":1214,"client":"1","":"downstairs","session_id":"a212636b-66dd-44bc-8595-2836ecba2d02"} {"msg":"[1] Transition from New to WaitActive","v":0,"name":"crucible","level":30,"time":"2024-08-05T19:07:36.241169568Z","hostname":"w-01J4HYXJ15GWTB3A0BGQ511MRA","pid":1214,"client":"1","":"downstairs","session_id":"a212636b-66dd-44bc-8595-2836ecba2d02"} {"msg":"ds_transition from New to WaitActive","v":0,"name":"crucible","level":30,"time":"2024-08-05T19:07:36.241174697Z","hostname":"w-01J4HYXJ15GWTB3A0BGQ511MRA","pid":1214,"client":"2","":"downstairs","session_id":"a212636b-66dd-44bc-8595-2836ecba2d02"} {"msg":"[2] Transition from New to WaitActive","v":0,"name":"crucible","level":30,"time":"2024-08-05T19:07:36.241179426Z","hostname":"w-01J4HYXJ15GWTB3A0BGQ511MRA","pid":1214,"client":"2","":"downstairs","session_id":"a212636b-66dd-44bc-8595-2836ecba2d02"} {"msg":"ds_transition from New to WaitActive","v":0,"name":"crucible","level":30,"time":"2024-08-05T19:07:36.241285019Z","hostname":"w-01J4HYXJ15GWTB3A0BGQ511MRA","pid":1214,"client":"0","":"downstairs","session_id":"a212636b-66dd-44bc-8595-2836ecba2d02"} {"msg":"[0] Transition from New to WaitActive","v":0,"name":"crucible","level":30,"time":"2024-08-05T19:07:36.241301737Z","hostname":"w-01J4HYXJ15GWTB3A0BGQ511MRA","pid":1214,"client":"0","":"downstairs","session_id":"a212636b-66dd-44bc-8595-2836ecba2d02"} {"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-08-05T19:07:36.241397972Z","hostname":"w-01J4HYXJ15GWTB3A0BGQ511MRA","pid":1214,"client":"1","":"downstairs","session_id":"a212636b-66dd-44bc-8595-2836ecba2d02"} {"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-08-05T19:07:36.241551837Z","hostname":"w-01J4HYXJ15GWTB3A0BGQ511MRA","pid":1214,"client":"0","":"downstairs","session_id":"a212636b-66dd-44bc-8595-2836ecba2d02"} {"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-08-05T19:07:36.241575114Z","hostname":"w-01J4HYXJ15GWTB3A0BGQ511MRA","pid":1214,"client":"2","":"downstairs","session_id":"a212636b-66dd-44bc-8595-2836ecba2d02"} {"msg":"ds_transition from WaitActive to WaitQuorum","v":0,"name":"crucible","level":30,"time":"2024-08-05T19:07:36.247041708Z","hostname":"w-01J4HYXJ15GWTB3A0BGQ511MRA","pid":1214,"client":"0","":"downstairs","session_id":"a212636b-66dd-44bc-8595-2836ecba2d02"} {"msg":"[0] Transition from WaitActive to WaitQuorum","v":0,"name":"crucible","level":30,"time":"2024-08-05T19:07:36.247062825Z","hostname":"w-01J4HYXJ15GWTB3A0BGQ511MRA","pid":1214,"client":"0","":"downstairs","session_id":"a212636b-66dd-44bc-8595-2836ecba2d02"} {"msg":"Waiting for more clients to be ready","v":0,"name":"crucible","level":30,"time":"2024-08-05T19:07:36.247068474Z","hostname":"w-01J4HYXJ15GWTB3A0BGQ511MRA","pid":1214,"session_id":"a212636b-66dd-44bc-8595-2836ecba2d02"} {"msg":"ds_transition from WaitActive to WaitQuorum","v":0,"name":"crucible","level":30,"time":"2024-08-05T19:07:36.247072284Z","hostname":"w-01J4HYXJ15GWTB3A0BGQ511MRA","pid":1214,"client":"1","":"downstairs","session_id":"a212636b-66dd-44bc-8595-2836ecba2d02"} {"msg":"[1] Transition from WaitActive to WaitQuorum","v":0,"name":"crucible","level":30,"time":"2024-08-05T19:07:36.247076463Z","hostname":"w-01J4HYXJ15GWTB3A0BGQ511MRA","pid":1214,"client":"1","":"downstairs","session_id":"a212636b-66dd-44bc-8595-2836ecba2d02"} {"msg":"Waiting for more clients to be ready","v":0,"name":"crucible","level":30,"time":"2024-08-05T19:07:36.247080742Z","hostname":"w-01J4HYXJ15GWTB3A0BGQ511MRA","pid":1214,"session_id":"a212636b-66dd-44bc-8595-2836ecba2d02"} {"msg":"ds_transition from WaitActive to WaitQuorum","v":0,"name":"crucible","level":30,"time":"2024-08-05T19:07:36.247085362Z","hostname":"w-01J4HYXJ15GWTB3A0BGQ511MRA","pid":1214,"client":"2","":"downstairs","session_id":"a212636b-66dd-44bc-8595-2836ecba2d02"} {"msg":"[2] Transition from WaitActive to WaitQuorum","v":0,"name":"crucible","level":30,"time":"2024-08-05T19:07:36.247089491Z","hostname":"w-01J4HYXJ15GWTB3A0BGQ511MRA","pid":1214,"client":"2","":"downstairs","session_id":"a212636b-66dd-44bc-8595-2836ecba2d02"} {"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-08-05T19:07:36.2470941Z","hostname":"w-01J4HYXJ15GWTB3A0BGQ511MRA","pid":1214,"":"downstairs","":"downstairs","session_id":"a212636b-66dd-44bc-8595-2836ecba2d02"} {"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-08-05T19:07:36.247099319Z","hostname":"w-01J4HYXJ15GWTB3A0BGQ511MRA","pid":1214,"":"downstairs","":"downstairs","session_id":"a212636b-66dd-44bc-8595-2836ecba2d02"} {"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-08-05T19:07:36.247103939Z","hostname":"w-01J4HYXJ15GWTB3A0BGQ511MRA","pid":1214,"":"downstairs","":"downstairs","session_id":"a212636b-66dd-44bc-8595-2836ecba2d02"} {"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-08-05T19:07:36.247108178Z","hostname":"w-01J4HYXJ15GWTB3A0BGQ511MRA","pid":1214,"":"downstairs","":"downstairs","session_id":"a212636b-66dd-44bc-8595-2836ecba2d02"} {"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-08-05T19:07:36.247112917Z","hostname":"w-01J4HYXJ15GWTB3A0BGQ511MRA","pid":1214,"":"downstairs","":"downstairs","session_id":"a212636b-66dd-44bc-8595-2836ecba2d02"} {"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-08-05T19:07:36.247117047Z","hostname":"w-01J4HYXJ15GWTB3A0BGQ511MRA","pid":1214,"":"downstairs","":"downstairs","session_id":"a212636b-66dd-44bc-8595-2836ecba2d02"} {"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-08-05T19:07:36.247121226Z","hostname":"w-01J4HYXJ15GWTB3A0BGQ511MRA","pid":1214,"":"downstairs","":"downstairs","session_id":"a212636b-66dd-44bc-8595-2836ecba2d02"} {"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-08-05T19:07:36.247125585Z","hostname":"w-01J4HYXJ15GWTB3A0BGQ511MRA","pid":1214,"":"downstairs","":"downstairs","session_id":"a212636b-66dd-44bc-8595-2836ecba2d02"} {"msg":"[2]R dirty[0..12]: [false, false, false, false, false, false, false, false, false, false, false, false]","v":0,"name":"crucible","levelWait for a query_work_queue command to finish before sending IO ":30,"time":"2024-08-05T19:07:36.247132934Z","hostname":"w-01J4HYXJ15GWTB3A0BGQ511MRA","pid":1214,"":"downstairs","":"downstairs","session_id":"a212636b-66dd-44bc-8595-2836ecba2d02"} {"msg":"Max found gen is 1","v":0,"name":"crucible","level":30,"time":"2024-08-05T19:07:36.247138513Z","hostname":"w-01J4HYXJ15GWTB3A0BGQ511MRA","pid":1214,"":"downstairs","":"downstairs","session_id":"a212636b-66dd-44bc-8595-2836ecba2d02"} {"msg":"Generation requested: 1 >= found:1","v":0,"name":"crucible","level":30,"time":"2024-08-05T19:07:36.247142852Z","hostname":"w-01J4HYXJ15GWTB3A0BGQ511MRA","pid":1214,"":"downstairs","":"downstairs","session_id":"a212636b-66dd-44bc-8595-2836ecba2d02"} {"msg":"Next flush: 1","v":0,"name":"crucible","level":30,"time":"2024-08-05T19:07:36.247147002Z","hostname":"w-01J4HYXJ15GWTB3A0BGQ511MRA","pid":1214,"":"downstairs","":"downstairs","session_id":"a212636b-66dd-44bc-8595-2836ecba2d02"} {"msg":"All extents match","v":0,"name":"crucible","level":30,"time":"2024-08-05T19:07:36.247151141Z","hostname":"w-01J4HYXJ15GWTB3A0BGQ511MRA","pid":1214,"":"downstairs","":"downstairs","session_id":"a212636b-66dd-44bc-8595-2836ecba2d02"} {"msg":"No downstairs reconciliation required","v":0,"name":"crucible","level":30,"time":"2024-08-05T19:07:36.247155301Z","hostname":"w-01J4HYXJ15GWTB3A0BGQ511MRA","pid":1214,"session_id":"a212636b-66dd-44bc-8595-2836ecba2d02"} {"msg":"Transition from WaitQuorum to Active","v":0,"name":"crucible","level":30,"time":"2024-08-05T19:07:36.24715883Z","hostname":"w-01J4HYXJ15GWTB3A0BGQ511MRA","pid":1214,"client":"0","":"downstairs","session_id":"a212636b-66dd-44bc-8595-2836ecba2d02"} {"msg":"Transition from WaitQuorum to Active","v":0,"name":"crucible","level":30,"time":"2024-08-05T19:07:36.247172728Z","hostname":"w-01J4HYXJ15GWTB3A0BGQ511MRA","pid":1214,"client":"1","":"downstairs","session_id":"a212636b-66dd-44bc-8595-2836ecba2d02"} {"msg":"Transition from WaitQuorum to Active","v":0,"name":"crucible","level":30,"time":"2024-08-05T19:07:36.247180027Z","hostname":"w-01J4HYXJ15GWTB3A0BGQ511MRA","pid":1214,"client":"2","":"downstairs","session_id":"a212636b-66dd-44bc-8595-2836ecba2d02"} {"msg":"All required reconciliation work is completed","v":0,"name":"crucible","level":30,"time":"2024-08-05T19:07:36.247184866Z","hostname":"w-01J4HYXJ15GWTB3A0BGQ511MRA","pid":1214,"session_id":"a212636b-66dd-44bc-8595-2836ecba2d02"} {"msg":"Set Downstairs and Upstairs active after reconciliation","v":0,"name":"crucible","level":30,"time":"2024-08-05T19:07:36.247189175Z","hostname":"w-01J4HYXJ15GWTB3A0BGQ511MRA","pid":1214,"session_id":"a212636b-66dd-44bc-8595-2836ecba2d02"} {"msg":"1dec929f-9aa9-4bff-8ed2-9b6227b68c62 is now active with session: a212636b-66dd-44bc-8595-2836ecba2d02","v":0,"name":"crucible","level":30,"time":"2024-08-05T19:07:36.247192845Z","hostname":"w-01J4HYXJ15GWTB3A0BGQ511MRA","pid":1214,"session_id":"a212636b-66dd-44bc-8595-2836ecba2d02"} {"msg":"Set Active after no reconciliation","v":0,"name":"crucible","level":30,"time":"2024-08-05T19:07:36.247196494Z","hostname":"w-01J4HYXJ15GWTB3A0BGQ511MRA","pid":1214,"session_id":"a212636b-66dd-44bc-8595-2836ecba2d02"} {"msg":"The guest has finished waiting for activation with:1","v":0,"name":"crucible","level":30,"time":"2024-08-05T19:07:36.247200603Z","hostname":"w-01J4HYXJ15GWTB3A0BGQ511MRA","pid":1214} 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 6.93 30000 1 4326.54 0.00023 0.00094 0.00134 0.06735 16384 1280 rwrites 6.81 30000 1 4403.86 0.00023 0.00081 0.00130 0.06911 16384 1280 rreads 5.55 30000 1 5406.88 0.00018 0.00023 0.00028 0.01305 16384 1280 rreads 5.55 30000 1 5407.17 0.00018 0.00023 0.00027 0.01305 16384 1280 Perf test finished on August 5, 2024 at 07:08:04 PM UTC