Hi Rob,
I can confirm this as I wrote the original patch to pgjdbc. :)
It may be the case that you need to use a more recent pgjdbc build as
the patch got integrated within the last year or so (IIRC).
Regards,
Omar
On Thu, Sep 7, 2017 at 9:36 AM Rob Sargent <[email protected]
<mailto:[email protected]>> wrote:
Omar,
My last message may have not gone through because I was attempting to
cross-post to the jOOQ list. (I got a message about it being reviewed
for some forgotten reason.)
Can you confirm that zero is the kill switch for re-using prepared
statements on the server. And is it connection based? I have two
distinct modes of use and the other (not yet shown) makes heavy use of
jOOQ batch writing (sending lists of 1000s of items) which in turn
uses
(quite sensibly) prepared statements. I have never seen this
list-based
usage generate the error, but I don't go through pgbouncer connections
when doing so - a two-tiered scenario.
In the problematic case, I can turn off prepared statements from the
jOOQ interface and all seems well. I'm just trying to understand how
I'm hitting the 'already exists' error in the default world of
PreparedStatements under separate connections. Granted I am
intensionally flooding pgbouncer with requests: am I re-using
pgbouncer
connections by repeated requests from same host/user thereby
exposing a
client to re-using a prepared statement?
(I'll cross this back to the jOOQ list later)
Thanks
On 08/30/2017 12:10 PM, Omar Kilani wrote:
> Hi Rob,
>
> It depends on the code -- if you're not explicitly using prepared
> statements from other pgsql sessions it should be fine.
>
> There's no way to use 'pool = transaction' without
> 'prepareThreshold=0'. Even with 'prepareThreshold=0', pgjdbc still
> uses prepared statements. It just doesn't *reuse* them (which is
where
> the problem comes in with transaction pooling mode). The performance
> improvement in high RPS environments from using transaction pooling
> mode far outweighs any benefits of reusing prepared statements.
>
> Otherwise you can switch to 'pool = session'.
>
> Regards,
> Omar
>
> On Wed, Aug 30, 2017 at 10:55 AM, Rob Sargent
<[email protected] <mailto:[email protected]>> wrote:
>> Yes, I've seen that bit, but wonder how that impacts the code
which is
>> using/generating PreparedStatement calls?
>>
>> Btw, of the 100 runs of the client only went through all 5
attempts and
>> ultimately failed, though many clients successfully resubmitted
their
>> payload. You can see below (if you strectch your screen really
wide) the
>> first client (later runtime) failed once then succeeded. (The
emergency
>> landing worked, dumping a the json version of the data)
>>
>> [u0138544@syslog camp]$ zcat yesterday/lonepeak9/messages.gz | grep
>> 14a99861-fb7c-4c45-bed0-c12d0bd4ae15
>> 2017-08-29T21:44:50-06:00 lonepeak9 [pool-1-thread-5]
>> edu.utah.camplab.server.PayloadThread Saving Private Ryan:
>> 14a99861-fb7c-4c45-bed0-c12d0bd4ae15
>> 2017-08-29T21:44:50-06:00 lonepeak9 [pool-1-thread-5]
>> edu.utah.camplab.jx.AbstractPayload sending
>> 14a99861-fb7c-4c45-bed0-c12d0bd4ae15
>> 2017-08-29T21:44:50-06:00 lonepeak9 [pool-1-thread-5]
>> edu.utah.camplab.jx.AbstractPayload
14a99861-fb7c-4c45-bed0-c12d0bd4ae15:
>> start transaction
>> 2017-08-29T21:44:50-06:00 lonepeak9 [pool-1-thread-5]
>> edu.utah.camplab.jx.AbstractPayload
14a99861-fb7c-4c45-bed0-c12d0bd4ae15:
>> failed write attempt #1, SQL [insert into "process_input" ("id",
>> "process_id", "input_type", "input_ref") values (?, ?, ?, ?)];
Batch entry 0
>> insert into "process_input" ("id", "process_id", "input_type",
"input_ref")
>> values ('e8a8f8cb-4b84-43b6-8c0d-8081a672deca'::uuid,
>> 'c2c13b27-bc8a-4ece-aab2-036b93180b2e'::uuid, 'pedfile',
>> 'a3a1326a-cd40-4777-903f-546621028e9f') was aborted: ERROR:
prepared
>> statement "S_1" already exists Call getNextException to see
other errors in
>> the batch.
>> 2017-08-29T21:44:50-06:00 lonepeak9 [pool-1-thread-5]
>> edu.utah.camplab.jx.AbstractPayload
14a99861-fb7c-4c45-bed0-c12d0bd4ae15:
>> start transaction
>> 2017-08-29T21:44:50-06:00 lonepeak9 [pool-1-thread-5]
>> edu.utah.camplab.jx.AbstractPayload
14a99861-fb7c-4c45-bed0-c12d0bd4ae15:
>> end transaction
>>
>> [u0138544@syslog camp]$ zcat yesterday/lonepeak9/messages.gz | grep
>> d3d3a62f-64cf-4ffe-b7f8-927943af5c3e
>> 2017-08-29T17:33:25-06:00 lonepeak9 [pool-1-thread-6]
>> edu.utah.camplab.server.PayloadThread Saving Private Ryan:
>> d3d3a62f-64cf-4ffe-b7f8-927943af5c3e
>> 2017-08-29T17:33:25-06:00 lonepeak9 [pool-1-thread-6]
>> edu.utah.camplab.jx.AbstractPayload sending
>> d3d3a62f-64cf-4ffe-b7f8-927943af5c3e
>> 2017-08-29T17:33:25-06:00 lonepeak9 [pool-1-thread-6]
>> edu.utah.camplab.jx.AbstractPayload
d3d3a62f-64cf-4ffe-b7f8-927943af5c3e:
>> failed write attempt #1, SQL [insert into "process_input" ("id",
>> "process_id", "input_type", "input_ref") values (?, ?, ?, ?)];
Batch entry 0
>> insert into "process_input" ("id", "process_id", "input_type",
"input_ref")
>> values ('05f9c2b7-b2a1-441b-aabe-686ed48e84c2'::uuid,
>> '40cd010d-804d-4963-ad06-eca57b795f74'::uuid, 'pedfile',
>> 'a3a1326a-cd40-4777-903f-546621028e9f') was aborted: ERROR:
prepared
>> statement "S_1" already exists Call getNextException to see
other errors in
>> the batch.
>> 2017-08-29T17:33:25-06:00 lonepeak9 [pool-1-thread-6]
>> edu.utah.camplab.jx.AbstractPayload
d3d3a62f-64cf-4ffe-b7f8-927943af5c3e:
>> failed write attempt #2, SQL [insert into "process_input" ("id",
>> "process_id", "input_type", "input_ref") values (?, ?, ?, ?)];
Batch entry 0
>> insert into "process_input" ("id", "process_id", "input_type",
"input_ref")
>> values ('d29a39fd-e952-4c6b-a016-b6ca72f0a546'::uuid,
>> '13083f28-a6c6-44a0-be14-e24f8add05f9'::uuid, 'pedfile',
>> 'a3a1326a-cd40-4777-903f-546621028e9f') was aborted: ERROR:
prepared
>> statement "S_1" already exists Call getNextException to see
other errors in
>> the batch.
>> 2017-08-29T17:33:25-06:00 lonepeak9 [pool-1-thread-6]
>> edu.utah.camplab.jx.AbstractPayload
d3d3a62f-64cf-4ffe-b7f8-927943af5c3e:
>> failed write attempt #3, SQL [insert into "process_input" ("id",
>> "process_id", "input_type", "input_ref") values (?, ?, ?, ?)];
Batch entry 0
>> insert into "process_input" ("id", "process_id", "input_type",
"input_ref")
>> values ('25831dcc-2cfe-4a54-a6e6-b5a4efec08da'::uuid,
>> 'f150d753-822e-4aa2-8745-fc1ce6e99041'::uuid, 'pedfile',
>> 'a3a1326a-cd40-4777-903f-546621028e9f') was aborted: ERROR:
prepared
>> statement "S_1" already exists Call getNextException to see
other errors in
>> the batch.
>> 2017-08-29T17:33:25-06:00 lonepeak9 [pool-1-thread-6]
>> edu.utah.camplab.jx.AbstractPayload
d3d3a62f-64cf-4ffe-b7f8-927943af5c3e:
>> failed write attempt #4, SQL [insert into "process_input" ("id",
>> "process_id", "input_type", "input_ref") values (?, ?, ?, ?)];
Batch entry 0
>> insert into "process_input" ("id", "process_id", "input_type",
"input_ref")
>> values ('1ec5e560-35aa-4ea9-9c4b-22293a67b8bf'::uuid,
>> '2d05a7a9-625e-4dfe-9e72-ec4671cdd67c'::uuid, 'pedfile',
>> 'a3a1326a-cd40-4777-903f-546621028e9f') was aborted: ERROR:
prepared
>> statement "S_1" already exists Call getNextException to see
other errors in
>> the batch.
>> 2017-08-29T17:33:25-06:00 lonepeak9 [pool-1-thread-6]
>> edu.utah.camplab.jx.AbstractPayload
d3d3a62f-64cf-4ffe-b7f8-927943af5c3e:
>> failed write attempt #5, SQL [insert into "process_input" ("id",
>> "process_id", "input_type", "input_ref") values (?, ?, ?, ?)];
Batch entry 0
>> insert into "process_input" ("id", "process_id", "input_type",
"input_ref")
>> values ('11c0e3d1-59a5-469e-a77d-89dcc98f03e0'::uuid,
>> '14271c8d-31ea-4cd7-bcba-62b2436a9c21'::uuid, 'pedfile',
>> 'a3a1326a-cd40-4777-903f-546621028e9f') was aborted: ERROR:
prepared
>> statement "S_1" already exists Call getNextException to see
other errors in
>> the batch.
>> 2017-08-29T17:33:25-06:00 lonepeak9 [pool-1-thread-6]
>> edu.utah.camplab.server.PayloadThread Write attempt failed for
payload
>> d3d3a62f-64cf-4ffe-b7f8-927943af5c3e. Trying emergency landing at
>> /tmp/SGS.crashpad
>> 2017-08-29T17:33:25-06:00 lonepeak9 [pool-1-thread-6]
>> edu.utah.camplab.server.PayloadThread EMERGENCY LANDING:
writing run
>> d3d3a62f-64cf-4ffe-b7f8-927943af5c3e as json to /tmp/SGS.crashpad
>>
>> On 08/30/2017 11:21 AM, Omar Kilani wrote:
>>
>> Hi Rob,
>>
>> Please see the pgbouncer FAQ:
>>
>> https://pgbouncer.github.io/faq.html
>>
>> Specifically:
>>
>> "Disabling prepared statements in JDBC"
>>
>> Hope this helps!
>>
>> Regards,
>> Omar
>>
>> On Wed, Aug 30, 2017 at 9:20 AM, Rob Sargent
<[email protected] <mailto:[email protected]>> wrote:
>>
>> This is a cross-post to both pgbouncer and jooq lists, as I am
unsure where
>> in my stack I need to address this issue.
>>
>> I am testing my throughput by intensionally swamping my
systems. The stack
>> I am using consists of
>> - postgres 10
>> - pgbouncer 1.7.2 (running on db machine)
>> - collector (java Selector programme running on NOT db machine)
>> - clients (java analysis running on machine(s) NOT db NOT
collector)
>>
>> The clients are spawned from GNU parallel, one second delay
each, 100 jobs
>> with max 16 concurrent (hyper-threaded processor count) and
last for about
>> 10 seconds. The clients all finish successfully and more
quickly than I can
>> perform the rest of the stack. This is a temporary, testing
situation -
>> ultimately the clients will take much longer as I do a more
realistic amount
>> (one thousand fold more) of work per invocation.
>>
>> Each client sends a payload to the collector; the collector has
>> ThreadPoolExecutor transforming payload into db calls via jOOQ.
>>
>> The payload inserts 6 new records (over three tables) and
updates one
>> record; the same record updated in all payloads.
>> I am NOT using PreparedStatment in my code.
>> pbBouncer is in "pool_mode = transaction"
>> The jOOQ transaction is
>>
>> ctx.transaction(ltx -> {
>> startProcess(ctx); //three inserts, two tables
>> writeSegments(ctx); //update single record by
PK (repeated
>> per client)
>> finishProcess(ctx); //three inserts, one table
>> });
>>
>> If I correctly read the error message below (the fifth of 5
attempts for
>> same payload) I must be reusing a pooled db connection for a
second payload.
>> If so, is this pbbouncer failing to close connection after
transaction; jooq
>> not signaling end of transaction, an artifact of intentional
overload;
>> other?
>>
>> 2017-08-29T17:33:25-06:00 lonepeak9 [pool-1-thread-6]
>> edu.utah.camplab.jx.AbstractPayload
d3d3a62f-64cf-4ffe-b7f8-927943af5c3e:
>> failed write attempt #5, SQL [insert into "process_input" ("id",
>> "process_id", "input_type", "input_ref") values (?, ?, ?, ?)];
Batch entry 0
>> insert into "process_input" ("id", "process_id", "input_type",
"input_ref")
>> values ('11c0e3d1-59a5-469e-a77d-89dcc98f03e0'::uuid,
>> '14271c8d-31ea-4cd7-bcba-62b2436a9c21'::uuid, 'pedfile',
>> 'a3a1326a-cd40-4777-903f-546621028e9f') was aborted: ERROR:
prepared
>> statement "S_1" already exists Call getNextException to see
other errors in
>> the batch.
>>
>>
>> _______________________________________________
>> Pgbouncer-general mailing list
>> [email protected]
<mailto:[email protected]>
>> http://lists.pgfoundry.org/mailman/listinfo/pgbouncer-general
>>
>>
