Perf test begins at September 27, 2024 at 03:51:53 AM UTC A new loop begins at September 27, 2024 at 03:52:00 AM 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":"look at: http://127.0.0.1:12810 ","v":0,"name":"crucible","level":30,"time":"2024-09-27T03:52:00.529026971Z","hostname":"w-01J8RSMQGNSRRS0N32D4380J4D","pid":1191,"task":"crutest"} {"msg":"RI is: RegionDefinition { block_size: 4096, extent_size: Block { value: 16384, shift: 12 }, extent_count: 640, uuid: 12345678-0000-0000-0000-000000008810, encrypted: false, database_read_version: 1, database_write_version: 1 }","v":0,"name":"crucible","level":30,"time":"2024-09-27T03:52:00.569875271Z","hostname":"w-01J8RSMQGNSRRS0N32D4380J4D","pid":1191,"task":"crutest"} {"msg":"Upstairs starts","v":0,"name":"crucible","level":30,"time":"2024-09-27T03:52:00.570424972Z","hostname":"w-01J8RSMQGNSRRS0N32D4380J4D","pid":1191} {"msg":"Crucible Version: BuildInfo {\n version: \"0.0.1\",\n git_sha: \"6901b9ee7172d672adc2780a2da758752eb0a2a4\",\n git_commit_timestamp: \"2024-09-27T03:30:33.000000000Z\",\n git_branch: \"alan/more-dsc-for-tests\",\n rustc_semver: \"1.80.0\",\n rustc_channel: \"stable\",\n rustc_host_triple: \"x86_64-unknown-illumos\",\n rustc_commit_sha: \"051478957371ee0084a7c0913941d2a8c4757bb9\",\n cargo_triple: \"x86_64-unknown-illumos\",\n debug: false,\n opt_level: 3,\n}","v":0,"name":"crucible","level":30,"time":"2024-09-27T03:52:00.570448685Z","hostname":"w-01J8RSMQGNSRRS0N32D4380J4D","pid":1191} {"msg":"Upstairs <-> Downstairs Message Version: 11","v":0,"name":"crucible","level":30,"time":"2024-09-27T03:52:00.570455075Z","hostname":"w-01J8RSMQGNSRRS0N32D4380J4D","pid":1191} {"msg":"Using region definition RegionDefinition { block_size: 4096, extent_size: Block { value: 16384, shift: 12 }, extent_count: 640, uuid: 00000000-0000-0000-0000-000000000000, encrypted: false, database_read_version: 1, database_write_version: 1 }","v":0,"name":"crucible","level":30,"time":"2024-09-27T03:52:00.570461216Z","hostname":"w-01J8RSMQGNSRRS0N32D4380J4D","pid":1191} {"msg":"Crucible de5ce9e6-16e1-4f31-910e-bc253fa1a790 has session id: b4ee0f08-0dc3-4b92-b45f-dcaac4e244c5","v":0,"name":"crucible","level":30,"time":"2024-09-27T03:52:00.570942099Z","hostname":"w-01J8RSMQGNSRRS0N32D4380J4D","pid":1191,"session_id":"b4ee0f08-0dc3-4b92-b45f-dcaac4e244c5"} {"msg":"Upstairs opts: Upstairs UUID: de5ce9e6-16e1-4f31-910e-bc253fa1a790, 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-09-27T03:52:00.570984464Z","hostname":"w-01J8RSMQGNSRRS0N32D4380J4D","pid":1191,"session_id":"b4ee0f08-0dc3-4b92-b45f-dcaac4e244c5"} {"msg":"Crucible stats registered with UUID: de5ce9e6-16e1-4f31-910e-bc253fa1a790","v":0,"name":"crucible","level":30,"time":"2024-09-27T03:52:00.570999136Z","hostname":"w-01J8RSMQGNSRRS0N32D4380J4D","pid":1191,"session_id":"b4ee0f08-0dc3-4b92-b45f-dcaac4e244c5"} {"msg":"The guest has requested activation with gen:1","v":0,"name":"crucible","level":30,"time":"2024-09-27T03:52:00.601119466Z","hostname":"w-01J8RSMQGNSRRS0N32D4380J4D","pid":1191} {"msg":"de5ce9e6-16e1-4f31-910e-bc253fa1a790 active request set","v":0,"name":"crucible","level":30,"time":"2024-09-27T03:52:00.601141049Z","hostname":"w-01J8RSMQGNSRRS0N32D4380J4D","pid":1191,"session_id":"b4ee0f08-0dc3-4b92-b45f-dcaac4e244c5"} {"msg":"sending connect oneshot to client","v":0,"name":"crucible","level":30,"time":"2024-09-27T03:52:00.601147639Z","hostname":"w-01J8RSMQGNSRRS0N32D4380J4D","pid":1191,"client":"0","":"downstairs","session_id":"b4ee0f08-0dc3-4b92-b45f-dcaac4e244c5"} {"msg":"client set_active_request while in New; waiting...","v":0,"name":"crucible","level":30,"time":"2024-09-27T03:52:00.601189184Z","hostname":"w-01J8RSMQGNSRRS0N32D4380J4D","pid":1191,"client":"0","":"downstairs","session_id":"b4ee0f08-0dc3-4b92-b45f-dcaac4e244c5"} {"msg":"sending connect oneshot to client","v":0,"name":"crucible","level":30,"time":"2024-09-27T03:52:00.601195875Z","hostname":"w-01J8RSMQGNSRRS0N32D4380J4D","pid":1191,"client":"1","":"downstairs","session_id":"b4ee0f08-0dc3-4b92-b45f-dcaac4e244c5"} {"msg":"client set_active_request while in New; waiting...","v":0,"name":"crucible","level":30,"time":"2024-09-27T03:52:00.601201745Z","hostname":"w-01J8RSMQGNSRRS0N32D4380J4D","pid":1191,"client":"1","":"downstairs","session_id":"b4ee0f08-0dc3-4b92-b45f-dcaac4e244c5"} {"msg":"sending connect oneshot to client","v":0,"name":"crucible","level":30,"time":"2024-09-27T03:52:00.601207196Z","hostname":"w-01J8RSMQGNSRRS0N32D4380J4D","pid":1191,"client":"2","":"downstairs","session_id":"b4ee0f08-0dc3-4b92-b45f-dcaac4e244c5"} {"msg":"client set_active_request while in New; waiting...","v":0,"name":"crucible","level":30,"time":"2024-09-27T03:52:00.601213377Z","hostname":"w-01J8RSMQGNSRRS0N32D4380J4D","pid":1191,"client":"2","":"downstairs","session_id":"b4ee0f08-0dc3-4b92-b45f-dcaac4e244c5"} {"msg":"connecting to 127.0.0.1:8830","v":0,"name":"crucible","level":30,"time":"2024-09-27T03:52:00.601313028Z","hostname":"w-01J8RSMQGNSRRS0N32D4380J4D","pid":1191,"":"io task","client":"2","":"downstairs","session_id":"b4ee0f08-0dc3-4b92-b45f-dcaac4e244c5"} {"msg":"connecting to 127.0.0.1:8810","v":0,"name":"crucible","level":30,"time":"2024-09-27T03:52:00.601330179Z","hostname":"w-01J8RSMQGNSRRS0N32D4380J4D","pid":1191,"":"io task","client":"0","":"downstairs","session_id":"b4ee0f08-0dc3-4b92-b45f-dcaac4e244c5"} {"msg":"connecting to 127.0.0.1:8820","v":0,"name":"crucible","level":30,"time":"2024-09-27T03:52:00.60133624Z","hostname":"w-01J8RSMQGNSRRS0N32D4380J4D","pid":1191,"":"io task","client":"1","":"downstairs","session_id":"b4ee0f08-0dc3-4b92-b45f-dcaac4e244c5"} {"msg":"ds_connection connected from Ok(127.0.0.1:44691)","v":0,"name":"crucible","level":30,"time":"2024-09-27T03:52:00.601447252Z","hostname":"w-01J8RSMQGNSRRS0N32D4380J4D","pid":1191,"":"io task","client":"0","":"downstairs","session_id":"b4ee0f08-0dc3-4b92-b45f-dcaac4e244c5"} {"msg":"ds_connection connected from Ok(127.0.0.1:39520)","v":0,"name":"crucible","level":30,"time":"2024-09-27T03:52:00.601470985Z","hostname":"w-01J8RSMQGNSRRS0N32D4380J4D","pid":1191,"":"io task","client":"2","":"downstairs","session_id":"b4ee0f08-0dc3-4b92-b45f-dcaac4e244c5"} {"msg":"ds_connection connected from Ok(127.0.0.1:39028)","v":0,"name":"crucible","level":30,"time":"2024-09-27T03:52:00.601479596Z","hostname":"w-01J8RSMQGNSRRS0N32D4380J4D","pid":1191,"":"io task","client":"1","":"downstairs","session_id":"b4ee0f08-0dc3-4b92-b45f-dcaac4e244c5"} {"msg":"ds_transition from New to WaitActive","v":0,"name":"crucible","level":30,"time":"2024-09-27T03:52:00.601971941Z","hostname":"w-01J8RSMQGNSRRS0N32D4380J4D","pid":1191,"client":"0","":"downstairs","session_id":"b4ee0f08-0dc3-4b92-b45f-dcaac4e244c5"} {"msg":"[0] Transition from New to WaitActive","v":0,"name":"crucible","level":30,"time":"2024-09-27T03:52:00.602033788Z","hostname":"w-01J8RSMQGNSRRS0N32D4380J4D","pid":1191,"client":"0","":"downstairs","session_id":"b4ee0f08-0dc3-4b92-b45f-dcaac4e244c5"} {"msg":"ds_transition from New to WaitActive","v":0,"name":"crucible","level":30,"time":"2024-09-27T03:52:00.602045169Z","hostname":"w-01J8RSMQGNSRRS0N32D4380J4D","pid":1191,"client":"1","":"downstairs","session_id":"b4ee0f08-0dc3-4b92-b45f-dcaac4e244c5"} {"msg":"[1] Transition from New to WaitActive","v":0,"name":"crucible","level":30,"time":"2024-09-27T03:52:00.602055Z","hostname":"w-01J8RSMQGNSRRS0N32D4380J4D","pid":1191,"client":"1","":"downstairs","session_id":"b4ee0f08-0dc3-4b92-b45f-dcaac4e244c5"} {"msg":"ds_transition from New to WaitActive","v":0,"name":"crucible","level":30,"time":"2024-09-27T03:52:00.602065931Z","hostname":"w-01J8RSMQGNSRRS0N32D4380J4D","pid":1191,"client":"2","":"downstairs","session_id":"b4ee0f08-0dc3-4b92-b45f-dcaac4e244c5"} {"msg":"[2] Transition from New to WaitActive","v":0,"name":"crucible","level":30,"time":"2024-09-27T03:52:00.602075312Z","hostname":"w-01J8RSMQGNSRRS0N32D4380J4D","pid":1191,"client":"2","":"downstairs","session_id":"b4ee0f08-0dc3-4b92-b45f-dcaac4e244c5"} {"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-09-27T03:52:00.602194205Z","hostname":"w-01J8RSMQGNSRRS0N32D4380J4D","pid":1191,"client":"0","":"downstairs","session_id":"b4ee0f08-0dc3-4b92-b45f-dcaac4e244c5"} {"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-09-27T03:52:00.60223143Z","hostname":"w-01J8RSMQGNSRRS0N32D4380J4D","pid":1191,"client":"1","":"downstairs","session_id":"b4ee0f08-0dc3-4b92-b45f-dcaac4e244c5"} {"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-09-27T03:52:00.60232421Z","hostname":"w-01J8RSMQGNSRRS0N32D4380J4D","pid":1191,"client":"2","":"downstairs","session_id":"b4ee0f08-0dc3-4b92-b45f-dcaac4e244c5"} {"msg":"ds_transition from WaitActive to WaitQuorum","v":0,"name":"crucible","level":30,"time":"2024-09-27T03:52:00.604386749Z","hostname":"w-01J8RSMQGNSRRS0N32D4380J4D","pid":1191,"client":"0","":"downstairs","session_id":"b4ee0f08-0dc3-4b92-b45f-dcaac4e244c5"} {"msg":"[0] Transition from WaitActive to WaitQuorum","v":0,"name":"crucible","level":30,"time":"2024-09-27T03:52:00.604429393Z","hostname":"w-01J8RSMQGNSRRS0N32D4380J4D","pid":1191,"client":"0","":"downstairs","session_id":"b4ee0f08-0dc3-4b92-b45f-dcaac4e244c5"} {"msg":"Waiting for more clients to be ready","v":0,"name":"crucible","level":30,"time":"2024-09-27T03:52:00.604450576Z","hostname":"w-01J8RSMQGNSRRS0N32D4380J4D","pid":1191,"session_id":"b4ee0f08-0dc3-4b92-b45f-dcaac4e244c5"} {"msg":"ds_transition from WaitActive to WaitQuorum","v":0,"name":"crucible","level":30,"time":"2024-09-27T03:52:00.604509552Z","hostname":"w-01J8RSMQGNSRRS0N32D4380J4D","pid":1191,"client":"1","":"downstairs","session_id":"b4ee0f08-0dc3-4b92-b45f-dcaac4e244c5"} {"msg":"[1] Transition from WaitActive to WaitQuorum","v":0,"name":"crucible","level":30,"time":"2024-09-27T03:52:00.604523044Z","hostname":"w-01J8RSMQGNSRRS0N32D4380J4D","pid":1191,"client":"1","":"downstairs","session_id":"b4ee0f08-0dc3-4b92-b45f-dcaac4e244c5"} {"msg":"Waiting for more clients to be ready","v":0,"name":"crucible","level":30,"time":"2024-09-27T03:52:00.604527624Z","hostname":"w-01J8RSMQGNSRRS0N32D4380J4D","pid":1191,"session_id":"b4ee0f08-0dc3-4b92-b45f-dcaac4e244c5"} {"msg":"ds_transition from WaitActive to WaitQuorum","v":0,"name":"crucible","level":30,"time":"2024-09-27T03:52:00.604845019Z","hostname":"w-01J8RSMQGNSRRS0N32D4380J4D","pid":1191,"client":"2","":"downstairs","session_id":"b4ee0f08-0dc3-4b92-b45f-dcaac4e244c5"} {"msg":"[2] Transition from WaitActive to WaitQuorum","v":0,"name":"crucible","level":30,"time":"2024-09-27T03:52:00.604857401Z","hostname":"w-01J8RSMQGNSRRS0N32D4380J4D","pid":1191,"client":"2","":"downstairs","session_id":"b4ee0f08-0dc3-4b92-b45f-dcaac4e244c5"} {"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-09-27T03:52:00.604862421Z","hostname":"w-01J8RSMQGNSRRS0N32D4380J4D","pid":1191,"":"downstairs","":"downstairs","session_id":"b4ee0f08-0dc3-4b92-b45f-dcaac4e244c5"} {"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-09-27T03:52:00.604868022Z","hostname":"w-01J8RSMQGNSRRS0N32D4380J4D","pid":1191,"":"downstairs","":"downstairs","session_id":"b4ee0f08-0dc3-4b92-b45f-dcaac4e244c5"} {"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-09-27T03:52:00.604872872Z","hostname":"w-01J8RSMQGNSRRS0N32D4380J4D","pid":1191,"":"downstairs","":"downstairs","session_id":"b4ee0f08-0dc3-4b92-b45f-dcaac4e244c5"} {"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-09-27T03:52:00.604877723Z","hostname":"w-01J8RSMQGNSRRS0N32D4380J4D","pid":1191,"":"downstairs","":"downstairs","session_id":"b4ee0f08-0dc3-4b92-b45f-dcaac4e244c5"} {"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-09-27T03:52:00.604881953Z","hostname":"w-01J8RSMQGNSRRS0N32D4380J4D","pid":1191,"":"downstairs","":"downstairs","session_id":"b4ee0f08-0dc3-4b92-b45f-dcaac4e244c5"} {"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-09-27T03:52:00.604886304Z","hostname":"w-01J8RSMQGNSRRS0N32D4380J4D","pid":1191,"":"downstairs","":"downstairs","session_id":"b4ee0f08-0dc3-4b92-b45f-dcaac4e244c5"} {"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-09-27T03:52:00.604890514Z","hostname":"w-01J8RSMQGNSRRS0N32D4380J4D","pid":1191,"":"downstairs","":"downstairs","session_id":"b4ee0f08-0dc3-4b92-b45f-dcaac4e244c5"} {"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-09-27T03:52:00.604895225Z","hostname":"w-01J8RSMQGNSRRS0N32D4380J4D","pid":1191,"":"downstairs","":"downstairs","session_id":"b4ee0f08-0dc3-4b92-b45f-dcaac4e244c5"} {"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-09-27T03:52:00.604899495Z","hostname":"w-01J8RSMQGNSRRS0N32D4380J4D","pid":1191,"":"downstairs","":"downstairs","session_id":"b4ee0f08-0dc3-4b92-b45f-dcaac4e244c5"} {"msg":"Max found gen is 1","v":0,"name":"crucible","level":30,"time":"2024-09-27T03:52:00.604903646Z","hostname":"w-01J8RSMQGNSRRS0N32D4380J4D","pid":1191,"":"downstairs","":"downstairs","session_id":"b4ee0f08-0dc3-4b92-b45f-dcaac4e244c5"} {"msg":"Generation requested: 1 >= found:1","v":0,"name":"crucible","level":30,"time":"2024-09-27T03:52:00.604908416Z","hostname":"w-01J8RSMQGNSRRS0N32D4380J4D","pid":1191,"":"downstairs","":"downstairs","session_id":"b4ee0f08-0dc3-4b92-b45f-dcaac4e244c5"} {"msg":"Next flush: 1","v":0,"name":"crucible","level":30,"time":"2024-09-27T03:52:00.604912527Z","hostname":"w-01J8RSMQGNSRRS0N32D4380J4D","pid":1191,"":"downstairs","":"downstairs","session_id":"b4ee0f08-0dc3-4b92-b45f-dcaac4e244c5"} {"msg":"All extents match","v":0,"name":"crucible","level":30,"time":"2024-09-27T03:52:00.604916577Z","hostname":"w-01J8RSMQGNSRRS0N32D4380J4D","pid":1191,"":"downstairs","":"downstairs","session_id":"b4ee0f08-0dc3-4b92-b45f-dcaac4e244c5"} {"msg":"No downstairs reconciliation required","v":0,"name":"crucible","level":30,"time":"2024-09-27T03:52:00.604920798Z","hostname":"w-01J8RSMQGNSRRS0N32D4380J4D","pid":1191,"session_id":"b4ee0f08-0dc3-4b92-b45f-dcaac4e244c5"} {"msg":"Transition from WaitQuorum to Active","v":0,"name":"crucible","level":30,"time":"2024-09-27T03:52:00.604931369Z","hostname":"w-01J8RSMQGNSRRS0N32D4380J4D","pid":1191,"client":"0","":"downstairs","session_id":"b4ee0f08-0dc3-4b92-b45f-dcaac4e244c5"} {"msg":"Transition from WaitQuorum to Active","v":0,"name":"crucible","level":30,"time":"2024-09-27T03:52:00.604935569Z","hostname":"w-01J8RSMQGNSRRS0N32D4380J4D","pid":1191,"client":"1","":"downstairs","session_id":"b4ee0f08-0dc3-4b92-b45f-dcaac4e244c5"} {"msg":"Transition from WaitQuorum to Active","v":0,"name":"crucible","level":30,"time":"2024-09-27T03:52:00.60493964Z","hostname":"w-01J8RSMQGNSRRS0N32D4380J4D","pid":1191,"client":"2","":"downstairs","session_id":"b4ee0f08-0dc3-4b92-b45f-dcaac4e244c5"} {"msg":"All required reconciliation work is completed","v":0,"name":"crucible","level":30,"time":"2024-09-27T03:52:00.60494385Z","hostname":"w-01J8RSMQGNSRRS0N32D4380J4D","pid":1191,"session_id":"b4ee0f08-0dc3-4b92-b45f-dcaac4e244c5"} {"msg":"Set Downstairs and Upstairs active after reconciliation","v":0,"name":"crucible","level":30,"time":"2024-09-27T03:52:00.604947431Z","hostname":"w-01J8RSMQGNSRRS0N32D4380J4D","pid":1191,"session_id":"b4ee0f08-0dc3-4b92-b45f-dcaac4e244c5"} {"msg":"de5ce9e6-16e1-4f31-910e-bc253fa1a790 is now active with session: b4ee0f08-0dc3-4b92-b45f-dcaac4e244c5","v":0,"name":"crucible","level":30,"time":"2024-09-27T03:52:00.604951571Z","hostname":"w-01J8RSMQGNSRRS0N32D4380J4D","pid":1191,"session_id":"b4ee0f08-0dc3-4b92-b45f-dcaac4e244c5"} {"msg":"Set Active after no reconciliation","v":0,"name":"crucible","level":30,"time":"2024-09-27T03:52:00.604955141Z","hostname":"w-01J8RSMQGNSRRS0N32D4380J4D","pid":1191,"session_id":"b4ee0f08-0dc3-4b92-b45f-dcaac4e244c5"} {"msg":"The guest has finished waiting for activation with:1","v":0,"name":"crucible","level":30,"time":"2024-09-27T03:52:00.604958662Z","hostname":"w-01J8RSMQGNSRRS0N32D4380J4D","pid":1191} Wait for a query_work_queue command to finish before sending IO region info: block size: 4096 bytes sub_volume 0 blocks / extent: 16384 sub_volume 0 extent size: 64 MiB sub_volume 0 extent count: 640 total blocks: 10485760 total size: 40 GiB encryption: no Perf test TEST SECONDS COUNT DPTH IOPS MEAN P95 P99 MAX ES EC rwrites 5.51 30000 1 5449.28 0.00018 0.00048 0.00124 0.08646 16384 640 rwrites 5.61 30000 1 5344.62 0.00019 0.00068 0.00128 0.06670 16384 640 rreads 5.42 30000 1 5536.32 0.00018 0.00023 0.00028 0.00581 16384 640 rreads 5.39 30000 1 5570.63 0.00018 0.00023 0.00028 0.00591 16384 640 A new loop begins at September 27, 2024 at 03:52:34 AM 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":"look at: http://127.0.0.1:12810 ","v":0,"name":"crucible","level":30,"time":"2024-09-27T03:52:34.649961586Z","hostname":"w-01J8RSMQGNSRRS0N32D4380J4D","pid":1210,"task":"crutest"} {"msg":"RI is: RegionDefinition { block_size: 4096, extent_size: Block { value: 16384, shift: 12 }, extent_count: 1280, uuid: 12345678-0000-0000-0000-000000008810, encrypted: false, database_read_version: 1, database_write_version: 1 }","v":0,"name":"crucible","level":30,"time":"2024-09-27T03:52:34.688923087Z","hostname":"w-01J8RSMQGNSRRS0N32D4380J4D","pid":1210,"task":"crutest"} {"msg":"Upstairs starts","v":0,"name":"crucible","level":30,"time":"2024-09-27T03:52:34.689342223Z","hostname":"w-01J8RSMQGNSRRS0N32D4380J4D","pid":1210} {"msg":"Crucible Version: BuildInfo {\n version: \"0.0.1\",\n git_sha: \"6901b9ee7172d672adc2780a2da758752eb0a2a4\",\n git_commit_timestamp: \"2024-09-27T03:30:33.000000000Z\",\n git_branch: \"alan/more-dsc-for-tests\",\n rustc_semver: \"1.80.0\",\n rustc_channel: \"stable\",\n rustc_host_triple: \"x86_64-unknown-illumos\",\n rustc_commit_sha: \"051478957371ee0084a7c0913941d2a8c4757bb9\",\n cargo_triple: \"x86_64-unknown-illumos\",\n debug: false,\n opt_level: 3,\n}","v":0,"name":"crucible","level":30,"time":"2024-09-27T03:52:34.689365026Z","hostname":"w-01J8RSMQGNSRRS0N32D4380J4D","pid":1210} {"msg":"Upstairs <-> Downstairs Message Version: 11","v":0,"name":"crucible","level":30,"time":"2024-09-27T03:52:34.689371057Z","hostname":"w-01J8RSMQGNSRRS0N32D4380J4D","pid":1210} {"msg":"Using region definition RegionDefinition { block_size: 4096, extent_size: Block { value: 16384, shift: 12 }, extent_count: 1280, uuid: 00000000-0000-0000-0000-000000000000, encrypted: false, database_read_version: 1, database_write_version: 1 }","v":0,"name":"crucible","level":30,"time":"2024-09-27T03:52:34.689376237Z","hostname":"w-01J8RSMQGNSRRS0N32D4380J4D","pid":1210} {"msg":"Crucible 9987ea66-cb9a-44cb-bc43-3e7dced09c1c has session id: 4befd25c-75a8-40a6-aeb4-a50a9454b06e","v":0,"name":"crucible","level":30,"time":"2024-09-27T03:52:34.689754499Z","hostname":"w-01J8RSMQGNSRRS0N32D4380J4D","pid":1210,"session_id":"4befd25c-75a8-40a6-aeb4-a50a9454b06e"} {"msg":"Upstairs opts: Upstairs UUID: 9987ea66-cb9a-44cb-bc43-3e7dced09c1c, 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-09-27T03:52:34.689778302Z","hostname":"w-01J8RSMQGNSRRS0N32D4380J4D","pid":1210,"session_id":"4befd25c-75a8-40a6-aeb4-a50a9454b06e"} {"msg":"Crucible stats registered with UUID: 9987ea66-cb9a-44cb-bc43-3e7dced09c1c","v":0,"name":"crucible","level":30,"time":"2024-09-27T03:52:34.689784342Z","hostname":"w-01J8RSMQGNSRRS0N32D4380J4D","pid":1210,"session_id":"4befd25c-75a8-40a6-aeb4-a50a9454b06e"} {"msg":"The guest has requested activation with gen:1","v":0,"name":"crucible","level":30,"time":"2024-09-27T03:52:34.719947138Z","hostname":"w-01J8RSMQGNSRRS0N32D4380J4D","pid":1210} {"msg":"9987ea66-cb9a-44cb-bc43-3e7dced09c1c active request set","v":0,"name":"crucible","level":30,"time":"2024-09-27T03:52:34.71996976Z","hostname":"w-01J8RSMQGNSRRS0N32D4380J4D","pid":1210,"session_id":"4befd25c-75a8-40a6-aeb4-a50a9454b06e"} {"msg":"sending connect oneshot to client","v":0,"name":"crucible","level":30,"time":"2024-09-27T03:52:34.719976101Z","hostname":"w-01J8RSMQGNSRRS0N32D4380J4D","pid":1210,"client":"0","":"downstairs","session_id":"4befd25c-75a8-40a6-aeb4-a50a9454b06e"} {"msg":"client set_active_request while in New; waiting...","v":0,"name":"crucible","level":30,"time":"2024-09-27T03:52:34.719989022Z","hostname":"w-01J8RSMQGNSRRS0N32D4380J4D","pid":1210,"client":"0","":"downstairs","session_id":"4befd25c-75a8-40a6-aeb4-a50a9454b06e"} {"msg":"sending connect oneshot to client","v":0,"name":"crucible","level":30,"time":"2024-09-27T03:52:34.719995923Z","hostname":"w-01J8RSMQGNSRRS0N32D4380J4D","pid":1210,"client":"1","":"downstairs","session_id":"4befd25c-75a8-40a6-aeb4-a50a9454b06e"} {"msg":"client set_active_request while in New; waiting...","v":0,"name":"crucible","level":30,"time":"2024-09-27T03:52:34.720054169Z","hostname":"w-01J8RSMQGNSRRS0N32D4380J4D","pid":1210,"client":"1","":"downstairs","session_id":"4befd25c-75a8-40a6-aeb4-a50a9454b06e"} {"msg":"sending connect oneshot to client","v":0,"name":"crucible","level":30,"time":"2024-09-27T03:52:34.720087723Z","hostname":"w-01J8RSMQGNSRRS0N32D4380J4D","pid":1210,"client":"2","":"downstairs","session_id":"4befd25c-75a8-40a6-aeb4-a50a9454b06e"} {"msg":"client set_active_request while in New; waiting...","v":0,"name":"crucible","level":30,"time":"2024-09-27T03:52:34.720099385Z","hostname":"w-01J8RSMQGNSRRS0N32D4380J4D","pid":1210,"client":"2","":"downstairs","session_id":"4befd25c-75a8-40a6-aeb4-a50a9454b06e"} {"msg":"connecting to 127.0.0.1:8830","v":0,"name":"crucible","level":30,"time":"2024-09-27T03:52:34.720120427Z","hostname":"w-01J8RSMQGNSRRS0N32D4380J4D","pid":1210,"":"io task","client":"2","":"downstairs","session_id":"4befd25c-75a8-40a6-aeb4-a50a9454b06e"} {"msg":"connecting to 127.0.0.1:8820","v":0,"name":"crucible","level":30,"time":"2024-09-27T03:52:34.720131728Z","hostname":"w-01J8RSMQGNSRRS0N32D4380J4D","pid":1210,"":"io task","client":"1","":"downstairs","session_id":"4befd25c-75a8-40a6-aeb4-a50a9454b06e"} {"msg":"connecting to 127.0.0.1:8810","v":0,"name":"crucible","level":30,"time":"2024-09-27T03:52:34.720140769Z","hostname":"w-01J8RSMQGNSRRS0N32D4380J4D","pid":1210,"":"io task","client":"0","":"downstairs","session_id":"4befd25c-75a8-40a6-aeb4-a50a9454b06e"} {"msg":"ds_connection connected from Ok(127.0.0.1:63925)","v":0,"name":"crucible","level":30,"time":"2024-09-27T03:52:34.7201515Z","hostname":"w-01J8RSMQGNSRRS0N32D4380J4D","pid":1210,"":"io task","client":"2","":"downstairs","session_id":"4befd25c-75a8-40a6-aeb4-a50a9454b06e"} {"msg":"ds_connection connected from Ok(127.0.0.1:41783)","v":0,"name":"crucible","level":30,"time":"2024-09-27T03:52:34.720161601Z","hostname":"w-01J8RSMQGNSRRS0N32D4380J4D","pid":1210,"":"io task","client":"0","":"downstairs","session_id":"4befd25c-75a8-40a6-aeb4-a50a9454b06e"} {"msg":"ds_connection connected from Ok(127.0.0.1:58797)","v":0,"name":"crucible","level":30,"time":"2024-09-27T03:52:34.720171102Z","hostname":"w-01J8RSMQGNSRRS0N32D4380J4D","pid":1210,"":"io task","client":"1","":"downstairs","session_id":"4befd25c-75a8-40a6-aeb4-a50a9454b06e"} {"msg":"ds_transition from New to WaitActive","v":0,"name":"crucible","level":30,"time":"2024-09-27T03:52:34.720427221Z","hostname":"w-01J8RSMQGNSRRS0N32D4380J4D","pid":1210,"client":"0","":"downstairs","session_id":"4befd25c-75a8-40a6-aeb4-a50a9454b06e"} {"msg":"[0] Transition from New to WaitActive","v":0,"name":"crucible","level":30,"time":"2024-09-27T03:52:34.720450384Z","hostname":"w-01J8RSMQGNSRRS0N32D4380J4D","pid":1210,"client":"0","":"downstairs","session_id":"4befd25c-75a8-40a6-aeb4-a50a9454b06e"} {"msg":"ds_transition from New to WaitActive","v":0,"name":"crucible","level":30,"time":"2024-09-27T03:52:34.720458334Z","hostname":"w-01J8RSMQGNSRRS0N32D4380J4D","pid":1210,"client":"2","":"downstairs","session_id":"4befd25c-75a8-40a6-aeb4-a50a9454b06e"} {"msg":"[2] Transition from New to WaitActive","v":0,"name":"crucible","level":30,"time":"2024-09-27T03:52:34.720465045Z","hostname":"w-01J8RSMQGNSRRS0N32D4380J4D","pid":1210,"client":"2","":"downstairs","session_id":"4befd25c-75a8-40a6-aeb4-a50a9454b06e"} {"msg":"ds_transition from New to WaitActive","v":0,"name":"crucible","level":30,"time":"2024-09-27T03:52:34.720472356Z","hostname":"w-01J8RSMQGNSRRS0N32D4380J4D","pid":1210,"client":"1","":"downstairs","session_id":"4befd25c-75a8-40a6-aeb4-a50a9454b06e"} {"msg":"[1] Transition from New to WaitActive","v":0,"name":"crucible","level":30,"time":"2024-09-27T03:52:34.720479687Z","hostname":"w-01J8RSMQGNSRRS0N32D4380J4D","pid":1210,"client":"1","":"downstairs","session_id":"4befd25c-75a8-40a6-aeb4-a50a9454b06e"} {"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-09-27T03:52:34.720652466Z","hostname":"w-01J8RSMQGNSRRS0N32D4380J4D","pid":1210,"client":"0","":"downstairs","session_id":"4befd25c-75a8-40a6-aeb4-a50a9454b06e"} {"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-09-27T03:52:34.720663017Z","hostname":"w-01J8RSMQGNSRRS0N32D4380J4D","pid":1210,"client":"1","":"downstairs","session_id":"4befd25c-75a8-40a6-aeb4-a50a9454b06e"} {"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-09-27T03:52:34.720671408Z","hostname":"w-01J8RSMQGNSRRS0N32D4380J4D","pid":1210,"client":"2","":"downstairs","session_id":"4befd25c-75a8-40a6-aeb4-a50a9454b06e"} {"msg":"ds_transition from WaitActive to WaitQuorum","v":0,"name":"crucible","level":30,"time":"2024-09-27T03:52:34.72600558Z","hostname":"w-01J8RSMQGNSRRS0N32D4380J4D","pid":1210,"client":"2","":"downstairs","session_id":"4befd25c-75a8-40a6-aeb4-a50a9454b06e"} {"msg":"[2] Transition from WaitActive to WaitQuorum","v":0,"name":"crucible","level":30,"time":"2024-09-27T03:52:34.726026922Z","hostname":"w-01J8RSMQGNSRRS0N32D4380J4D","pid":1210,"client":"2","":"downstairs","session_id":"4befd25c-75a8-40a6-aeb4-a50a9454b06e"} {"msg":"Waiting for more clients to be ready","v":0,"name":"crucible","level":30,"time":"2024-09-27T03:52:34.726034453Z","hostname":"w-01J8RSMQGNSRRS0N32D4380J4D","pid":1210,"session_id":"4befd25c-75a8-40a6-aeb4-a50a9454b06e"} {"msg":"ds_transition from WaitActive to WaitQuorum","v":0,"name":"crucible","level":30,"time":"2024-09-27T03:52:34.726120952Z","hostname":"w-01J8RSMQGNSRRS0N32D4380J4D","pid":1210,"client":"1","":"downstairs","session_id":"4befd25c-75a8-40a6-aeb4-a50a9454b06e"} {"msg":"[1] Transition from WaitActive to WaitQuorum","v":0,"name":"crucible","level":30,"time":"2024-09-27T03:52:34.726139454Z","hostname":"w-01J8RSMQGNSRRS0N32D4380J4D","pid":1210,"client":"1","":"downstairs","session_id":"4befd25c-75a8-40a6-aeb4-a50a9454b06e"} {"msg":"Waiting for more clients to be ready","v":0,"name":"crucible","level":30,"time":"2024-09-27T03:52:34.726147535Z","hostname":"w-01J8RSMQGNSRRS0N32D4380J4D","pid":1210,"session_id":"4befd25c-75a8-40a6-aeb4-a50a9454b06e"} {"msg":"ds_transition from WaitActive to WaitQuorum","v":0,"name":"crucible","level":30,"time":"2024-09-27T03:52:34.726153836Z","hostname":"w-01J8RSMQGNSRRS0N32D4380J4D","pid":1210,"client":"0","":"downstairs","session_id":"4befd25c-75a8-40a6-aeb4-a50a9454b06e"} {"msg":"[0] Transition from WaitActive to WaitQuorum","v":0,"name":"crucible","level":30,"time":"2024-09-27T03:52:34.726161137Z","hostname":"w-01J8RSMQGNSRRS0N32D4380J4D","pid":1210,"client":"0","":"downstairs","session_id":"4befd25c-75a8-40a6-aeb4-a50a9454b06e"} {"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-09-27T03:52:34.726168978Z","hostname":"w-01J8RSMQGNSRRS0N32D4380J4D","pid":1210,"":"downstairs","":"downstairs","session_id":"4befd25c-75a8-40a6-aeb4-a50a9454b06e"} {"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-09-27T03:52:34.726176139Z","hostname":"w-01J8RSMQGNSRRS0N32D4380J4D","pid":1210,"":"downstairs","":"downstairs","session_id":"4befd25c-75a8-40a6-aeb4-a50a9454b06e"} {"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-09-27T03:52:34.726183339Z","hostname":"w-01J8RSMQGNSRRS0N32D4380J4D","pid":1210,"":"downstairs","":"downstairs","session_id":"4befd25c-75a8-40a6-aeb4-a50a9454b06e"} {"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-09-27T03:52:34.726198761Z","hostname":"w-01J8RSMQGNSRRS0N32D4380J4D","pid":1210,"":"downstairs","":"downstairs","session_id":"4befd25c-75a8-40a6-aeb4-a50a9454b06e"} {"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-09-27T03:52:34.726206322Z","hostname":"w-01J8RSMQGNSRRS0N32D4380J4D","pid":1210,"":"downstairs","":"downstairs","session_id":"4befd25c-75a8-40a6-aeb4-a50a9454b06e"} {"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-09-27T03:52:34.726214723Z","hostname":"w-01J8RSMQGNSRRS0N32D4380J4D","pid":1210,"":"downstairs","":"downstairs","session_id":"4befd25c-75a8-40a6-aeb4-a50a9454b06e"} {"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-09-27T03:52:34.726222033Z","hostname":"w-01J8RSMQGNSRRS0N32D4380J4D","pid":1210,"":"downstairs","":"downstairs","session_id":"4befd25c-75a8-40a6-aeb4-a50a9454b06e"} {"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-09-27T03:52:34.726229444Z","hostname":"w-01J8RSMQGNSRRS0N32D4380J4D","pid":1210,"":"downstairs","":"downstairs","session_id":"4befd25c-75a8-40a6-aeb4-a50a9454b06e"} {"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-09-27T03:52:34.726236685Z","hostname":"w-01J8RSMQGNSRRS0N32D4380J4D","pid":1210,"":"downstairs","":"downstairs","session_id":"4befd25c-75a8-40a6-aeb4-a50a9454b06e"} {"msg":"Max found gen is 1","v":0,"name":"crucible","level":30,"time":"2024-09-27T03:52:34.726244036Z","hostname":"w-01J8RSMQGNSRRS0N32D4380J4D","pid":1210,"":"downstairs","":"downstairs","session_id":"4befd25c-75a8-40a6-aeb4-a50a9454b06e"} {"msg":"Generation requested: 1 >= found:1","v":0,"name":"crucible","level":30,"time":"2024-09-27T03:52:34.726250887Z","hostname":"w-01J8RSMQGNSRRS0N32D4380J4D","pid":1210,"":"downstairs","":"downstairs","session_id":"4befd25c-75a8-40a6-aeb4-a50a9454b06e"} {"msg":"Next flush: 1","v":0,"name":"crucible","level":30,"time":"2024-09-27T03:52:34.726257968Z","hostname":"w-01J8RSMQGNSRRS0N32D4380J4D","pid":1210,"":"downstairs","":"downstairs","session_id":"4befd25c-75a8-40a6-aeb4-a50a9454b06e"} {"msg":"All extents match","v":0,"name":"crucible","level":30,"time":"2024-09-27T03:52:34.726265188Z","hostname":"w-01J8RSMQGNSRRS0N32D4380J4D","pid":1210,"":"downstairs","":"downstairs","session_id":"4befd25c-75a8-40a6-aeb4-a50a9454b06e"} {"msg":"No downstairs reconciliation required","v":0,"name":"crucible","level":30,"time":"2024-09-27T03:52:34.726272059Z","hostname":"w-01J8RSMQGNSRRS0N32D4380J4D","pid":1210,"session_id":"4befd25c-75a8-40a6-aeb4-a50a9454b06e"} {"msg":"Transition from WaitQuorum to Active","v":0,"name":"crucible","level":30,"time":"2024-09-27T03:52:34.72627804Z","hostname":"w-01J8RSMQGNSRRS0N32D4380J4D","pid":1210,"client":"0","":"downstairs","session_id":"4befd25c-75a8-40a6-aeb4-a50a9454b06e"} Wait for a query_work_queue command to finish before sending IO {"msg":"Transition from WaitQuorum to Active","v":0,"name":"crucible","level":30,"time":"2024-09-27T03:52:34.726294201Z","hostname":"w-01J8RSMQGNSRRS0N32D4380J4D","pid":1210,"client":"1","":"downstairs","session_id":"4befd25c-75a8-40a6-aeb4-a50a9454b06e"} {"msg":"Transition from WaitQuorum to Active","v":0,"name":"crucible","level":30,"time":"2024-09-27T03:52:34.726301242Z","hostname":"w-01J8RSMQGNSRRS0N32D4380J4D","pid":1210,"client":"2","":"downstairs","session_id":"4befd25c-75a8-40a6-aeb4-a50a9454b06e"} {"msg":"All required reconciliation work is completed","v":0,"name":"crucible","level":30,"time":"2024-09-27T03:52:34.726308723Z","hostname":"w-01J8RSMQGNSRRS0N32D4380J4D","pid":1210,"session_id":"4befd25c-75a8-40a6-aeb4-a50a9454b06e"} {"msg":"Set Downstairs and Upstairs active after reconciliation","v":0,"name":"crucible","level":30,"time":"2024-09-27T03:52:34.726314854Z","hostname":"w-01J8RSMQGNSRRS0N32D4380J4D","pid":1210,"session_id":"4befd25c-75a8-40a6-aeb4-a50a9454b06e"} {"msg":"9987ea66-cb9a-44cb-bc43-3e7dced09c1c is now active with session: 4befd25c-75a8-40a6-aeb4-a50a9454b06e","v":0,"name":"crucible","level":30,"time":"2024-09-27T03:52:34.726321084Z","hostname":"w-01J8RSMQGNSRRS0N32D4380J4D","pid":1210,"session_id":"4befd25c-75a8-40a6-aeb4-a50a9454b06e"} {"msg":"Set Active after no reconciliation","v":0,"name":"crucible","level":30,"time":"2024-09-27T03:52:34.726327325Z","hostname":"w-01J8RSMQGNSRRS0N32D4380J4D","pid":1210,"session_id":"4befd25c-75a8-40a6-aeb4-a50a9454b06e"} {"msg":"The guest has finished waiting for activation with:1","v":0,"name":"crucible","level":30,"time":"2024-09-27T03:52:34.726333426Z","hostname":"w-01J8RSMQGNSRRS0N32D4380J4D","pid":1210} region info: block size: 4096 bytes sub_volume 0 blocks / extent: 16384 sub_volume 0 extent size: 64 MiB sub_volume 0 extent count: 1280 total blocks: 20971520 total size: 80 GiB encryption: no Perf test TEST SECONDS COUNT DPTH IOPS MEAN P95 P99 MAX ES EC rwrites 6.91 30000 1 4340.33 0.00023 0.00115 0.00144 0.09528 16384 1280 rwrites 7.40 30000 1 4054.46 0.00025 0.00117 0.00152 0.07834 16384 1280 rreads 5.47 30000 1 5488.04 0.00018 0.00022 0.00028 0.01241 16384 1280 rreads 5.41 30000 1 5549.68 0.00018 0.00022 0.00027 0.01241 16384 1280 Perf test finished on September 27, 2024 at 03:53:03 AM UTC