diff --git a/src/client.rs b/src/client.rs index 23392b73..4968adbf 100644 --- a/src/client.rs +++ b/src/client.rs @@ -1091,6 +1091,7 @@ where // // If the client is in session mode, no more custom protocol // commands will be accepted. + let transaction_start = Instant::now(); loop { let message = match initial_message { None => { @@ -1204,9 +1205,10 @@ where if !server.in_transaction() { // Report transaction executed statistics. self.stats.transaction(); - server - .stats() - .transaction(self.server_parameters.get_application_name()); + server.stats().transaction( + Instant::now().duration_since(transaction_start).as_millis() as u64, + self.server_parameters.get_application_name(), + ); // Release server back to the pool if we are in transaction mode. // If we are in session mode, we keep the server until the client disconnects. @@ -1460,9 +1462,10 @@ where if !server.in_transaction() { self.stats.transaction(); - server - .stats() - .transaction(self.server_parameters.get_application_name()); + server.stats().transaction( + Instant::now().duration_since(transaction_start).as_millis() as u64, + self.server_parameters.get_application_name(), + ); // Release server back to the pool if we are in transaction mode. // If we are in session mode, we keep the server until the client disconnects. @@ -1511,9 +1514,10 @@ where if !server.in_transaction() { self.stats.transaction(); - server - .stats() - .transaction(self.server_parameters.get_application_name()); + server.stats().transaction( + Instant::now().duration_since(transaction_start).as_millis() as u64, + self.server_parameters.get_application_name(), + ); // Release server back to the pool if we are in transaction mode. // If we are in session mode, we keep the server until the client disconnects. diff --git a/src/stats/server.rs b/src/stats/server.rs index 5d255994..0de8e939 100644 --- a/src/stats/server.rs +++ b/src/stats/server.rs @@ -187,11 +187,12 @@ impl ServerStats { /// we report each individual queries outside a transaction as a transaction /// We only count the initial BEGIN as a transaction, all queries within do not /// count as transactions - pub fn transaction(&self, application_name: &str) { + pub fn transaction(&self, milliseconds: u64, application_name: &str) { self.set_application(application_name.to_string()); self.transaction_count.fetch_add(1, Ordering::Relaxed); self.address.stats.xact_count_add(); + self.address.stats.xact_time_add(milliseconds); } /// Report data sent to a server diff --git a/tests/ruby/stats_spec.rb b/tests/ruby/stats_spec.rb index 8a683a01..b53eaf27 100644 --- a/tests/ruby/stats_spec.rb +++ b/tests/ruby/stats_spec.rb @@ -12,11 +12,11 @@ end describe "SHOW STATS" do - context "clients connect and make one query" do - it "updates *_query_time and *_wait_time" do + context "clients connect and issue queries" do + it "updates {avg,total}_{query,xact,wait}_{time,count}" do connections = Array.new(3) { PG::connect("#{pgcat_conn_str}?application_name=one_query") } connections.each do |c| - Thread.new { c.async_exec("SELECT pg_sleep(0.25)") } + Thread.new { c.transaction { |t| t.async_exec("SELECT pg_sleep(0.25);") } } end sleep(1) connections.map(&:close) @@ -25,9 +25,42 @@ sleep(15.5) admin_conn = PG::connect(processes.pgcat.admin_connection_string) results = admin_conn.async_exec("SHOW STATS")[0] - admin_conn.close + + # BEGIN, SELECT, COMMIT for each connection + expect(results["total_query_count"].to_i).to eq(9) expect(results["total_query_time"].to_i).to be_within(200).of(750) - expect(results["avg_query_time"].to_i).to be_within(50).of(250) + expect(results["avg_query_time"].to_i).to be_within(15).of(250.0 / 3) + + # Single transaction for each connection + expect(results["total_xact_count"].to_i).to eq(3) + expect(results["total_xact_time"].to_i).to be_within(200).of(750) + expect(results["avg_xact_time"].to_i).to be_within(50).of(250) + + expect(results["total_wait_time"].to_i).to_not eq(0) + expect(results["avg_wait_time"].to_i).to_not eq(0) + + connections = Array.new(3) { PG::connect("#{pgcat_conn_str}?application_name=one_query") } + connections.each do |c| + Thread.new { c.async_exec("SELECT pg_sleep(0.125);") } + end + sleep(1) + connections.map(&:close) + # wait for averages to be calculated again + sleep(15.5) + + results = admin_conn.async_exec("SHOW STATS")[0] + admin_conn.close + # Three more queries + expect(results["total_query_count"].to_i).to eq(12) + expect(results["total_query_time"].to_i).to be_within(225).of(1125) + # Average is 125ms in the current stats period + expect(results["avg_query_time"].to_i).to be_within(25).of(125.0) + + # Autocommit transactions still increase the count and time + expect(results["total_xact_count"].to_i).to eq(6) + expect(results["total_xact_time"].to_i).to be_within(225).of(1125) + # Average is 125ms in the current stats period + expect(results["avg_xact_time"].to_i).to be_within(25).of(125.0) expect(results["total_wait_time"].to_i).to_not eq(0) expect(results["avg_wait_time"].to_i).to_not eq(0)