Perf test begins at February 13, 2024 at 09:39:44 PM UTC A new loop begins at February 13, 2024 at 09:39:52 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-13T21:39:52.832517929Z","hostname":"ip-10-150-1-93.us-west-2.compute.internal","pid":1160} {"msg":"Crucible Version: BuildInfo {\n version: \"0.0.1\",\n git_sha: \"29185f5538632a13039785e911d1aaa0146bfa14\",\n git_commit_timestamp: \"2024-02-13T21:13:12.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-13T21:39:52.832672306Z","hostname":"ip-10-150-1-93.us-west-2.compute.internal","pid":1160} {"msg":"Upstairs <-> Downstairs Message Version: 5","v":0,"name":"crucible","level":30,"time":"2024-02-13T21:39:52.832679585Z","hostname":"ip-10-150-1-93.us-west-2.compute.internal","pid":1160} {"msg":"Crucible b7476a9a-854d-4925-8597-fe5d6db6341f has session id: 7be89de4-2429-4893-937f-e44e21235a1b","v":0,"name":"crucible","level":30,"time":"2024-02-13T21:39:52.832685115Z","hostname":"ip-10-150-1-93.us-west-2.compute.internal","pid":1160,"session_id":"7be89de4-2429-4893-937f-e44e21235a1b"} {"msg":"Upstairs opts: Upstairs UUID: b7476a9a-854d-4925-8597-fe5d6db6341f, 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-13T21:39:52.832712761Z","hostname":"ip-10-150-1-93.us-west-2.compute.internal","pid":1160,"session_id":"7be89de4-2429-4893-937f-e44e21235a1b"} {"msg":"Crucible stats registered with UUID: b7476a9a-854d-4925-8597-fe5d6db6341f","v":0,"name":"crucible","level":30,"time":"2024-02-13T21:39:52.83271881Z","hostname":"ip-10-150-1-93.us-west-2.compute.internal","pid":1160,"session_id":"7be89de4-2429-4893-937f-e44e21235a1b"} Crucible runtime is spawned {"msg":"The guest has requested activation with gen:1","v":0,"name":"crucible","level":30,"time":"2024-02-13T21:39:52.83292184Z","hostname":"ip-10-150-1-93.us-west-2.compute.internal","pid":1160} {"msg":"b7476a9a-854d-4925-8597-fe5d6db6341f active request set","v":0,"name":"crucible","level":30,"time":"2024-02-13T21:39:52.833072678Z","hostname":"ip-10-150-1-93.us-west-2.compute.internal","pid":1160,"session_id":"7be89de4-2429-4893-937f-e44e21235a1b"} {"msg":"sending connect oneshot to client","v":0,"name":"crucible","level":30,"time":"2024-02-13T21:39:52.833090246Z","hostname":"ip-10-150-1-93.us-west-2.compute.internal","pid":1160,"client":"0","":"downstairs","session_id":"7be89de4-2429-4893-937f-e44e21235a1b"} {"msg":"client set_active_request while in New; waiting...","v":0,"name":"crucible","level":30,"time":"2024-02-13T21:39:52.833096845Z","hostname":"ip-10-150-1-93.us-west-2.compute.internal","pid":1160,"client":"0","":"downstairs","session_id":"7be89de4-2429-4893-937f-e44e21235a1b"} {"msg":"sending connect oneshot to client","v":0,"name":"crucible","level":30,"time":"2024-02-13T21:39:52.833102834Z","hostname":"ip-10-150-1-93.us-west-2.compute.internal","pid":1160,"client":"1","":"downstairs","session_id":"7be89de4-2429-4893-937f-e44e21235a1b"} {"msg":"client set_active_request while in New; waiting...","v":0,"name":"crucible","level":30,"time":"2024-02-13T21:39:52.833107553Z","hostname":"ip-10-150-1-93.us-west-2.compute.internal","pid":1160,"client":"1","":"downstairs","session_id":"7be89de4-2429-4893-937f-e44e21235a1b"} {"msg":"sending connect oneshot to client","v":0,"name":"crucible","level":30,"time":"2024-02-13T21:39:52.833112633Z","hostname":"ip-10-150-1-93.us-west-2.compute.internal","pid":1160,"client":"2","":"downstairs","session_id":"7be89de4-2429-4893-937f-e44e21235a1b"} {"msg":"client set_active_request while in New; waiting...","v":0,"name":"crucible","level":30,"time":"2024-02-13T21:39:52.833116962Z","hostname":"ip-10-150-1-93.us-west-2.compute.internal","pid":1160,"client":"2","":"downstairs","session_id":"7be89de4-2429-4893-937f-e44e21235a1b"} {"msg":"connecting to 127.0.0.1:8830","v":0,"name":"crucible","level":30,"time":"2024-02-13T21:39:52.833121871Z","hostname":"ip-10-150-1-93.us-west-2.compute.internal","pid":1160,"":"io task","client":"2","":"downstairs","session_id":"7be89de4-2429-4893-937f-e44e21235a1b"} {"msg":"connecting to 127.0.0.1:8810","v":0,"name":"crucible","level":30,"time":"2024-02-13T21:39:52.8331271Z","hostname":"ip-10-150-1-93.us-west-2.compute.internal","pid":1160,"":"io task","client":"0","":"downstairs","session_id":"7be89de4-2429-4893-937f-e44e21235a1b"} {"msg":"connecting to 127.0.0.1:8820","v":0,"name":"crucible","level":30,"time":"2024-02-13T21:39:52.83313276Z","hostname":"ip-10-150-1-93.us-west-2.compute.internal","pid":1160,"":"io task","client":"1","":"downstairs","session_id":"7be89de4-2429-4893-937f-e44e21235a1b"} {"msg":"ds_connection connected","v":0,"name":"crucible","level":30,"time":"2024-02-13T21:39:52.833242514Z","hostname":"ip-10-150-1-93.us-west-2.compute.internal","pid":1160,"":"io task","client":"2","":"downstairs","session_id":"7be89de4-2429-4893-937f-e44e21235a1b"} {"msg":"ds_connection connected","v":0,"name":"crucible","level":30,"time":"2024-02-13T21:39:52.833263101Z","hostname":"ip-10-150-1-93.us-west-2.compute.internal","pid":1160,"":"io task","client":"1","":"downstairs","session_id":"7be89de4-2429-4893-937f-e44e21235a1b"} {"msg":"ds_connection connected","v":0,"name":"crucible","level":30,"time":"2024-02-13T21:39:52.83327157Z","hostname":"ip-10-150-1-93.us-west-2.compute.internal","pid":1160,"":"io task","client":"0","":"downstairs","session_id":"7be89de4-2429-4893-937f-e44e21235a1b"} {"msg":"ds_transition from New to WaitActive","v":0,"name":"crucible","level":30,"time":"2024-02-13T21:39:52.833791754Z","hostname":"ip-10-150-1-93.us-west-2.compute.internal","pid":1160,"client":"1","":"downstairs","session_id":"7be89de4-2429-4893-937f-e44e21235a1b"} {"msg":"[1] Transition from New to WaitActive","v":0,"name":"crucible","level":30,"time":"2024-02-13T21:39:52.833807732Z","hostname":"ip-10-150-1-93.us-west-2.compute.internal","pid":1160,"client":"1","":"downstairs","session_id":"7be89de4-2429-4893-937f-e44e21235a1b"} {"msg":"ds_transition from New to WaitActive","v":0,"name":"crucible","level":30,"time":"2024-02-13T21:39:52.833813881Z","hostname":"ip-10-150-1-93.us-west-2.compute.internal","pid":1160,"client":"2","":"downstairs","session_id":"7be89de4-2429-4893-937f-e44e21235a1b"} {"msg":"[2] Transition from New to WaitActive","v":0,"name":"crucible","level":30,"time":"2024-02-13T21:39:52.8338184Z","hostname":"ip-10-150-1-93.us-west-2.compute.internal","pid":1160,"client":"2","":"downstairs","session_id":"7be89de4-2429-4893-937f-e44e21235a1b"} {"msg":"ds_transition from New to WaitActive","v":0,"name":"crucible","level":30,"time":"2024-02-13T21:39:52.833823939Z","hostname":"ip-10-150-1-93.us-west-2.compute.internal","pid":1160,"client":"0","":"downstairs","session_id":"7be89de4-2429-4893-937f-e44e21235a1b"} {"msg":"[0] Transition from New to WaitActive","v":0,"name":"crucible","level":30,"time":"2024-02-13T21:39:52.833831158Z","hostname":"ip-10-150-1-93.us-west-2.compute.internal","pid":1160,"client":"0","":"downstairs","session_id":"7be89de4-2429-4893-937f-e44e21235a1b"} {"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-13T21:39:52.834045537Z","hostname":"ip-10-150-1-93.us-west-2.compute.internal","pid":1160,"client":"1","":"downstairs","session_id":"7be89de4-2429-4893-937f-e44e21235a1b"} {"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-13T21:39:52.834056735Z","hostname":"ip-10-150-1-93.us-west-2.compute.internal","pid":1160,"client":"2","":"downstairs","session_id":"7be89de4-2429-4893-937f-e44e21235a1b"} {"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-13T21:39:52.834062035Z","hostname":"ip-10-150-1-93.us-west-2.compute.internal","pid":1160,"client":"0","":"downstairs","session_id":"7be89de4-2429-4893-937f-e44e21235a1b"} {"msg":"ds_transition from WaitActive to WaitQuorum","v":0,"name":"crucible","level":30,"time":"2024-02-13T21:39:52.836350342Z","hostname":"ip-10-150-1-93.us-west-2.compute.internal","pid":1160,"client":"1","":"downstairs","session_id":"7be89de4-2429-4893-937f-e44e21235a1b"} {"msg":"[1] Transition from WaitActive to WaitQuorum","v":0,"name":"crucible","level":30,"time":"2024-02-13T21:39:52.836370829Z","hostname":"ip-10-150-1-93.us-west-2.compute.internal","pid":1160,"client":"1","":"downstairs","session_id":"7be89de4-2429-4893-937f-e44e21235a1b"} {"msg":"Waiting for true more clients to be ready","v":0,"name":"crucible","level":30,"time":"2024-02-13T21:39:52.836377078Z","hostname":"ip-10-150-1-93.us-west-2.compute.internal","pid":1160,"session_id":"7be89de4-2429-4893-937f-e44e21235a1b"} {"msg":"ds_transition from WaitActive to WaitQuorum","v":0,"name":"crucible","level":30,"time":"2024-02-13T21:39:52.837176532Z","hostname":"ip-10-150-1-93.us-west-2.compute.internal","pid":1160,"client":"0","":"downstairs","session_id":"7be89de4-2429-4893-937f-e44e21235a1b"} {"msg":"[0] Transition from WaitActive to WaitQuorum","v":0,"name":"crucible","level":30,"time":"2024-02-13T21:39:52.837199299Z","hostname":"ip-10-150-1-93.us-west-2.compute.internal","pid":1160,"client":"0","":"downstairs","session_id":"7be89de4-2429-4893-937f-e44e21235a1b"} {"msg":"Waiting for true more clients to be ready","v":0,"name":"crucible","level":30,"time":"2024-02-13T21:39:52.837208307Z","hostname":"ip-10-150-1-93.us-west-2.compute.internal","pid":1160,"session_id":"7be89de4-2429-4893-937f-e44e21235a1b"} {"msg":"ds_transition from WaitActive to WaitQuorum","v":0,"name":"crucible","level":30,"time":"2024-02-13T21:39:52.837216156Z","hostname":"ip-10-150-1-93.us-west-2.compute.internal","pid":1160,"client":"2","":"downstairs","session_id":"7be89de4-2429-4893-937f-e44e21235a1b"} {"msg":"[2] Transition from WaitActive to WaitQuorum","v":0,"name":"crucible","level":30,"time":"2024-02-13T21:39:52.837224455Z","hostname":"ip-10-150-1-93.us-west-2.compute.internal","pid":1160,"client":"2","":"downstairs","session_id":"7be89de4-2429-4893-937f-e44e21235a1b"} {"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-13T21:39:52.837247941Z","hostname":"ip-10-150-1-93.us-west-2.compute.internal","pid":1160,"":"downstairs","":"downstairs","session_id":"7be89de4-2429-4893-937f-e44e21235a1b"} {"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-13T21:39:52.837266279Z","hostname":"ip-10-150-1-93.us-west-2.compute.internal","pid":1160,"":"downstairs","":"downstairs","session_id":"7be89de4-2429-4893-937f-e44e21235a1b"} {"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-13T21:39:52.837273948Z","hostname":"ip-10-150-1-93.us-west-2.compute.internal","pid":1160,"":"downstairs","":"downstairs","session_id":"7be89de4-2429-4893-937f-e44e21235a1b"} {"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-13T21:39:52.837281877Z","hostname":"ip-10-150-1-93.us-west-2.compute.internal","pid":1160,"":"downstairs","":"downstairs","session_id":"7be89de4-2429-4893-937f-e44e21235a1b"} {"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-13T21:39:52.837288846Z","hostname":"ip-10-150-1-93.us-west-2.compute.internal","pid":1160,"":"downstairs","":"downstairs","session_id":"7be89de4-2429-4893-937f-e44e21235a1b"} {"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-13T21:39:52.837296865Z","hostname":"ip-10-150-1-93.us-west-2.compute.internal","pid":1160,"":"downstairs","":"downstairs","session_id":"7be89de4-2429-4893-937f-e44e21235a1b"} {"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-13T21:39:52.837304303Z","hostname":"ip-10-150-1-93.us-west-2.compute.internal","pid":1160,"":"downstairs","":"downstairs","session_id":"7be89de4-2429-4893-937f-e44e21235a1b"} {"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-13T21:39:52.837311842Z","hostname":"ip-10-150-1-93.us-west-2.compute.internal","pid":1160,"":"downstairs","":"downstairs","session_id":"7be89de4-2429-4893-937f-e44e21235a1b"} {"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-13T21:39:52.837318851Z","hostname":"ip-10-150-1-93.us-west-2.compute.internal","pid":1160,"":"downstairs","":"downstairs","session_id":"7be89de4-2429-4893-937f-e44e21235a1b"} {"msg":"Max found gen is 1","v":0,"name":"crucible","level":30,"time":"2024-02-13T21:39:52.83732698Z","hostname":"ip-10-150-1-93.us-west-2.compute.internal","pid":1160,"":"downstairs","":"downstairs","session_id":"7be89de4-2429-4893-937f-e44e21235a1b"} {"msg":"Generation requested: 1 >= found:1","v":0,"name":"crucible","level":30,"time":"2024-02-13T21:39:52.837334869Z","hostname":"ip-10-150-1-93.us-west-2.compute.internal","pid":1160,"":"downstairs","":"downstairs"Wait for a query_work_queue command to finish before sending IO ,"session_id":"7be89de4-2429-4893-937f-e44e21235a1b"} {"msg":"Next flush: 1","v":0,"name":"crucible","level":30,"time":"2024-02-13T21:39:52.837352286Z","hostname":"ip-10-150-1-93.us-west-2.compute.internal","pid":1160,"":"downstairs","":"downstairs","session_id":"7be89de4-2429-4893-937f-e44e21235a1b"} {"msg":"All extents match","v":0,"name":"crucible","level":30,"time":"2024-02-13T21:39:52.837356716Z","hostname":"ip-10-150-1-93.us-west-2.compute.internal","pid":1160,"":"downstairs","":"downstairs","session_id":"7be89de4-2429-4893-937f-e44e21235a1b"} {"msg":"No downstairs reconciliation required","v":0,"name":"crucible","level":30,"time":"2024-02-13T21:39:52.837361665Z","hostname":"ip-10-150-1-93.us-west-2.compute.internal","pid":1160,"session_id":"7be89de4-2429-4893-937f-e44e21235a1b"} {"msg":"Transition from WaitQuorum to Active","v":0,"name":"crucible","level":30,"time":"2024-02-13T21:39:52.837368844Z","hostname":"ip-10-150-1-93.us-west-2.compute.internal","pid":1160,"client":"0","":"downstairs","session_id":"7be89de4-2429-4893-937f-e44e21235a1b"} {"msg":"Transition from WaitQuorum to Active","v":0,"name":"crucible","level":30,"time":"2024-02-13T21:39:52.837376353Z","hostname":"ip-10-150-1-93.us-west-2.compute.internal","pid":1160,"client":"1","":"downstairs","session_id":"7be89de4-2429-4893-937f-e44e21235a1b"} {"msg":"Transition from WaitQuorum to Active","v":0,"name":"crucible","level":30,"time":"2024-02-13T21:39:52.837391681Z","hostname":"ip-10-150-1-93.us-west-2.compute.internal","pid":1160,"client":"2","":"downstairs","session_id":"7be89de4-2429-4893-937f-e44e21235a1b"} {"msg":"All required reconciliation work is completed","v":0,"name":"crucible","level":30,"time":"2024-02-13T21:39:52.837399099Z","hostname":"ip-10-150-1-93.us-west-2.compute.internal","pid":1160,"session_id":"7be89de4-2429-4893-937f-e44e21235a1b"} {"msg":"Set Downstairs and Upstairs active after reconciliation","v":0,"name":"crucible","level":30,"time":"2024-02-13T21:39:52.837412788Z","hostname":"ip-10-150-1-93.us-west-2.compute.internal","pid":1160,"session_id":"7be89de4-2429-4893-937f-e44e21235a1b"} {"msg":"b7476a9a-854d-4925-8597-fe5d6db6341f is now active with session: 7be89de4-2429-4893-937f-e44e21235a1b","v":0,"name":"crucible","level":30,"time":"2024-02-13T21:39:52.837419567Z","hostname":"ip-10-150-1-93.us-west-2.compute.internal","pid":1160,"session_id":"7be89de4-2429-4893-937f-e44e21235a1b"} {"msg":"Set Active after no reconciliation","v":0,"name":"crucible","level":30,"time":"2024-02-13T21:39:52.837426306Z","hostname":"ip-10-150-1-93.us-west-2.compute.internal","pid":1160,"session_id":"7be89de4-2429-4893-937f-e44e21235a1b"} {"msg":"The guest has finished waiting for activation with:1","v":0,"name":"crucible","level":30,"time":"2024-02-13T21:39:52.837430385Z","hostname":"ip-10-150-1-93.us-west-2.compute.internal","pid":1160} Region: es:16384 ec:640 bs:4096 ts:42949672960 tb:10485760 max_io:256 or 1048576 Perf test TEST SECONDS COUNT DPTH IOPS MEAN P95 P99 MAX ES EC rwrites 20.90 30000 1 1435.65 0.00070 0.00144 0.00199 0.03447 16384 640 rwrites 8.84 30000 1 3395.41 0.00029 0.00095 0.00174 0.06385 16384 640 rreads 5.53 30000 1 5425.50 0.00018 0.00023 0.00029 0.01323 16384 640 rreads 5.47 30000 1 5484.98 0.00018 0.00023 0.00028 0.01686 16384 640 A new loop begins at February 13, 2024 at 09:40:46 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-13T21:40:46.867457329Z","hostname":"ip-10-150-1-93.us-west-2.compute.internal","pid":1179} {"msg":"Crucible Version: BuildInfo {\n version: \"0.0.1\",\n git_sha: \"29185f5538632a13039785e911d1aaa0146bfa14\",\n git_commit_timestamp: \"2024-02-13T21:13:12.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-13T21:40:46.867581831Z","hostname":"ip-10-150-1-93.us-west-2.compute.internal","pid":1179} {"msg":"Upstairs <-> Downstairs Message Version: 5","v":0,"name":"crucible","level":30,"time":"2024-02-13T21:40:46.86758861Z","hostname":"ip-10-150-1-93.us-west-2.compute.internal","pid":1179} {"msg":"Crucible 59489292-28f0-45b0-8f75-1a7468f0fcb1 has session id: 83636ead-55c3-414e-9e81-cdb884fd0bba","v":0,"name":"crucible","level":30,"time":"2024-02-13T21:40:46.867593079Z","hostname":"ip-10-150-1-93.us-west-2.compute.internal","pid":1179,"session_id":"Crucible runtime is spawned 83636ead-55c3-414e-9e81-cdb884fd0bba"} {"msg":"Upstairs opts: Upstairs UUID: 59489292-28f0-45b0-8f75-1a7468f0fcb1, 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-13T21:40:46.867612766Z","hostname":"ip-10-150-1-93.us-west-2.compute.internal","pid":1179,"session_id":"83636ead-55c3-414e-9e81-cdb884fd0bba"} {"msg":"Crucible stats registered with UUID: 59489292-28f0-45b0-8f75-1a7468f0fcb1","v":0,"name":"crucible","level":30,"time":"2024-02-13T21:40:46.867619276Z","hostname":"ip-10-150-1-93.us-west-2.compute.internal","pid":1179,"session_id":"83636ead-55c3-414e-9e81-cdb884fd0bba"} {"msg":"The guest has requested activation with gen:1","v":0,"name":"crucible","level":30,"time":"2024-02-13T21:40:46.867628394Z","hostname":"ip-10-150-1-93.us-west-2.compute.internal","pid":1179} {"msg":"59489292-28f0-45b0-8f75-1a7468f0fcb1 active request set","v":0,"name":"crucible","level":30,"time":"2024-02-13T21:40:46.867709852Z","hostname":"ip-10-150-1-93.us-west-2.compute.internal","pid":1179,"session_id":"83636ead-55c3-414e-9e81-cdb884fd0bba"} {"msg":"sending connect oneshot to client","v":0,"name":"crucible","level":30,"time":"2024-02-13T21:40:46.86772402Z","hostname":"ip-10-150-1-93.us-west-2.compute.internal","pid":1179,"client":"0","":"downstairs","session_id":"83636ead-55c3-414e-9e81-cdb884fd0bba"} {"msg":"client set_active_request while in New; waiting...","v":0,"name":"crucible","level":30,"time":"2024-02-13T21:40:46.867733629Z","hostname":"ip-10-150-1-93.us-west-2.compute.internal","pid":1179,"client":"0","":"downstairs","session_id":"83636ead-55c3-414e-9e81-cdb884fd0bba"} {"msg":"sending connect oneshot to client","v":0,"name":"crucible","level":30,"time":"2024-02-13T21:40:46.867742028Z","hostname":"ip-10-150-1-93.us-west-2.compute.internal","pid":1179,"client":"1","":"downstairs","session_id":"83636ead-55c3-414e-9e81-cdb884fd0bba"} {"msg":"client set_active_request while in New; waiting...","v":0,"name":"crucible","level":30,"time":"2024-02-13T21:40:46.867750097Z","hostname":"ip-10-150-1-93.us-west-2.compute.internal","pid":1179,"client":"1","":"downstairs","session_id":"83636ead-55c3-414e-9e81-cdb884fd0bba"} {"msg":"sending connect oneshot to client","v":0,"name":"crucible","level":30,"time":"2024-02-13T21:40:46.867758735Z","hostname":"ip-10-150-1-93.us-west-2.compute.internal","pid":1179,"client":"2","":"downstairs","session_id":"83636ead-55c3-414e-9e81-cdb884fd0bba"} {"msg":"client set_active_request while in New; waiting...","v":0,"name":"crucible","level":30,"time":"2024-02-13T21:40:46.867766344Z","hostname":"ip-10-150-1-93.us-west-2.compute.internal","pid":1179,"client":"2","":"downstairs","session_id":"83636ead-55c3-414e-9e81-cdb884fd0bba"} {"msg":"connecting to 127.0.0.1:8830","v":0,"name":"crucible","level":30,"time":"2024-02-13T21:40:46.867774733Z","hostname":"ip-10-150-1-93.us-west-2.compute.internal","pid":1179,"":"io task","client":"2","":"downstairs","session_id":"83636ead-55c3-414e-9e81-cdb884fd0bba"} {"msg":"connecting to 127.0.0.1:8810","v":0,"name":"crucible","level":30,"time":"2024-02-13T21:40:46.867782882Z","hostname":"ip-10-150-1-93.us-west-2.compute.internal","pid":1179,"":"io task","client":"0","":"downstairs","session_id":"83636ead-55c3-414e-9e81-cdb884fd0bba"} {"msg":"connecting to 127.0.0.1:8820","v":0,"name":"crucible","level":30,"time":"2024-02-13T21:40:46.86779156Z","hostname":"ip-10-150-1-93.us-west-2.compute.internal","pid":1179,"":"io task","client":"1","":"downstairs","session_id":"83636ead-55c3-414e-9e81-cdb884fd0bba"} {"msg":"ds_connection connected","v":0,"name":"crucible","level":30,"time":"2024-02-13T21:40:46.867850552Z","hostname":"ip-10-150-1-93.us-west-2.compute.internal","pid":1179,"":"io task","client":"2","":"downstairs","session_id":"83636ead-55c3-414e-9e81-cdb884fd0bba"} {"msg":"ds_connection connected","v":0,"name":"crucible","level":30,"time":"2024-02-13T21:40:46.867868619Z","hostname":"ip-10-150-1-93.us-west-2.compute.internal","pid":1179,"":"io task","client":"0","":"downstairs","session_id":"83636ead-55c3-414e-9e81-cdb884fd0bba"} {"msg":"ds_connection connected","v":0,"name":"crucible","level":30,"time":"2024-02-13T21:40:46.867974934Z","hostname":"ip-10-150-1-93.us-west-2.compute.internal","pid":1179,"":"io task","client":"1","":"downstairs","session_id":"83636ead-55c3-414e-9e81-cdb884fd0bba"} {"msg":"ds_transition from New to WaitActive","v":0,"name":"crucible","level":30,"time":"2024-02-13T21:40:46.86820866Z","hostname":"ip-10-150-1-93.us-west-2.compute.internal","pid":1179,"client":"1","":"downstairs","session_id":"83636ead-55c3-414e-9e81-cdb884fd0bba"} {"msg":"[1] Transition from New to WaitActive","v":0,"name":"crucible","level":30,"time":"2024-02-13T21:40:46.868226597Z","hostname":"ip-10-150-1-93.us-west-2.compute.internal","pid":1179,"client":"1","":"downstairs","session_id":"83636ead-55c3-414e-9e81-cdb884fd0bba"} {"msg":"ds_transition from New to WaitActive","v":0,"name":"crucible","level":30,"time":"2024-02-13T21:40:46.868234486Z","hostname":"ip-10-150-1-93.us-west-2.compute.internal","pid":1179,"client":"2","":"downstairs","session_id":"83636ead-55c3-414e-9e81-cdb884fd0bba"} {"msg":"[2] Transition from New to WaitActive","v":0,"name":"crucible","level":30,"time":"2024-02-13T21:40:46.868242055Z","hostname":"ip-10-150-1-93.us-west-2.compute.internal","pid":1179,"client":"2","":"downstairs","session_id":"83636ead-55c3-414e-9e81-cdb884fd0bba"} {"msg":"ds_transition from New to WaitActive","v":0,"name":"crucible","level":30,"time":"2024-02-13T21:40:46.868249864Z","hostname":"ip-10-150-1-93.us-west-2.compute.internal","pid":1179,"client":"0","":"downstairs","session_id":"83636ead-55c3-414e-9e81-cdb884fd0bba"} {"msg":"[0] Transition from New to WaitActive","v":0,"name":"crucible","level":30,"time":"2024-02-13T21:40:46.868257523Z","hostname":"ip-10-150-1-93.us-west-2.compute.internal","pid":1179,"client":"0","":"downstairs","session_id":"83636ead-55c3-414e-9e81-cdb884fd0bba"} {"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-13T21:40:46.868451935Z","hostname":"ip-10-150-1-93.us-west-2.compute.internal","pid":1179,"client":"1","":"downstairs","session_id":"83636ead-55c3-414e-9e81-cdb884fd0bba"} {"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-13T21:40:46.868469632Z","hostname":"ip-10-150-1-93.us-west-2.compute.internal","pid":1179,"client":"0","":"downstairs","session_id":"83636ead-55c3-414e-9e81-cdb884fd0bba"} {"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-13T21:40:46.868501427Z","hostname":"ip-10-150-1-93.us-west-2.compute.internal","pid":1179,"client":"2","":"downstairs","session_id":"83636ead-55c3-414e-9e81-cdb884fd0bba"} {"msg":"ds_transition from WaitActive to WaitQuorum","v":0,"name":"crucible","level":30,"time":"2024-02-13T21:40:46.874080896Z","hostname":"ip-10-150-1-93.us-west-2.compute.internal","pid":1179,"client":"2","":"downstairs","session_id":"83636ead-55c3-414e-9e81-cdb884fd0bba"} {"msg":"[2] Transition from WaitActive to WaitQuorum","v":0,"name":"crucible","level":30,"time":"2024-02-13T21:40:46.874098684Z","hostname":"ip-10-150-1-93.us-west-2.compute.internal","pid":1179,"client":"2","":"downstairs","session_id":"83636ead-55c3-414e-9e81-cdb884fd0bba"} {"msg":"Waiting for true more clients to be ready","v":0,"name":"crucible","level":30,"time":"2024-02-13T21:40:46.874104633Z","hostname":"ip-10-150-1-93.us-west-2.compute.internal","pid":1179,"session_id":"83636ead-55c3-414e-9e81-cdb884fd0bba"} {"msg":"ds_transition from WaitActive to WaitQuorum","v":0,"name":"crucible","level":30,"time":"2024-02-13T21:40:46.875135483Z","hostname":"ip-10-150-1-93.us-west-2.compute.internal","pid":1179,"client":"1","":"downstairs","session_id":"83636ead-55c3-414e-9e81-cdb884fd0bba"} {"msg":"[1] Transition from WaitActive to WaitQuorum","v":0,"name":"crucible","level":30,"time":"2024-02-13T21:40:46.87515365Z","hostname":"ip-10-150-1-93.us-west-2.compute.internal","pid":1179,"client":"1","":"downstairs","session_id":"83636ead-55c3-414e-9e81-cdb884fd0bba"} {"msg":"Waiting for true more clients to be ready","v":0,"name":"crucible","level":30,"time":"2024-02-13T21:40:46.87515924Z","hostname":"ip-10-150-1-93.us-west-2.compute.internal","pid":1179,"session_id":"83636ead-55c3-414e-9e81-cdb884fd0bba"} {"msg":"ds_transition from WaitActive to WaitQuorum","v":0,"name":"crucible","level":30,"time":"2024-02-13T21:40:46.875163379Z","hostname":"ip-10-150-1-93.us-west-2.compute.internal","pid":1179,"client":"0","":"downstairs","session_id":"83636ead-55c3-414e-9e81-cdb884fd0bba"} {"msg":"[0] Transition from WaitActive to WaitQuorum","v":0,"name":"crucible","level":30,"time":"2024-02-13T21:40:46.875168538Z","hostname":"ip-10-150-1-93.us-west-2.compute.internal","pid":1179,"client":"0","":"downstairs","session_id":"83636ead-55c3-414e-9e81-cdb884fd0bba"} {"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-13T21:40:46.875173118Z","hostname":"ip-10-150-1-93.us-west-2.compute.internal","pid":1179,"":"downstairs","":"downstairs","session_id":"83636ead-55c3-414e-9e81-cdb884fd0bba"} {"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-13T21:40:46.875178137Z","hostname":"ip-10-150-1-93.us-west-2.compute.internal","pid":1179,"":"downstairs","":"downstairs","session_id":"83636ead-55c3-414e-9e81-cdb884fd0bba"} {"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-13T21:40:46.875182886Z","hostname":"ip-10-150-1-93.us-west-2.compute.internal","pid":1179,"":"downstairs","":"downstairs","session_id":"83636ead-55c3-414e-9e81-cdb884fd0bba"} {"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-13T21:40:46.875187505Z","hostname":"ip-10-150-1-93.us-west-2.compute.internal","pid":1179,"":"downstairs","":"downstairs","session_id":"83636ead-55c3-414e-9e81-cdb884fd0bba"} {"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-13T21:40:46.875191805Z","hostname":"ip-10-150-1-93.us-west-2.compute.internal","pid":1179,"":"downstairs","":"downstairs","session_id":"83636ead-55c3-414e-9e81-cdb884fd0bba"} {"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-13T21:40:46.875196764Z","hostname":"ip-10-150-1-93.us-west-2.compute.internal","pid":1179,"":"downstairs","":"downstairs","session_id":"83636ead-55c3-414e-9e81-cdb884fd0bba"} {"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-13T21:40:46.875201234Z","hostname":"ip-10-150-1-93.us-west-2.compute.internal","pid":1179,"":"downstairs","":"downstairs","session_id":"83636ead-55c3-414e-9e81-cdb884fd0bba"} {"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-13T21:40:46.875205813Z","hostname":"ip-10-150-1-93.us-west-2.compute.internal","pid":1179,"":"downstairs","":"downstairs","session_id":"83636ead-55c3-414e-9e81-cdb884fd0bba"} {"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-13T21:40:46.875210572Z","hostname":"ip-10-150-1-93.us-west-2.compute.internal","pid":1179,"":"downstairs","":"downstairs","session_id":"83636ead-55c3-414e-9e81-cdb884fd0bba"} {"msg":"Max found gen is 1","v":0,"name":"crucible","level":30,"time":"2024-02-13T21:40:46.875215232Z","hostname":"ip-10-150-1-93.us-west-2.compute.internal","pid":1179,"":"downstairs","":"downstairs","session_id":"83636ead-55c3-414e-9e81-cdb884fd0bba"} {"msg":"Generation requested: 1 >= found:1","v":0,"name":"crucible","level":30,"time":"2024-02-13T21:40:46.875220281Z","hostname":"ip-10-150-1-93.us-west-2.compute.internal","pid":1179,"":"downstairs","":"downstairs","session_id":"83636ead-55c3-414e-9e81-cdb884fd0bba"} {"msg":"Next flush: 1","v":0,"name":"crucible","level":30,"time":"2024-02-13T21:40:46.87522525Z","hostname":"ip-10-150-1-93.us-west-2.compute.internal","pid":1179,"":"downstairs","":"downstairs","session_id":"83636ead-55c3-414e-9e81-cdb884fd0bba"} {"msg":"All extents match","v":0,"name":"crucible","level":30,"time":"2024-02-13T21:40:46.875229699Z","hostname":"ip-10-150-1-93.us-west-2.compute.internal","pid":1179,"":"downstairs","":"downstairs","session_id":"83636ead-55c3-414e-9e81-cdb884fd0bba"} {"msg":"No downstairs reconciliation required","v":0,"name":"crucible","level":30,"time":"2024-02-13T21:40:46.875234559Z","hostname":"ip-10-150-1-93.us-west-2.compute.internal","pid":1179,"session_id":"83636ead-55c3-414e-9e81-cdb884fd0bba"} {"msg":"Transition from WaitQuorum to Active","v":0,"name":"crucible","level":30,"time":"2024-02-13T21:40:46.875238378Z","hostname":"ip-10-150-1-93.us-west-2.compute.internal","pid":1179,"client":"0","":"downstairs","session_id":"83636ead-55c3-414e-9e81-cdb884fd0bba"} {"msg":"Transition from WaitQuorum to Active","v":0,"name":"crucible","level":30,"time":"2024-02-13T21:40:46.875242648Z","hostname":"ip-10-150-1-93.us-west-2.compute.internal","pid":1179,"client":"1","":"downstairs","session_id":"83636ead-55c3-414e-9e81-cdb884fd0bba"} {"msg":"Transition from WaitQuorum to Active","v":0,"name":"crucible","level":30,"time":"2024-02-13T21:40:46.875246967Z","hostname":"ip-10-150-1-93.us-west-2.compute.internal","pid":1179,"client":"2","":"downstairs","session_id":"83636ead-55c3-414e-9e81-cdb884fd0bba"} {"msg":"All required reconciliation work is completed","v":0,"name":"crucible","level":30,"time":"2024-02-13T21:40:46.875251136Z","hostname":"ip-10-150-1-93.us-west-2.compute.internal","pid":1179,"session_id":"83636ead-55c3-414e-9e81-cdb884fd0bba"} {"msg":"Set Downstairs and Upstairs active after reconciliation","v":0,"name":"crucible","level":30,"time":"2024-02-13T21:40:46.875255396Z","hostname":"ip-10-150-1-93.us-west-2.compute.internal","pid":1179,"session_id":"83636ead-55c3-414e-9e81-cdb884fd0bba"} {"msg":"59489292-28f0-45b0-8f75-1a7468f0fcb1 is now active with session: 83636ead-55c3-414e-9e81-cdb884fd0bba","v":0,"name":"crucible","level":30,"time":"2024-02-13T21:40:46.875259315Z","hostname":"ip-10-150-1-93.us-west-2.compute.internal","pid":1179,"session_id":"Wait for a query_work_queue command to finish before sending IO 83636ead-55c3-414e-9e81-cdb884fd0bba"} {"msg":"Set Active after no reconciliation","v":0,"name":"crucible","level":30,"time":"2024-02-13T21:40:46.875266014Z","hostname":"ip-10-150-1-93.us-west-2.compute.internal","pid":1179,"session_id":"83636ead-55c3-414e-9e81-cdb884fd0bba"} {"msg":"The guest has finished waiting for activation with:1","v":0,"name":"crucible","level":30,"time":"2024-02-13T21:40:46.875270513Z","hostname":"ip-10-150-1-93.us-west-2.compute.internal","pid":1179} Region: es:16384 ec:1280 bs:4096 ts:85899345920 tb:20971520 max_io:256 or 1048576 Perf test TEST SECONDS COUNT DPTH IOPS MEAN P95 P99 MAX ES EC rwrites 8.04 30000 1 3733.27 0.00027 0.00062 0.00134 0.06491 16384 1280 rwrites 8.36 30000 1 3589.50 0.00028 0.00062 0.00118 0.05722 16384 1280 rreads 5.53 30000 1 5426.72 0.00018 0.00023 0.00028 0.01422 16384 1280 rreads 5.51 30000 1 5448.53 0.00018 0.00023 0.00027 0.01422 16384 1280 Perf test finished on February 13, 2024 at 09:41:18 PM UTC