/input/rbuild/work Create region with ES:16384 EC:640 BS:4096 Creating region directory at: /var/tmp/dsc Creating dsc directory at: /tmp/dsc Downstairs region 0 created at /var/tmp/dsc/8810 in 0.85678744 Downstairs region 1 created at /var/tmp/dsc/8820 in 0.6957866 Downstairs region 2 created at /var/tmp/dsc/8830 in 0.70346975 Created 3 regions Using existing output directory "/tmp/dsc" Update our region info with: Some(RegionExtentInfo { block_size: 4096, blocks_per_extent: 16384, extent_count: 640 }) start ds: 8810 start ds: 8820 start ds: 8830 start access at:127.0.0.1:9998 Starting downstairs at port 8820 Starting downstairs at port 8810 Starting downstairs at port 8830 Make output file at "/tmp/dsc/downstairs-8810.txt" Make output file at "/tmp/dsc/downstairs-8830.txt" [8820][1] initial start wait reports Starting Make output file at "/tmp/dsc/downstairs-8820.txt" [8810][0] initial start wait reports Starting [8830][2] initial start wait reports Starting Downstairs /var/tmp/dsc/8810 port 8810 PID:Some(1181) [8810][0] initial start wait reports Running Downstairs /var/tmp/dsc/8820 port 8820 PID:Some(1182) [8820][1] initial start wait reports Running Downstairs /var/tmp/dsc/8830 port 8830 PID:Some(1183) [8830][2] initial start wait reports Running All downstairs are running Sep 27 03:51:55.466 INFO listening, local_addr: 127.0.0.1:9998 Control access at:127.0.0.1:9998 1181 1182 1183 Sep 27 03:52:00.505 INFO accepted connection, remote_addr: 127.0.0.1:47993, local_addr: 127.0.0.1:9998 Main task has work to do, go find it got dsc DisableRestartAll disable restart on all: 3 Sep 27 03:52:00.506 INFO request completed, latency_us: 150[8810] Disable keep_running , [8830] Disable keep_running response_code: 204, uri: /disablerestart/all, method: POST, req_id: [8820] Disable keep_running 35349fbb-25e1-4e7e-8fa2-5053636874b5, remote_addr: 127.0.0.1:47993, local_addr: 127.0.0.1:9998 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 Perf test completed, stop all downstairs Sep 27 03:52:24.967 INFO accepted connection, remote_addr: 127.0.0.1:47752, local_addr: 127.0.0.1:9998 Main task has work to do, go find it got dsc Shutdown Shutdown Shut it down Sep 27 03:52:24.967 INFO request completed, latency_us: 61[8810] Disable keep_running , [8810] Got stop action so:false kr:false response_code: 204, uri: /shutdown, method: POST, req_id: 8eadf351-0951-4bd5-a93d-6b142f4804f6, remote_addr: 127[8830] Disable keep_running .0.0.1:47752[8820] Disable keep_running , [8820] Got stop action so:false kr:false local_addr: 127.0.0.1:[8830] Got stop action so:false kr:false 9998 [8830] Exited with: ExitStatus(unix_wait_status(9)) [8820] Exited with: ExitStatus(unix_wait_status(9)) [8830][2] reports Exit [8820][1] reports Exit [8810] Exited with: ExitStatus(unix_wait_status(9)) [8810][0] reports Exit Create region with ES:16384 EC:1280 BS:4096 Removing existing dsc directory "/tmp/dsc" Removing existing region "/var/tmp/dsc" Creating region directory at: /var/tmp/dsc Creating dsc directory at: /tmp/dsc Downstairs region 0 created at /var/tmp/dsc/8810 in 1.1683705 Downstairs region 1 created at /var/tmp/dsc/8820 in 1.1823382 Downstairs region 2 created at /var/tmp/dsc/8830 in 1.2101189 Created 3 regions Using existing output directory "/tmp/dsc" Update our region info with: Some(RegionExtentInfo { block_size: 4096, blocks_per_extent: 16384, extent_count: 1280 }) start ds: 8810 start ds: 8820 start ds: 8830 start access at:127.0.0.1:9998 Starting downstairs at port 8810 Make output file at "/tmp/dsc/downstairs-8810.txt" Starting downstairs at port 8820 Make output file at "/tmp/dsc/downstairs-8820.txt" [8810][0] initial start wait reports Starting [8820][1] initial start wait reports Starting Starting downstairs at port 8830 Make output file at "/tmp/dsc/downstairs-8830.txt" [8830][2] initial start wait reports Starting Downstairs /var/tmp/dsc/8820 port 8820 PID:Some(1200) [8820][1] initial start wait reports Running Downstairs /var/tmp/dsc/8830 port 8830 PID:Some(1201) [8830][2] initial start wait reports Running Downstairs /var/tmp/dsc/8810 port 8810 PID:Some(1202) [8810][0] initial start wait reports Running All downstairs are running Sep 27 03:52:29.591 INFO listening, local_addr: 127.0.0.1:9998 Control access at:127.0.0.1:9998 1202 1200 1201 Sep 27 03:52:34.630 INFO accepted connection, remote_addr: 127.0.0.1:38401, local_addr: 127.0.0.1:9998 Main task has work to do, go find it got dsc DisableRestartAll disable restart on all: 3 Sep 27 03:52:34.630 INFO request completed, latency_us: 123, response_code: 204, [8820] Disable keep_running uri[8830] Disable keep_running : /disablerestart/all, method: POST, req_id: 6a0e0926-ba87-455a-af4f-5eb0776af8b3, remote_addr:[8810] Disable keep_running 127.0.0.1:38401, local_addr: 127.0.0.1:9998 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 completed, stop all downstairs Sep 27 03:53:02.522 INFO accepted connection, remote_addr: 127.0.0.1:61478, local_addr: 127.0.0.1:9998 Main task has work to do, go find it got dsc Shutdown Shutdown Sep 27 03:53:02.522Shut it down INFO[8810] Disable keep_running [8810] Got stop action so:false kr:false request completed[8820] Disable keep_running , latency_us: 54, response_code: 204, [8830] Disable keep_running uri[8830] Got stop action so:false kr:false : /shutdown, method: POST, req_id: [8820] Got stop action so:false kr:false 8b123024-2a06-4af4-9490-40f84822534c, remote_addr: 127.0.0.1:61478, local_addr: 127.0.0.1:9998 [8820] Exited with: ExitStatus(unix_wait_status(9)) [8810] Exited with: ExitStatus(unix_wait_status(9)) [8820][1] reports Exit [8810][0] reports Exit [8830] Exited with: ExitStatus(unix_wait_status(9)) [8830][2] reports Exit 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 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 TEST SECONDS COUNT DPTH IOPS MEAN P95 P99 MAX ES EC 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 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