View Issue Details

IDProjectCategoryView StatusLast Update
0000244Pgpool-IIBugpublic2017-03-30 09:30
Reporterpgdude Assigned Tot-ishii  
PriorityimmediateSeveritymajorReproducibilityalways
Status closedResolutionopen 
PlatformLinuxOSDebianOS Version7.11 Wheezy
Product Version3.5.3 
Summary0000244: Load balancing error
DescriptionWithin a transaction block, an insert goes to the master correctly, a subsequent query goes to the master correctly, but the next query goes to the slave, which is an error.
Steps To ReproduceRestarted the Perl DBI application and waited for application rollback errors to occur since the DBI transaction manager rolls back this transaction when it cannot find the query results that went against the slave instead of the master.
Additional InformationI have attached the pgpool2 logs which show the error context.
Tagsload balancing

Activities

pgdude

2016-09-13 00:24

reporter  

pgpoolbug.log (3,637 bytes)

pgdude

2016-09-15 02:28

reporter   ~0001064

This needs to be turned into a blocker severity. cannot implement this in production environment with load balancing error within transaction.

t-ishii

2016-09-23 16:18

developer   ~0001084

I have tried with Java program (I'm not familiar with perl) and failed to reproduce the problem.

See attached sample program.

t-ishii

2016-09-23 16:18

developer  

Sample.java (1,238 bytes)   
Sample.java (1,238 bytes)   

pgdude

2016-09-26 21:55

reporter   ~0001086

Thank you for addressing this problem. Unfortunately, while we can re-create the problem, we cannot isolate it to a small test script like the one you attached.

Is there some kind of racing condition that could occur that would result in this transactional load balancing error? Or can you suggest some other parameters that we might change to see if it makes a difference?

pgdude

2016-09-26 21:57

reporter   ~0001087

Little more elaboration: The problem occurs after we run some automated testing for a few hours. It never appears immediately. Does that give you any idea about what may be happening?

t-ishii

2016-09-28 11:37

developer   ~0001100

To isolate the problem, I would like to know if the problem occurs with simple protocol as well.

pgdude

2016-09-28 12:33

reporter   ~0001102

What do you mean by "simple protocol"? If you mean running your small java program, the answer is no: We cannot isolate it to a simple one time transaction test.

t-ishii

2016-09-28 12:52

developer   ~0001103

Simple protocol is typically used by psql and other applications. In extended protocol, queries are divided into multiple phases: parse, bind, execute etc.
Typically Java application and Perl DBI applications. See below for more details.

https://www.postgresql.org/docs/9.5/static/protocol-overview.html

pgdude

2016-10-21 01:07

reporter   ~0001129

Please keep this issue open while we explore the problem with how PERL DBI is working with extended protocol, prepare, execute, etc.

We will respond to this ticket within 2 weeks.

pgdude

2016-10-28 06:04

reporter   ~0001141

still internally investigating this problem...

pgdude

2016-11-01 23:09

reporter   ~0001147

still internally investigating this problem...

pgdude

2016-11-05 04:43

reporter   ~0001152

update status: I think we have identified the problem with our PERL DBix coding--> prepare_cached

Instead of doing regular prepares which always go the db and return instantly without reparsing in most cases, we had bypassed this db server round-trip by using cached, prepare handles on the client side, which had the unintended effect of interfering with pgpool parsing logic.

We have turned off "prepare_cached" and testing again to see if this fixes our problem. Since this problem only occurred after many hours, we have to do some in depth regression testing to make sure we correctly identified this as the culprit.

Will update this thread when testing is complete.

t-ishii

2016-11-10 14:24

developer   ~0001158

Thanks for the investigation.

supp_k

2016-12-19 05:41

reporter   ~0001227

Hi Pgpool developers!

Please consider the logic that reproduces the error.

In approximately 30% of cases the attached class (TestPgpool.java) reproduces the issue.
The target testing DB has 2 tables used for testing (tables.ddl). We did several modifications in pgpool code that show the cases (as we could detect it) when Pgpool does balancing instead of forwarding the SELECT request to MASTER backend after DDL statement was processed.

In several runnings one will see messages: "USE BACKEND: {1} THOUGH THE WRITE TRANSACTION IS ACTIVE!!!!!!!!" which say that previously the UPDATE statement was executed but the next SELECT method is forwarded to SLAVE – which should not happen.

We enforced balancing ratio in pgpool by proportion MASTER/SLAVE as 0/1000. Thus the majority of requests will be forwarded to SLAVE. The attached configuration assumes the 2 backends are synchronous and backend #0 is master

Notes: The attached DIFF file also contains patch for the issue 0000231.
TestPgpool.java (2,259 bytes)

supp_k

2016-12-19 05:41

reporter  

pgpool.conf (4,158 bytes)

supp_k

2016-12-19 05:42

reporter   ~0001228

pgpool conf file
pgpool-2.conf (4,158 bytes)

supp_k

2016-12-19 05:42

reporter   ~0001229

java class that reproduces the error
TestPgpool-2.java (2,259 bytes)

supp_k

2016-12-19 05:42

reporter   ~0001230

code changes (diff)
error_prove_change.diff (4,166 bytes)   
error_prove_change.diff (4,166 bytes)   

supp_k

2016-12-19 05:43

reporter  

tables.ddl (67 bytes)

t-ishii

2017-02-23 16:17

developer   ~0001356

This is the same issue as bug 271. I'm going to close this issue if there's no objection.

Issue History

Date Modified Username Field Change
2016-09-13 00:24 pgdude New Issue
2016-09-13 00:24 pgdude File Added: pgpoolbug.log
2016-09-15 00:46 pgdude Tag Attached: load balancing
2016-09-15 02:28 pgdude Note Added: 0001064
2016-09-21 16:37 t-ishii Assigned To => t-ishii
2016-09-21 16:37 t-ishii Status new => assigned
2016-09-23 16:18 t-ishii Note Added: 0001084
2016-09-23 16:18 t-ishii File Added: Sample.java
2016-09-23 16:19 t-ishii Status assigned => feedback
2016-09-26 21:55 pgdude Note Added: 0001086
2016-09-26 21:55 pgdude Status feedback => assigned
2016-09-26 21:57 pgdude Note Added: 0001087
2016-09-28 11:37 t-ishii Note Added: 0001100
2016-09-28 11:38 t-ishii Status assigned => feedback
2016-09-28 12:33 pgdude Note Added: 0001102
2016-09-28 12:33 pgdude Status feedback => assigned
2016-09-28 12:52 t-ishii Note Added: 0001103
2016-10-19 11:59 t-ishii Status assigned => feedback
2016-10-21 01:07 pgdude Note Added: 0001129
2016-10-21 01:07 pgdude Status feedback => assigned
2016-10-26 16:26 t-ishii Status assigned => feedback
2016-10-28 06:04 pgdude Note Added: 0001141
2016-10-28 06:04 pgdude Status feedback => assigned
2016-11-01 09:58 t-ishii Status assigned => feedback
2016-11-01 23:09 pgdude Note Added: 0001147
2016-11-01 23:09 pgdude Status feedback => assigned
2016-11-05 04:43 pgdude Note Added: 0001152
2016-11-10 14:24 t-ishii Note Added: 0001158
2016-11-10 14:24 t-ishii Status assigned => feedback
2016-12-19 05:41 supp_k File Added: TestPgpool.java
2016-12-19 05:41 supp_k Note Added: 0001227
2016-12-19 05:41 supp_k File Added: pgpool.conf
2016-12-19 05:42 supp_k File Added: pgpool-2.conf
2016-12-19 05:42 supp_k Note Added: 0001228
2016-12-19 05:42 supp_k File Added: TestPgpool-2.java
2016-12-19 05:42 supp_k Note Added: 0001229
2016-12-19 05:42 supp_k File Added: error_prove_change.diff
2016-12-19 05:42 supp_k Note Added: 0001230
2016-12-19 05:43 supp_k File Added: tables.ddl
2017-02-23 16:17 t-ishii Note Added: 0001356
2017-03-30 09:30 t-ishii Status feedback => closed