Jira (PDB-4871) Investigate queries using two Hikari connections per request

28 views
Skip to first unread message

Zachary Kent (Jira)

unread,
Aug 25, 2020, 5:23:04 PM8/25/20
to puppe...@googlegroups.com
Zachary Kent created an issue
 
PuppetDB / Bug PDB-4871
Investigate queries using two Hikari connections per request
Issue Type: Bug Bug
Assignee: Unassigned
Created: 2020/08/25 2:22 PM
Priority: Normal Normal
Reporter: Zachary Kent

It looks like PDB queries are grabbing two connections from the Hikari PDBReadPool for each request. You can see this behavior by fetching this branch. The commit on the tip of that branch uses the Hikari AcviveConnections metric to get the number of active connections being used from the pool at any given time (refreshed every second).

Once you have the branch, start PDB up locally with `lein run services -c ...` and then run any query against the `/pdb/query/v4` endpoint. This should result in the following output:

"inside the outer with-transacted-connection form:"
"pg_backend_pid: [{:pg_backend_pid 91592}]"
"number of active connections:"
{:request
 {:mbean
  "puppetlabs.puppetdb.database:name=PDBReadPool.pool.ActiveConnections",
  :type "read"},
 :value {:Value 1},
 :timestamp 1598388833,
 :status 200}
 
"inside the inner with-transacted-connection form:"
"pg_backend_pid: [{:pg_backend_pid 91593}]"
"number of active connections:"
{:request
 {:mbean
  "puppetlabs.puppetdb.database:name=PDBReadPool.pool.ActiveConnections",
  :type "read"},
 :value {:Value 2},
 :timestamp 1598388834,
 :status 200}
 
"Inside top level query handler which calls produce-streaming-body"
"Number of connections after exiting both with-transacted-connection forms:"
{:request
 {:mbean
  "puppetlabs.puppetdb.database:name=PDBReadPool.pool.ActiveConnections",
  :type "read"},
 :value {:Value 0},
 :timestamp 1598388835,
 :status 200}

You can see above that the nested with-transacted-connection marcos appear to be grabbing two connections from the Hikari read pool for each query. I believe this is because we end up calling with-db-connection twice as a result of this nesting. Also note how the pg_backend_pid is changing half way through the query, we'll want to have a way to unify these to help provide accurate correlation ids between any logging PDB does and the PG side.

I tried removing the inner call to with-transacted-connection and tests in the following namespaces failed:
puppetlabs.puppetdb.http.resources-test
puppetlabs.puppetdb.http.facts-test
puppetlabs.puppetdb.command-test
puppetlabs.puppetdb.admin-test
puppetlabs.puppetdb.admin-clean-test
puppetlabs.puppetdb.acceptance.node-ttl
puppetlabs.puppetdb.scf.sql-test

We should investigate if we intended to hold two Hikari connections open per query or if all of the work we're doing can be accomplished by one. I poked around a bit and it seems like we've been doing this for at least 5+ years.

Add Comment Add Comment
 
This message was sent by Atlassian Jira (v8.5.2#805002-sha1:a66f935)
Atlassian logo

Rob Browning (Jira)

unread,
Oct 22, 2020, 3:25:03 PM10/22/20
to puppe...@googlegroups.com

Rob Browning (Jira)

unread,
Oct 22, 2020, 3:26:03 PM10/22/20
to puppe...@googlegroups.com

Zachary Kent (Jira)

unread,
Oct 29, 2020, 12:43:03 PM10/29/20
to puppe...@googlegroups.com

Zachary Kent (Jira)

unread,
Nov 4, 2020, 6:32:03 PM11/4/20
to puppe...@googlegroups.com

Josh Cooper (Jira)

unread,
Nov 4, 2020, 7:27:03 PM11/4/20
to puppe...@googlegroups.com

Jarret Lavallee (Jira)

unread,
Nov 4, 2020, 10:01:03 PM11/4/20
to puppe...@googlegroups.com

Rob Browning (Jira)

unread,
Nov 5, 2020, 1:46:03 PM11/5/20
to puppe...@googlegroups.com
Rob Browning assigned an issue to Rob Browning
Change By: Rob Browning
Assignee: Zachary Kent Rob Browning

Jarret Lavallee (Jira)

unread,
Nov 5, 2020, 5:52:03 PM11/5/20
to puppe...@googlegroups.com

Jarret Lavallee (Jira)

unread,
Nov 5, 2020, 6:12:03 PM11/5/20
to puppe...@googlegroups.com

Austin Blatt (Jira)

unread,
Nov 10, 2020, 11:39:03 AM11/10/20
to puppe...@googlegroups.com

Austin Blatt (Jira)

unread,
Nov 10, 2020, 11:39:04 AM11/10/20
to puppe...@googlegroups.com

Rob Browning (Jira)

unread,
Nov 12, 2020, 5:45:04 PM11/12/20
to puppe...@googlegroups.com
Rob Browning updated an issue
Change By: Rob Browning
Release Notes: Bug Fix
Release Notes Summary: PuppetDB won't hold an extra database connection open while generating query responses.  Previously it would create and hold an extra connection open during the initial phase of the response.  For the moment, the previous behavior can be restored by setting the PDB_USE_DEPRECATED_QUERY_STREAMING_METHOD environment variable.  See the [configuration information](https://puppet.com/docs/puppetdb/latest/configure.html#experimental-environment-variables) for further details.

Zachary Kent (Jira)

unread,
Nov 18, 2020, 12:29:02 PM11/18/20
to puppe...@googlegroups.com
Zachary Kent commented on Bug PDB-4871
 
Re: Investigate queries using two Hikari connections per request

Investigating this issue we realized that the 2nd connection was only being held open until the first row from the query was ready to be streamed to the client. This isn't as bad as holding the connection open for the entire query but could still cause the outer setup query to appear idle in transaction for a short time before rows we returned.

Austin Blatt (Jira)

unread,
May 28, 2021, 1:17:28 PM5/28/21
to puppe...@googlegroups.com
Austin Blatt updated an issue
 
Change By: Austin Blatt
Fix Version/s: PDB 6.14.0
This message was sent by Atlassian Jira (v8.13.2#813002-sha1:c495a97)
Atlassian logo
Reply all
Reply to author
Forward
0 new messages