Log the state of the connection pool once per minute #1606
Merged
Conversation
This file contains hidden or bidirectional Unicode text that may be interpreted or compiled differently than what appears below. To review, open the file in an editor that reveals hidden Unicode characters.
Learn more about bidirectional Unicode characters
On rare occasions we've had outages occur as a result of the connection pool refusing to return any connections. Shortly before this occurs, we start to see significant spikes in response times (likely because the pool has begun serving only a 1 or 2 connections and there's a large amount of contention). Right now we have limited capability to debug this. The only explanations that I can come up with are a bug in r2d2, or something is happening causing our worker threads to be killed in a way that does not run destructors, or something is causing threads to hang indefinitely. If one of those three options above is true, we should see `connections - idle_connections` trend towards zero over time, and diverge away from `in_flight_requests` over time (they aren't expected to be exactly equal, since some requests will never attempt to get a database connection, and we can have more requests than available connections during normal operations) This isn't going to be enough information to definitively figure out what's going on here, but it should hopefully give us *some* information to help figure out where to look next
jtgeibel
approved these changes
Jan 31, 2019
There was a problem hiding this comment.
LGTM! Here is what I'm seeing in my logs on staging after enabling the environment variable:
$ heroku logs | grep connection
2019-01-31T00:52:23.556302+00:00 app[web.1]: connection_pool_status="State { connections: 8, idle_connections: 8 }" in_flight_requests=0
2019-01-31T00:54:49.617156+00:00 app[web.1]: connection_pool_status="State { connections: 8, idle_connections: 8 }" in_flight_requests=0
2019-01-31T00:55:58.628764+00:00 app[web.1]: connection_pool_status="State { connections: 8, idle_connections: 8 }" in_flight_requests=0@bors r+
|
@bors r=jtgeibel |
|
📌 Commit 90edc2f has been approved by |
bors
added a commit
that referenced
this pull request
Jan 31, 2019
Log the state of the connection pool once per minute On rare occasions we've had outages occur as a result of the connection pool refusing to return any connections. Shortly before this occurs, we start to see significant spikes in response times (likely because the pool has begun serving only a 1 or 2 connections and there's a large amount of contention). Right now we have limited capability to debug this. The only explanations that I can come up with are a bug in r2d2, or something is happening causing our worker threads to be killed in a way that does not run destructors, or something is causing threads to hang indefinitely. If one of those three options above is true, we should see `connections - idle_connections` trend towards zero over time, and diverge away from `in_flight_requests` over time (they aren't expected to be exactly equal, since some requests will never attempt to get a database connection, and we can have more requests than available connections during normal operations) This isn't going to be enough information to definitively figure out what's going on here, but it should hopefully give us *some* information to help figure out where to look next
|
💔 Test failed - checks-travis |
|
@bors retry
…On Thu, Jan 31, 2019 at 2:52 PM bors ***@***.***> wrote:
💔 Test failed - checks-travis
<https://travis-ci.com/rust-lang/crates.io/builds/99344193>
—
You are receiving this because you authored the thread.
Reply to this email directly, view it on GitHub
<#1606 (comment)>,
or mute the thread
<https://github.com/notifications/unsubscribe-auth/ABdWKyP1tRnBqcx_eVnL9Re19g4vLkhSks5vI2WWgaJpZM4aUTVd>
.
|
bors
added a commit
that referenced
this pull request
Jan 31, 2019
Log the state of the connection pool once per minute On rare occasions we've had outages occur as a result of the connection pool refusing to return any connections. Shortly before this occurs, we start to see significant spikes in response times (likely because the pool has begun serving only a 1 or 2 connections and there's a large amount of contention). Right now we have limited capability to debug this. The only explanations that I can come up with are a bug in r2d2, or something is happening causing our worker threads to be killed in a way that does not run destructors, or something is causing threads to hang indefinitely. If one of those three options above is true, we should see `connections - idle_connections` trend towards zero over time, and diverge away from `in_flight_requests` over time (they aren't expected to be exactly equal, since some requests will never attempt to get a database connection, and we can have more requests than available connections during normal operations) This isn't going to be enough information to definitively figure out what's going on here, but it should hopefully give us *some* information to help figure out where to look next
|
☀️ Test successful - checks-travis |
Sign up for free
to join this conversation on GitHub.
Already have an account?
Sign in to comment
Add this suggestion to a batch that can be applied as a single commit.
This suggestion is invalid because no changes were made to the code.
Suggestions cannot be applied while the pull request is closed.
Suggestions cannot be applied while viewing a subset of changes.
Only one suggestion per line can be applied in a batch.
Add this suggestion to a batch that can be applied as a single commit.
Applying suggestions on deleted lines is not supported.
You must change the existing code in this line in order to create a valid suggestion.
Outdated suggestions cannot be applied.
This suggestion has been applied or marked resolved.
Suggestions cannot be applied from pending reviews.
Suggestions cannot be applied on multi-line comments.
Suggestions cannot be applied while the pull request is queued to merge.
Suggestion cannot be applied right now. Please check back later.
On rare occasions we've had outages occur as a result of the connection
pool refusing to return any connections. Shortly before this occurs, we
start to see significant spikes in response times (likely because the
pool has begun serving only a 1 or 2 connections and there's a large
amount of contention).
Right now we have limited capability to debug this. The only
explanations that I can come up with are a bug in r2d2, or something is
happening causing our worker threads to be killed in a way that does not
run destructors, or something is causing threads to hang indefinitely.
If one of those three options above is true, we should see
connections - idle_connectionstrend towards zero over time, and diverge away from
in_flight_requestsover time (they aren't expected to be exactlyequal, since some requests will never attempt to get a database
connection, and we can have more requests than available connections
during normal operations)
This isn't going to be enough information to definitively figure out
what's going on here, but it should hopefully give us some information
to help figure out where to look next