Perf test begins at July 9, 2024 at 09:26:07 PM UTC A new loop begins at July 9, 2024 at 09:26:14 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-07-09T21:26:14.467375588Z","hostname":"w-01J2CP58F0HWTMECWTSGW2EZ6Y","pid":1199} {"msg":"Crucible Version: BuildInfo {\n version: \"0.0.1\",\n git_sha: \"e5f834981d3a43d75fe6f427c4755541ac0c2270\",\n git_commit_timestamp: \"2024-07-09T21:07:43.000000000Z\",\n git_branch: \"main\",\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-07-09T21:26:14.467542Z","hostname":"w-01J2CP58F0HWTMECWTSGW2EZ6Y","pid":1199} {"msg":"Upstairs <-> Downstairs Message Version: 8","v":0,"name":"crucible","level":30,"time":"2024-07-09T21:26:14.467548279Z","hostname":"w-01J2CP58F0HWTMECWTSGW2EZ6Y","pid":1199} {"msg":"Crucible 73c30300-2c83-4d4e-89df-8edcca1a9d64 has session id: 22c353b8-ead2-4be7-ab76-1268f13ff041","v":0,"name":"crucible","level":30,"time":"2024-07-09T21:26:14.467906579Z","hostname":"w-01J2CP58F0HWTMECWTSGW2EZ6Y","pid":1199,"session_id":"22c353b8-ead2-4be7-ab76-1268f13ff041"} {"msg":"Upstairs opts: Upstairs UUID: 73c30300-2c83-4d4e-89df-8edcca1a9d64, 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-07-09T21:26:14.467956191Z","hostname":"w-01J2CP58F0HWTMECWTSGW2EZ6Y","pid":1199,"session_id":"22c353b8-ead2-4be7-ab76-1268f13ff041"} {"msg":"Crucible stats registered with UUID: 73c30300-2c83-4d4e-89df-8edcca1a9d64","v":0,"name":"crucible","level":30,"time":"2024-07-09T21:26:14.46796189Z","hostname":"w-01J2CP58F0HWTMECWTSGW2EZ6Y","pid":1199,"session_id":"22c353b8-ead2-4be7-ab76-1268f13ff041"} Crucible runtime is spawned {"msg":"The guest has requested activation with gen:1","v":0,"name":"crucible","level":30,"time":"2024-07-09T21:26:14.504354636Z","hostname":"w-01J2CP58F0HWTMECWTSGW2EZ6Y","pid":1199} {"msg":"73c30300-2c83-4d4e-89df-8edcca1a9d64 active request set","v":0,"name":"crucible","level":30,"time":"2024-07-09T21:26:14.504417325Z","hostname":"w-01J2CP58F0HWTMECWTSGW2EZ6Y","pid":1199,"session_id":"22c353b8-ead2-4be7-ab76-1268f13ff041"} {"msg":"sending connect oneshot to client","v":0,"name":"crucible","level":30,"time":"2024-07-09T21:26:14.504439622Z","hostname":"w-01J2CP58F0HWTMECWTSGW2EZ6Y","pid":1199,"client":"0","":"downstairs","session_id":"22c353b8-ead2-4be7-ab76-1268f13ff041"} {"msg":"client set_active_request while in New; waiting...","v":0,"name":"crucible","level":30,"time":"2024-07-09T21:26:14.504486624Z","hostname":"w-01J2CP58F0HWTMECWTSGW2EZ6Y","pid":1199,"client":"0","":"downstairs","session_id":"22c353b8-ead2-4be7-ab76-1268f13ff041"} {"msg":"sending connect oneshot to client","v":0,"name":"crucible","level":30,"time":"2024-07-09T21:26:14.504493493Z","hostname":"w-01J2CP58F0HWTMECWTSGW2EZ6Y","pid":1199,"client":"1","":"downstairs","session_id":"22c353b8-ead2-4be7-ab76-1268f13ff041"} {"msg":"client set_active_request while in New; waiting...","v":0,"name":"crucible","level":30,"time":"2024-07-09T21:26:14.504499601Z","hostname":"w-01J2CP58F0HWTMECWTSGW2EZ6Y","pid":1199,"client":"1","":"downstairs","session_id":"22c353b8-ead2-4be7-ab76-1268f13ff041"} {"msg":"sending connect oneshot to client","v":0,"name":"crucible","level":30,"time":"2024-07-09T21:26:14.504504891Z","hostname":"w-01J2CP58F0HWTMECWTSGW2EZ6Y","pid":1199,"client":"2","":"downstairs","session_id":"22c353b8-ead2-4be7-ab76-1268f13ff041"} {"msg":"client set_active_request while in New; waiting...","v":0,"name":"crucible","level":30,"time":"2024-07-09T21:26:14.50451078Z","hostname":"w-01J2CP58F0HWTMECWTSGW2EZ6Y","pid":1199,"client":"2","":"downstairs","session_id":"22c353b8-ead2-4be7-ab76-1268f13ff041"} {"msg":"connecting to 127.0.0.1:8820","v":0,"name":"crucible","level":30,"time":"2024-07-09T21:26:14.504607974Z","hostname":"w-01J2CP58F0HWTMECWTSGW2EZ6Y","pid":1199,"":"io task","client":"1","":"downstairs","session_id":"22c353b8-ead2-4be7-ab76-1268f13ff041"} {"msg":"connecting to 127.0.0.1:8830","v":0,"name":"crucible","level":30,"time":"2024-07-09T21:26:14.504624521Z","hostname":"w-01J2CP58F0HWTMECWTSGW2EZ6Y","pid":1199,"":"io task","client":"2","":"downstairs","session_id":"22c353b8-ead2-4be7-ab76-1268f13ff041"} {"msg":"connecting to 127.0.0.1:8810","v":0,"name":"crucible","level":30,"time":"2024-07-09T21:26:14.50463043Z","hostname":"w-01J2CP58F0HWTMECWTSGW2EZ6Y","pid":1199,"":"io task","client":"0","":"downstairs","session_id":"22c353b8-ead2-4be7-ab76-1268f13ff041"} {"msg":"ds_connection connected from Ok(127.0.0.1:55558)","v":0,"name":"crucible","level":30,"time":"2024-07-09T21:26:14.504758958Z","hostname":"w-01J2CP58F0HWTMECWTSGW2EZ6Y","pid":1199,"":"io task","client":"1","":"downstairs","session_id":"22c353b8-ead2-4be7-ab76-1268f13ff041"} {"msg":"ds_connection connected from Ok(127.0.0.1:40186)","v":0,"name":"crucible","level":30,"time":"2024-07-09T21:26:14.504773646Z","hostname":"w-01J2CP58F0HWTMECWTSGW2EZ6Y","pid":1199,"":"io task","client":"2","":"downstairs","session_id":"22c353b8-ead2-4be7-ab76-1268f13ff041"} {"msg":"ds_connection connected from Ok(127.0.0.1:34762)","v":0,"name":"crucible","level":30,"time":"2024-07-09T21:26:14.504782074Z","hostname":"w-01J2CP58F0HWTMECWTSGW2EZ6Y","pid":1199,"":"io task","client":"0","":"downstairs","session_id":"22c353b8-ead2-4be7-ab76-1268f13ff041"} {"msg":"ds_transition from New to WaitActive","v":0,"name":"crucible","level":30,"time":"2024-07-09T21:26:14.505568153Z","hostname":"w-01J2CP58F0HWTMECWTSGW2EZ6Y","pid":1199,"client":"0","":"downstairs","session_id":"22c353b8-ead2-4be7-ab76-1268f13ff041"} {"msg":"[0] Transition from New to WaitActive","v":0,"name":"crucible","level":30,"time":"2024-07-09T21:26:14.505590879Z","hostname":"w-01J2CP58F0HWTMECWTSGW2EZ6Y","pid":1199,"client":"0","":"downstairs","session_id":"22c353b8-ead2-4be7-ab76-1268f13ff041"} {"msg":"ds_transition from New to WaitActive","v":0,"name":"crucible","level":30,"time":"2024-07-09T21:26:14.505599478Z","hostname":"w-01J2CP58F0HWTMECWTSGW2EZ6Y","pid":1199,"client":"1","":"downstairs","session_id":"22c353b8-ead2-4be7-ab76-1268f13ff041"} {"msg":"[1] Transition from New to WaitActive","v":0,"name":"crucible","level":30,"time":"2024-07-09T21:26:14.505607157Z","hostname":"w-01J2CP58F0HWTMECWTSGW2EZ6Y","pid":1199,"client":"1","":"downstairs","session_id":"22c353b8-ead2-4be7-ab76-1268f13ff041"} {"msg":"ds_transition from New to WaitActive","v":0,"name":"crucible","level":30,"time":"2024-07-09T21:26:14.505614446Z","hostname":"w-01J2CP58F0HWTMECWTSGW2EZ6Y","pid":1199,"client":"2","":"downstairs","session_id":"22c353b8-ead2-4be7-ab76-1268f13ff041"} {"msg":"[2] Transition from New to WaitActive","v":0,"name":"crucible","level":30,"time":"2024-07-09T21:26:14.505621874Z","hostname":"w-01J2CP58F0HWTMECWTSGW2EZ6Y","pid":1199,"client":"2","":"downstairs","session_id":"22c353b8-ead2-4be7-ab76-1268f13ff041"} {"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-07-09T21:26:14.505811393Z","hostname":"w-01J2CP58F0HWTMECWTSGW2EZ6Y","pid":1199,"client":"0","":"downstairs","session_id":"22c353b8-ead2-4be7-ab76-1268f13ff041"} {"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-07-09T21:26:14.505859565Z","hostname":"w-01J2CP58F0HWTMECWTSGW2EZ6Y","pid":1199,"client":"2","":"downstairs","session_id":"22c353b8-ead2-4be7-ab76-1268f13ff041"} {"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-07-09T21:26:14.505872972Z","hostname":"w-01J2CP58F0HWTMECWTSGW2EZ6Y","pid":1199,"client":"1","":"downstairs","session_id":"22c353b8-ead2-4be7-ab76-1268f13ff041"} {"msg":"ds_transition from WaitActive to WaitQuorum","v":0,"name":"crucible","level":30,"time":"2024-07-09T21:26:14.508021474Z","hostname":"w-01J2CP58F0HWTMECWTSGW2EZ6Y","pid":1199,"client":"0","":"downstairs","session_id":"22c353b8-ead2-4be7-ab76-1268f13ff041"} {"msg":"[0] Transition from WaitActive to WaitQuorum","v":0,"name":"crucible","level":30,"time":"2024-07-09T21:26:14.50804286Z","hostname":"w-01J2CP58F0HWTMECWTSGW2EZ6Y","pid":1199,"client":"0","":"downstairs","session_id":"22c353b8-ead2-4be7-ab76-1268f13ff041"} {"msg":"Waiting for more clients to be ready","v":0,"name":"crucible","level":30,"time":"2024-07-09T21:26:14.508050289Z","hostname":"w-01J2CP58F0HWTMECWTSGW2EZ6Y","pid":1199,"session_id":"22c353b8-ead2-4be7-ab76-1268f13ff041"} {"msg":"ds_transition from WaitActive to WaitQuorum","v":0,"name":"crucible","level":30,"time":"2024-07-09T21:26:14.508198834Z","hostname":"w-01J2CP58F0HWTMECWTSGW2EZ6Y","pid":1199,"client":"2","":"downstairs","session_id":"22c353b8-ead2-4be7-ab76-1268f13ff041"} {"msg":"[2] Transition from WaitActive to WaitQuorum","v":0,"name":"crucible","level":30,"time":"2024-07-09T21:26:14.508216571Z","hostname":"w-01J2CP58F0HWTMECWTSGW2EZ6Y","pid":1199,"client":"2","":"downstairs","session_id":"22c353b8-ead2-4be7-ab76-1268f13ff041"} {"msg":"Waiting for more clients to be ready","v":0,"name":"crucible","level":30,"time":"2024-07-09T21:26:14.50822221Z","hostname":"w-01J2CP58F0HWTMECWTSGW2EZ6Y","pid":1199,"session_id":"22c353b8-ead2-4be7-ab76-1268f13ff041"} {"msg":"ds_transition from WaitActive to WaitQuorum","v":0,"name":"crucible","level":30,"time":"2024-07-09T21:26:14.508271572Z","hostname":"w-01J2CP58F0HWTMECWTSGW2EZ6Y","pid":1199,"client":"1","":"downstairs","session_id":"22c353b8-ead2-4be7-ab76-1268f13ff041"} {"msg":"[1] Transition from WaitActive to WaitQuorum","v":0,"name":"crucible","level":30,"time":"2024-07-09T21:26:14.508287179Z","hostname":"w-01J2CP58F0HWTMECWTSGW2EZ6Y","pid":1199,"client":"1","":"downstairs","session_id":"22c353b8-ead2-4be7-ab76-1268f13ff041"} {"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-07-09T21:26:14.508292928Z","hostname":"w-01J2CP58F0HWTMECWTSGW2EZ6Y","pid":1199,"":"downstairs","":"downstairs","session_id":"22c353b8-ead2-4be7-ab76-1268f13ff041"} {"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-07-09T21:26:14.508298398Z","hostname":"w-01J2CP58F0HWTMECWTSGW2EZ6Y","pid":1199,"":"downstairs","":"downstairs","session_id":"22c353b8-ead2-4be7-ab76-1268f13ff041"} {"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-07-09T21:26:14.508303937Z","hostname":"w-01J2CP58F0HWTMECWTSGW2EZ6Y","pid":1199,"":"downstairs","":"downstairs","session_id":"22c353b8-ead2-4be7-ab76-1268f13ff041"} {"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-07-09T21:26:14.508309286Z","hostname":"w-01J2CP58F0HWTMECWTSGW2EZ6Y","pid":1199,"":"downstairs","":"downstairs","session_id":"22c353b8-ead2-4be7-ab76-1268f13ff041"} {"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-07-09T21:26:14.508315095Z","hostname":"w-01J2CP58F0HWTMECWTSGW2EZ6Y","pid":1199,"":"downstairs","":"downstairs","session_id":"22c353b8-ead2-4be7-ab76-1268f13ff041"} {"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-07-09T21:26:14.508320234Z","hostname":"w-01J2CP58F0HWTMECWTSGW2EZ6Y","pid":1199,"":"downstairs","":"downstairs","session_id":"22c353b8-ead2-4be7-ab76-1268f13ff041"} {"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-07-09T21:26:14.508326443Z","hostname":"w-01J2CP58F0HWTMECWTSGW2EZ6Y","pid":1199,"":"downstairs","":"downstairs","session_id":"22c353b8-ead2-4be7-ab76-1268f13ff041"} {"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-07-09T21:26:14.508331992Z","hostname":"w-01J2CP58F0HWTMECWTSGW2EZ6Y","pid":1199,"":"downstairs","":"downstairs","session_id":"22c353b8-ead2-4be7-ab76-1268f13ff041"} {"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-07-09T21:26:14.508337531Z","hostname":"w-01J2CP58F0HWTMECWTSGW2EZ6Y","pid":1199,"":"downstairs","":"downstairs","session_id":"22c353b8-ead2-4be7-ab76-1268f13ff041"} {"msg":"Max found gen is 1","v":0,"name":"crucible","level":30,"time":"2024-07-09T21:26:14.50834306Z","hostname":"w-01J2CP58F0HWTMECWTSGW2EZ6Y","pid":1199,"":"downstairs","":"downstairs","session_id":"22c353b8-ead2-4be7-ab76-1268f13ff041"} {"msg":"Generation requested: 1 >= found:1","v":0,"name":"crucible","level":30,"time":"2024-07-09T21:26:14.508348349Z","hostname":"w-01J2CP58F0HWTMECWTSGW2EZ6Y","pid":1199,"":"downstairs","":"downstairs","session_id":"22c353b8-ead2-4be7-ab76-1268f13ff041"} {"msg":"Next flush: 1","v":0,"name":"crucible","level":30,"time":"2024-07-09T21:26:14.508354068Z","hostname":"w-01J2CP58F0HWTMECWTSGW2EZ6Y","pid":1199,"":"downstairs","":"downstairs","session_id":"22c353b8-ead2-4be7-ab76-1268f13ff041"} {"msg":"All extents match","v":0,"name":"crucible","level":30,"time":"2024-07-09T21:26:14.508359317Z","hostname":"w-01J2CP58F0HWTMECWTSGW2EZ6Y","pid":1199,"":"downstairs","":"downstairs","session_id":"22c353b8-ead2-4be7-ab76-1268f13ff041"} {"msg":"No downstairs reconciliation required","v":0,"name":"crucible","level":30,"time":"2024-07-09T21:26:14.508364966Z","hostname":"w-01J2CP58F0HWTMECWTSGW2EZ6Y","pid":1199,"session_id":"22c353b8-ead2-4be7-ab76-1268f13ff041"} {"msg":"Transition from WaitQuorum to Active","v":0,"name":"crucible","level":30,"time":"2024-07-09T21:26:14.508369516Z","hostname":"w-01J2CP58F0HWTMECWTSGW2EZ6Y","pid":1199,"client":"0","":"downstairs","session_id":"22c353b8-ead2-4be7-ab76-1268f13ff041"} {"msg":"Transition from WaitQuorum to Active","v":0,"name":"crucible","level":30,"time":"2024-07-09T21:26:14.508375445Z","hostname":"w-01J2CP58F0HWTMECWTSGW2EZ6Y","pid":1199,"client":"1","":"downstairs","session_id":"22c353b8-ead2-4be7-ab76-1268f13ff041"} {"msg":"Transition from WaitQuorum to Active","v":0,"name":"crucible","level":30,"time":"2024-07-09T21:26:14.508381873Z","hostname":"w-01J2CP58F0HWTMECWTSGW2EZ6Y","pid":1199,"client":"2","":"downstairs","session_id":"22c353b8-ead2-4be7-ab76-1268f13ff041"} {"msg":"All required reconciliation work is completed","v":0,"name":"crucible","level":30,"time":"2024-07-09T21:26:14.508386233Z","hostname":"w-01J2CP58F0HWTMECWTSGW2EZ6Y","pid":1199,"session_id":"22c353b8-ead2-4be7-ab76-1268f13ff041"} {"msg":"Set Downstairs and Upstairs active after reconciliation","v":0,"name":"crucible","level":30,"time":"2024-07-09T21:26:14.508390472Z","hostname":"w-01J2CP58F0HWTMECWTSGW2EZ6Y","pid":1199,"session_id":"22c353b8-ead2-4be7-ab76-1268f13ff041"} {"msg":"73c30300-2c83-4d4e-89df-8edcca1a9d64 is now active with session: 22c353b8-ead2-4be7-ab76-1268f13ff041","v":0,"name":"crucible","level":30,"time":"2024-07-09T21:26:14.508394342Z"Wait for a query_work_queue command to finish before sending IO ,"hostname":"w-01J2CP58F0HWTMECWTSGW2EZ6Y","pid":1199,"session_id":"22c353b8-ead2-4be7-ab76-1268f13ff041"} {"msg":"Set Active after no reconciliation","v":0,"name":"crucible","level":30,"time":"2024-07-09T21:26:14.50840065Z","hostname":"w-01J2CP58F0HWTMECWTSGW2EZ6Y","pid":1199,"session_id":"22c353b8-ead2-4be7-ab76-1268f13ff041"} {"msg":"The guest has finished waiting for activation with:1","v":0,"name":"crucible","level":30,"time":"2024-07-09T21:26:14.50840483Z","hostname":"w-01J2CP58F0HWTMECWTSGW2EZ6Y","pid":1199} 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 7.94 30000 1 3779.65 0.00026 0.00118 0.00166 0.03200 16384 640 rwrites 6.39 30000 1 4692.00 0.00021 0.00077 0.00181 0.03976 16384 640 rreads 5.66 30000 1 5301.59 0.00019 0.00024 0.00029 0.01340 16384 640 rreads 5.55 30000 1 5402.15 0.00019 0.00023 0.00028 0.01340 16384 640 {"msg":"Guest handle has been dropped","v":0,"name":"crucible","level":40,"time":"2024-07-09T21:26:44.543396414Z","hostname":"w-01J2CP58F0HWTMECWTSGW2EZ6Y","pid":1199} A new loop begins at July 9, 2024 at 09:26:54 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-07-09T21:26:54.319480968Z","hostname":"w-01J2CP58F0HWTMECWTSGW2EZ6Y","pid":1218} {"msg":"Crucible Version: BuildInfo {\n version: \"0.0.1\",\n git_sha: \"e5f834981d3a43d75fe6f427c4755541ac0c2270\",\n git_commit_timestamp: \"2024-07-09T21:07:43.000000000Z\",\n git_branch: \"main\",\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-07-09T21:26:54.319615905Z","hostname":"w-01J2CP58F0HWTMECWTSGW2EZ6Y","pid":1218} {"msg":"Upstairs <-> Downstairs Message Version: 8","v":0,"name":"crucible","level":30,"time":"2024-07-09T21:26:54.319622954Z","hostname":"w-01J2CP58F0HWTMECWTSGW2EZ6Y","pid":1218} {"msg":"Crucible fed7e0d7-d541-4f58-8485-8372ecf9b991 has session id: da99c0e3-514a-469b-ab48-be803ae4773a","v":0,"name":"crucible","level":30,"time":"2024-07-09T21:26:54.319936592Z","hostname":"w-01J2CP58F0HWTMECWTSGW2EZ6Y","pid":1218,"session_id":"da99c0e3-514a-469b-ab48-be803ae4773a"} {"msg":"Upstairs opts: Upstairs UUID: fed7e0d7-d541-4f58-8485-8372ecf9b991, 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-07-09T21:26:54.320015729Z","hostname":"w-01J2CP58F0HWTMECWTSGW2EZ6Y","pid":1218,"session_id":"da99c0e3-514a-469b-ab48-be803ae4773a"} {"msg":"Crucible stats registered with UUID: fed7e0d7-d541-4f58-8485-8372ecf9b991","v":0,"name":"crucible","level":30,"time":"2024-07-09T21:26:54.320031296Z","hostname":"w-01J2CP58F0HWTMECWTSGW2EZ6Y","pid":1218,"session_id":"da99c0e3-514a-469b-ab48-be803ae4773a"} Crucible runtime is spawned {"msg":"The guest has requested activation with gen:1","v":0,"name":"crucible","level":30,"time":"2024-07-09T21:26:54.35667561Z","hostname":"w-01J2CP58F0HWTMECWTSGW2EZ6Y","pid":1218} {"msg":"fed7e0d7-d541-4f58-8485-8372ecf9b991 active request set","v":0,"name":"crucible","level":30,"time":"2024-07-09T21:26:54.35673748Z","hostname":"w-01J2CP58F0HWTMECWTSGW2EZ6Y","pid":1218,"session_id":"da99c0e3-514a-469b-ab48-be803ae4773a"} {"msg":"sending connect oneshot to client","v":0,"name":"crucible","level":30,"time":"2024-07-09T21:26:54.356760266Z","hostname":"w-01J2CP58F0HWTMECWTSGW2EZ6Y","pid":1218,"client":"0","":"downstairs","session_id":"da99c0e3-514a-469b-ab48-be803ae4773a"} {"msg":"client set_active_request while in New; waiting...","v":0,"name":"crucible","level":30,"time":"2024-07-09T21:26:54.356782522Z","hostname":"w-01J2CP58F0HWTMECWTSGW2EZ6Y","pid":1218,"client":"0","":"downstairs","session_id":"da99c0e3-514a-469b-ab48-be803ae4773a"} {"msg":"sending connect oneshot to client","v":0,"name":"crucible","level":30,"time":"2024-07-09T21:26:54.356803449Z","hostname":"w-01J2CP58F0HWTMECWTSGW2EZ6Y","pid":1218,"client":"1","":"downstairs","session_id":"da99c0e3-514a-469b-ab48-be803ae4773a"} {"msg":"client set_active_request while in New; waiting...","v":0,"name":"crucible","level":30,"time":"2024-07-09T21:26:54.356813057Z","hostname":"w-01J2CP58F0HWTMECWTSGW2EZ6Y","pid":1218,"client":"1","":"downstairs","session_id":"da99c0e3-514a-469b-ab48-be803ae4773a"} {"msg":"sending connect oneshot to client","v":0,"name":"crucible","level":30,"time":"2024-07-09T21:26:54.356822205Z","hostname":"w-01J2CP58F0HWTMECWTSGW2EZ6Y","pid":1218,"client":"2","":"downstairs","session_id":"da99c0e3-514a-469b-ab48-be803ae4773a"} {"msg":"client set_active_request while in New; waiting...","v":0,"name":"crucible","level":30,"time":"2024-07-09T21:26:54.356831684Z","hostname":"w-01J2CP58F0HWTMECWTSGW2EZ6Y","pid":1218,"client":"2","":"downstairs","session_id":"da99c0e3-514a-469b-ab48-be803ae4773a"} {"msg":"connecting to 127.0.0.1:8830","v":0,"name":"crucible","level":30,"time":"2024-07-09T21:26:54.356869977Z","hostname":"w-01J2CP58F0HWTMECWTSGW2EZ6Y","pid":1218,"":"io task","client":"2","":"downstairs","session_id":"da99c0e3-514a-469b-ab48-be803ae4773a"} {"msg":"connecting to 127.0.0.1:8810","v":0,"name":"crucible","level":30,"time":"2024-07-09T21:26:54.356879306Z","hostname":"w-01J2CP58F0HWTMECWTSGW2EZ6Y","pid":1218,"":"io task","client":"0","":"downstairs","session_id":"da99c0e3-514a-469b-ab48-be803ae4773a"} {"msg":"connecting to 127.0.0.1:8820","v":0,"name":"crucible","level":30,"time":"2024-07-09T21:26:54.356887095Z","hostname":"w-01J2CP58F0HWTMECWTSGW2EZ6Y","pid":1218,"":"io task","client":"1","":"downstairs","session_id":"da99c0e3-514a-469b-ab48-be803ae4773a"} {"msg":"ds_connection connected from Ok(127.0.0.1:47677)","v":0,"name":"crucible","level":30,"time":"2024-07-09T21:26:54.356923888Z","hostname":"w-01J2CP58F0HWTMECWTSGW2EZ6Y","pid":1218,"":"io task","client":"2","":"downstairs","session_id":"da99c0e3-514a-469b-ab48-be803ae4773a"} {"msg":"ds_connection connected from Ok(127.0.0.1:60924)","v":0,"name":"crucible","level":30,"time":"2024-07-09T21:26:54.356938866Z","hostname":"w-01J2CP58F0HWTMECWTSGW2EZ6Y","pid":1218,"":"io task","client":"1","":"downstairs","session_id":"da99c0e3-514a-469b-ab48-be803ae4773a"} {"msg":"ds_connection connected from Ok(127.0.0.1:38110)","v":0,"name":"crucible","level":30,"time":"2024-07-09T21:26:54.356955533Z","hostname":"w-01J2CP58F0HWTMECWTSGW2EZ6Y","pid":1218,"":"io task","client":"0","":"downstairs","session_id":"da99c0e3-514a-469b-ab48-be803ae4773a"} {"msg":"ds_transition from New to WaitActive","v":0,"name":"crucible","level":30,"time":"2024-07-09T21:26:54.357426954Z","hostname":"w-01J2CP58F0HWTMECWTSGW2EZ6Y","pid":1218,"client":"1","":"downstairs","session_id":"da99c0e3-514a-469b-ab48-be803ae4773a"} {"msg":"[1] Transition from New to WaitActive","v":0,"name":"crucible","level":30,"time":"2024-07-09T21:26:54.357444391Z","hostname":"w-01J2CP58F0HWTMECWTSGW2EZ6Y","pid":1218,"client":"1","":"downstairs","session_id":"da99c0e3-514a-469b-ab48-be803ae4773a"} {"msg":"ds_transition from New to WaitActive","v":0,"name":"crucible","level":30,"time":"2024-07-09T21:26:54.357449251Z","hostname":"w-01J2CP58F0HWTMECWTSGW2EZ6Y","pid":1218,"client":"0","":"downstairs","session_id":"da99c0e3-514a-469b-ab48-be803ae4773a"} {"msg":"[0] Transition from New to WaitActive","v":0,"name":"crucible","level":30,"time":"2024-07-09T21:26:54.35745364Z","hostname":"w-01J2CP58F0HWTMECWTSGW2EZ6Y","pid":1218,"client":"0","":"downstairs","session_id":"da99c0e3-514a-469b-ab48-be803ae4773a"} {"msg":"ds_transition from New to WaitActive","v":0,"name":"crucible","level":30,"time":"2024-07-09T21:26:54.357457969Z","hostname":"w-01J2CP58F0HWTMECWTSGW2EZ6Y","pid":1218,"client":"2","":"downstairs","session_id":"da99c0e3-514a-469b-ab48-be803ae4773a"} {"msg":"[2] Transition from New to WaitActive","v":0,"name":"crucible","level":30,"time":"2024-07-09T21:26:54.357463668Z","hostname":"w-01J2CP58F0HWTMECWTSGW2EZ6Y","pid":1218,"client":"2","":"downstairs","session_id":"da99c0e3-514a-469b-ab48-be803ae4773a"} {"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-07-09T21:26:54.357718846Z","hostname":"w-01J2CP58F0HWTMECWTSGW2EZ6Y","pid":1218,"client":"1","":"downstairs","session_id":"da99c0e3-514a-469b-ab48-be803ae4773a"} {"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-07-09T21:26:54.357758349Z","hostname":"w-01J2CP58F0HWTMECWTSGW2EZ6Y","pid":1218,"client":"2","":"downstairs","session_id":"da99c0e3-514a-469b-ab48-be803ae4773a"} {"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-07-09T21:26:54.357773127Z","hostname":"w-01J2CP58F0HWTMECWTSGW2EZ6Y","pid":1218,"client":"0","":"downstairs","session_id":"da99c0e3-514a-469b-ab48-be803ae4773a"} {"msg":"ds_transition from WaitActive to WaitQuorum","v":0,"name":"crucible","level":30,"time":"2024-07-09T21:26:54.363115175Z","hostname":"w-01J2CP58F0HWTMECWTSGW2EZ6Y","pid":1218,"client":"0","":"downstairs","session_id":"da99c0e3-514a-469b-ab48-be803ae4773a"} {"msg":"[0] Transition from WaitActive to WaitQuorum","v":0,"name":"crucible","level":30,"time":"2024-07-09T21:26:54.363136332Z","hostname":"w-01J2CP58F0HWTMECWTSGW2EZ6Y","pid":1218,"client":"0","":"downstairs","session_id":"da99c0e3-514a-469b-ab48-be803ae4773a"} {"msg":"Waiting for more clients to be ready","v":0,"name":"crucible","level":30,"time":"2024-07-09T21:26:54.36314192Z","hostname":"w-01J2CP58F0HWTMECWTSGW2EZ6Y","pid":1218,"session_id":"da99c0e3-514a-469b-ab48-be803ae4773a"} {"msg":"ds_transition from WaitActive to WaitQuorum","v":0,"name":"crucible","level":30,"time":"2024-07-09T21:26:54.364263503Z","hostname":"w-01J2CP58F0HWTMECWTSGW2EZ6Y","pid":1218,"client":"1","":"downstairs","session_id":"da99c0e3-514a-469b-ab48-be803ae4773a"} {"msg":"[1] Transition from WaitActive to WaitQuorum","v":0,"name":"crucible","level":30,"time":"2024-07-09T21:26:54.364278051Z","hostname":"w-01J2CP58F0HWTMECWTSGW2EZ6Y","pid":1218,"client":"1","":"downstairs","session_id":"da99c0e3-514a-469b-ab48-be803ae4773a"} {"msg":"Waiting for more clients to be ready","v":0,"name":"crucible","level":30,"time":"2024-07-09T21:26:54.36428271Z","hostname":"w-01J2CP58F0HWTMECWTSGW2EZ6Y","pid":1218,"session_id":"da99c0e3-514a-469b-ab48-be803ae4773a"} {"msg":"ds_transition from WaitActive to WaitQuorum","v":0,"name":"crucible","level":30,"time":"2024-07-09T21:26:54.364412728Z","hostname":"w-01J2CP58F0HWTMECWTSGW2EZ6Y","pid":1218,"client":"2","":"downstairs","session_id":"da99c0e3-514a-469b-ab48-be803ae4773a"} {"msg":"[2] Transition from WaitActive to WaitQuorum","v":0,"name":"crucible","level":30,"time":"2024-07-09T21:26:54.364425436Z","hostname":"w-01J2CP58F0HWTMECWTSGW2EZ6Y","pid":1218,"client":"2","":"downstairs","session_id":"da99c0e3-514a-469b-ab48-be803ae4773a"} {"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-07-09T21:26:54.364429976Z","hostname":"w-01J2CP58F0HWTMECWTSGW2EZ6Y","pid":1218,"":"downstairs","":"downstairs","session_id":"da99c0e3-514a-469b-ab48-be803ae4773a"} {"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-07-09T21:26:54.364434485Z","hostname":"w-01J2CP58F0HWTMECWTSGW2EZ6Y","pid":1218,"":"downstairs","":"downstairs","session_id":"da99c0e3-514a-469b-ab48-be803ae4773a"} {"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-07-09T21:26:54.364440634Z","hostname":"w-01J2CP58F0HWTMECWTSGW2EZ6Y","pid":1218,"":"downstairs","":"downstairs","session_id":"da99c0e3-514a-469b-ab48-be803ae4773a"} {"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-07-09T21:26:54.364444933Z","hostname":"w-01J2CP58F0HWTMECWTSGW2EZ6Y","pid":1218,"":"downstairs","":"downstairs","session_id":"da99c0e3-514a-469b-ab48-be803ae4773a"} {"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-07-09T21:26:54.364449222Z","hostname":"w-01J2CP58F0HWTMECWTSGW2EZ6Y","pid":1218,"":"downstairs","":"downstairs","session_id":"da99c0e3-514a-469b-ab48-be803ae4773a"} {"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-07-09T21:26:54.364453692Z","hostname":"w-01J2CP58F0HWTMECWTSGW2EZ6Y","pid":1218,"":"downstairs","":"downstairs","session_id":"da99c0e3-514a-469b-ab48-be803ae4773a"} {"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-07-09T21:26:54.364457751Z","hostname":"w-01J2CP58F0HWTMECWTSGW2EZ6Y","pid":1218,"":"downstairs","":"downstairs","session_id":"da99c0e3-514a-469b-ab48-be803ae4773a"} {"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-07-09T21:26:54.3644619Z","hostname":"w-01J2CP58F0HWTMECWTSGW2EZ6Y","pid":1218,"":"downstairs","":"downstairs","session_id":"da99c0e3-514a-469b-ab48-be803ae4773a"} {"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-07-09T21:26:54.36446625Z","hostname":"w-01J2CP58F0HWTMECWTSGW2EZ6Y","pid":1218,"":"downstairs","":"downstairs","session_id":"da99c0e3-514a-469b-ab48-be803ae4773a"} {"msg":"Max found gen is 1","v":0,"name":"crucible","level":30,"time":"2024-07-09T21:26:54.364470409Z","hostname":"w-01J2CP58F0HWTMECWTSGW2EZ6Y","pid":1218,"":"downstairs","":"downstairs","session_id":"da99c0e3-514a-469b-ab48-be803ae4773a"} {"msg":"Generation requested: 1 >= found:1","v":0,"name":"crucible","level":30,"time":"2024-07-09T21:26:54.364481837Z","hostname":"w-01J2CP58F0HWTMECWTSGW2EZ6Y","pid":1218,"":"downstairs","":"downstairs","session_id":"da99c0e3-514a-469b-ab48-be803ae4773a"} {"msg":"Next flush: 1","v":0,"name":"crucible","level":30,"time":"2024-07-09T21:26:54.364486236Z","hostname":"w-01J2CP58F0HWTMECWTSGW2EZ6Y","pid":1218,"":"downstairs","":"downstairs","session_id":"da99c0e3-514a-469b-ab48-be803ae4773a"} {"msg":"All extents match","v":0,"name":"crucible","level":30,"time":"2024-07-09T21:26:54.364490555Z","hostname":"w-01J2CP58F0HWTMECWTSGW2EZ6Y","pid":1218,"":"downstairs","":"downstairs","session_id":"da99c0e3-514a-469b-ab48-be803ae4773a"} {"msg":"No downstairs reconciliation required","v":0,"name":"crucible","level":30,"time":"2024-07-09T21:26:54.364494975Z","hostname":"w-01J2CP58F0HWTMECWTSGW2EZ6Y","pid":1218,"session_id":"da99c0e3-514a-469b-ab48-be803ae4773a"} {"msg":"Transition from WaitQuorum to Active","v":0,"name":"crucible","level":30,"time":"2024-07-09T21:26:54.364498684Z","hostname":"w-01J2CP58F0HWTMECWTSGW2EZ6Y","pid":1218,"client":"0","":"downstairs","session_id":"da99c0e3-514a-469b-ab48-be803ae4773a"} {"msg":"Transition from WaitQuorum to Active","v":0,"name":"crucible","level":30,"time":"2024-07-09T21:26:54.364502773Z","hostname":"w-01J2CP58F0HWTMECWTSGW2EZ6Y","pid":1218,"client":"1","":"downstairs","session_id":"da99c0e3-514a-469b-ab48-be803ae4773a"} {"msg":"Transition from WaitQuorum to Active","v":0,"name":"crucible","level":30,"time":"2024-07-09T21:26:54.364506823Z","hostname":"w-01J2CP58F0HWTMECWTSGW2EZ6Y","pid":1218,"client":"2","":"downstairs","session_id":"da99c0e3-514a-469b-ab48-be803ae4773a"} {"msg":"All required reconciliation work is completed","v":0,"name":"crucible","level":30,"time":"2024-07-09T21:26:54.364511582Z","hostname":"w-01J2CP58F0HWTMECWTSGW2EZ6Y","pid":1218,"session_id":"da99c0e3-514a-469b-ab48-be803ae4773a"} {"msg":"Set Downstairs and Upstairs active after reconciliation","v":0,"name":"crucible","level":30,"time":"2024-07-09T21:26:54.364515181Z","hostname":"w-01J2CP58F0HWTMECWTSGW2EZ6Y","pid":1218,"session_id":"da99c0e3-514a-469b-ab48-be803ae4773a"} {"msg":"fed7e0d7-d541-4f58-8485-8372ecf9b991 is now active with session: da99c0e3-514a-469b-ab48-be803ae4773a","v":0,"name":"crucible","level":30,"time":"2024-07-09T21:26:54.364518811Z","hostname":"w-01J2CP58F0HWTMECWTSGW2EZ6Y","pid":1218,"session_id":"da99c0e3-514a-469b-ab48-be803ae4773a"} {"msg":"Set Active after no reconciliation","v":0,"name"Wait for a query_work_queue command to finish before sending IO :"crucible","level":30,"time":"2024-07-09T21:26:54.36452572Z","hostname":"w-01J2CP58F0HWTMECWTSGW2EZ6Y","pid":1218,"session_id":"da99c0e3-514a-469b-ab48-be803ae4773a"} {"msg":"The guest has finished waiting for activation with:1","v":0,"name":"crucible","level":30,"time":"2024-07-09T21:26:54.364529599Z","hostname":"w-01J2CP58F0HWTMECWTSGW2EZ6Y","pid":1218} 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.34 30000 1 3597.92 0.00028 0.00121 0.00196 0.04181 16384 1280 rwrites 8.32 30000 1 3605.06 0.00028 0.00120 0.00168 0.05841 16384 1280 rreads 5.52 30000 1 5437.70 0.00018 0.00022 0.00026 0.01540 16384 1280 rreads 5.54 30000 1 5411.28 0.00018 0.00023 0.00027 0.01551 16384 1280 Perf test finished on July 9, 2024 at 09:27:29 PM UTC