Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Track transaction time #798

Open
wants to merge 1 commit into
base: main
Choose a base branch
from

Conversation

smcgivern
Copy link
Contributor

@smcgivern smcgivern commented Sep 5, 2024

I'm not sure if this is the correct way to track it (on the server, with an always-outdated timestamp), but I couldn't see an obvious way to track this on the client side, and logically a transaction must be tied to a particular server connection, right? Now tracking on the client side.

Closes #114 (total_query_time is already implemented).

@@ -29,6 +29,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["total_xact_time"].to_i).to be_within(200).of(750)
Copy link
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

This is failing in CI:

  1) Stats SHOW STATS clients connect and make one query updates *_query_time and *_wait_time
     Failure/Error: expect(results["total_xact_time"].to_i).to be_within(200).of(750)
       expected 1203 to be within 200 of 750
     # ./stats_spec.rb:32:in `block (4 levels) in <top (required)>'

It passes locally for me inside the dev container, but I wonder if that shows that this approach is flawed.

Having said that, I do see other specs fail some of the time, like this, which I don't think I broke:

  1) Stats SHOW POOLS bad database name does not change any stats
     Failure/Error: expect(results["sv_idle"]).to eq("1")

       expected: "1"
            got: "2"

       (compared using ==)
     # ./stats_spec.rb:72:in `block (4 levels) in <top (required)>'

@drdrsh
Copy link
Collaborator

drdrsh commented Sep 6, 2024

I am testing this with

pgbench -i
pgbench -c 5 -j 10 -T 1800 -P 10 -S

and seeing monotonically increasing avg transaction time.

Screenshot from 2024-09-06 09-01-13

I am trying to figure out the reason for it, also I would expect the tests to fail so we probably have a coverage gap here that we'll want to address

@smcgivern
Copy link
Contributor Author

Ha, yes, this is definitely wrong. I added a test that runs more queries (not in a transaction), and it fails with:

  1) Stats SHOW STATS clients connect and make one query updates *_query_time and *_wait_time
     Failure/Error: expect(results["total_xact_time"].to_i).to be_within(200).of(750)
       expected 51397 to be within 200 of 750
     # ./stats_spec.rb:50:in `block (4 levels) in <top (required)>'

When this metric should not have increased in that time.

# 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
Copy link
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

@smcgivern
Copy link
Contributor Author

smcgivern commented Sep 9, 2024

@drdrsh could you try again, please? I'm seeing an issue when running pgbench in the dev container where both avg_query_time and avg_xact_time are zero, and I'm not sure if I'm doing something wrong in the setup there. (I don't think I broke it in this PR as I see the same on the main branch.)

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
None yet
Development

Successfully merging this pull request may close these issues.

Implement missing statistics
2 participants