View Issue Details

IDProjectCategoryView StatusLast Update
0000288Pgpool-IIBugpublic2017-04-07 00:46
ReporterhcsatishAssigned ToMuhammad Usama 
PriorityurgentSeveritymajorReproducibilityrandom
Status resolvedResolutionfixed 
PlatformLinuxOSUbuntu 12.04OS VersionUbuntu 12.04
Product Version3.6.1 
Target VersionFixed in Version 
Summary0000288: FATAL: failed to read kind from backend
DescriptionWe are randomly getting following errors while using application.
###Pgpool Log##
2017-02-15 08:43:16: pid 12625: DEBUG: reading backend data packet kind
2017-02-15 08:43:16: pid 12625: DETAIL: master node id: 0
2017-02-15 08:43:16: pid 12625: DEBUG: pool_read: read 103 bytes from backend 0
2017-02-15 08:43:16: pid 12625: DEBUG: reading backend data packet kind
2017-02-15 08:43:16: pid 12625: DETAIL: backend:0 of 2 kind = 'E'
2017-02-15 08:43:16: pid 12625: DEBUG: pool_read: read 24 bytes from backend 1
2017-02-15 08:43:16: pid 12625: DEBUG: reading backend data packet kind
2017-02-15 08:43:16: pid 12625: DETAIL: backend:1 of 2 kind = '1'
2017-02-15 08:43:16: pid 12625: DEBUG: read_kind_from_backend max_count:1.000000 num_executed_nodes:2
2017-02-15 08:43:16: pid 12625: WARNING: packet kind of backend 1 ['1'] does not match with master/majority nodes packet kind ['E']
2017-02-15 08:43:16: pid 12625: FATAL: failed to read kind from backend
2017-02-15 08:43:16: pid 12625: DETAIL: kind mismatch among backends. Possible last query was: "set search_path = 'nmc_uat'" kind details are: 0[E: canceling statement due to statement timeout] 1[1]
2017-02-15 08:43:16: pid 12625: HINT: check data consistency among db nodes

##Application Log##

2017-02-15 08:42:14 [10.8.180.1] [Gideesh@nmc_uat] INFO CreateAction: Initialize action of type: com.insta.hms.billing.ClaimSubmissionAction
2017-02-15 08:43:16 [10.8.180.1] [Gideesh@nmc_uat] ERROR DBUtil: Unable to get connection/set search path: org.postgresql.util.PSQLException: FATAL: failed to read kind from backend
  Detail: kind mismatch among backends. Possible last query was: "set search_path = 'nmc_uat'" kind details are: 0[E: canceling statement due to statement timeout] 1[1]
  Hint: check data consistency among db nodes
2017-02-15 08:43:16 [10.8.180.1] [Gideesh@nmc_uat] ERROR DBUtil: Unable to get connection/set search path: org.postgresql.util.PSQLException: This connection has been closed.
2017-02-15 08:43:16 [10.8.180.1] [Gideesh@nmc_uat] ERROR HMSExceptionHandler: Global exception handler caught exception:
java.lang.NullPointerException
        at com.insta.hms.usermanager.RoleDAO.getPageStatVals(RoleDAO.java:233)
        at com.bob.hms.common.HomeAction.execute(HomeAction.java:46)
        at org.apache.struts.chain.commands.servlet.ExecuteAction.execute(ExecuteAction.java:58)
        at org.apache.struts.chain.commands.AbstractExecuteAction.execute(AbstractExecuteAction.java:67)
        at org.apache.struts.chain.commands.ActionCommandBase.execute(ActionCommandBase.java:51)
        at org.apache.commons.chain.impl.ChainBase.execute(ChainBase.java:190)
        at org.apache.commons.chain.generic.LookupCommand.execute(LookupCommand.java:304)
        at org.apache.commons.chain.impl.ChainBase.execute(ChainBase.java:190)
        at org.apache.struts.chain.ComposableRequestProcessor.process(ComposableRequestProcessor.java:283)

Additional Information##Setup##
pgpool : 3.6.1
jdbc : postgresql-9.3-1104.jdbc4.jar
postgres : 9.3

We are using pgpool 3.6.1 for only load balancing, not using any other features of pgpool.

JDBC Configuration :
<Resource name="postgres" auth="Container"
                type="javax.sql.DataSource" factory="org.apache.tomcat.jdbc.pool.DataSourceFactory"
                url="jdbc:postgresql://127.0.0.1:5432/hms"
                username="postgres" password=""
                driverClassName="org.postgresql.Driver"
                maxWait="10000" jdbcInterceptors="StatementFinalizer;ResetAbandonedTimer"
                minIdle="20" maxIdle="20" maxActive="20"
                removeAbandoned="true" removeAbandonedTimeout="300" logAbandoned="true"
                validationQueryTimeout="-1" testWhileIdle="true" testOnBorrow="true"
                validationQuery="SELECT version();"
                minEvictableIdleTimeMillis="300000" timeBetweenEvictionRunsMillis="250000"
                validationInterval="20000"
        />
TagsNo tags attached.

Activities

Muhammad Usama

2017-02-15 22:50

developer   ~0001343

The Pgpool-II log you shared above indicates that the cause of the problem is one of the PostgreSQL backend (backend node 0) is canceling the query with statement timeout error. Can you verify the statement_timeout parameter value on PostgreSQL backend 0.

hcsatish

2017-02-16 00:12

reporter   ~0001345

#statement_timeout = 0 # in milliseconds, 0 is disabled
#lock_timeout = 0 # in milliseconds, 0 is disabled

Statement timeout is disable on node0

Muhammad Usama

2017-02-16 00:35

developer   ~0001346

If statement_timeout is not set in the postgresql.conf than the application might have altered the statement_timeout to a very low value for the session, Or somehow the query is taking too long on to execute on backend node 0 and it is being canceled by the server.
PostgreSQL server logs should me more revealing to identify the issue.

anil_gv

2017-02-16 16:41

reporter   ~0001347

We are getting this error when con.prepareStatement(..) is called on the connection.

Application works fine when connection factory is configured to connect postgres. We are seeing this issue only when pgpool is used.

More info about platform : postgresql-9.3-1104.jdbc4.jar, JDK 1.6, tomcat 7. Postgres 9.3 ,

hcsatish

2017-02-20 17:12

reporter   ~0001350

Hi ,

Can you pleas update on this ?

Regards,
Satish

anil_gv

2017-02-20 21:03

reporter   ~0001351

Few additional info: We are getting this issue only when both read and write transactions are performed in the application. This issue is not happening only if read transaction are performed.

Is is it connected to streaming replication delay / settings. Here is the current setting.

sr_check_period = 5
delay_threshold = 10000

Muhammad Usama

2017-04-07 00:46

developer   ~0001405

Sorry For the late response. The issue you reported was similar to bug 271 (http://www.pgpool.net/mantisbt/view.php?id=271) And is now fixed by the community leader Ishii-San.
https://git.postgresql.org/gitweb/?p=pgpool2.git;a=commitdiff;h=adcb63696b55463d6f6aa493b1b510e135ea67d7

You can try building from the latest source code to verify the fix at your end.

Thanks

Issue History

Date Modified Username Field Change
2017-02-15 14:54 hcsatish New Issue
2017-02-15 22:50 Muhammad Usama Note Added: 0001343
2017-02-16 00:12 hcsatish Note Added: 0001345
2017-02-16 00:35 Muhammad Usama Note Added: 0001346
2017-02-16 16:41 anil_gv Note Added: 0001347
2017-02-20 17:12 hcsatish Note Added: 0001350
2017-02-20 21:03 anil_gv Note Added: 0001351
2017-02-23 16:59 t-ishii Assigned To => Muhammad Usama
2017-02-23 16:59 t-ishii Status new => assigned
2017-02-23 16:59 t-ishii Description Updated View Revisions
2017-04-07 00:46 Muhammad Usama Status assigned => resolved
2017-04-07 00:46 Muhammad Usama Resolution open => fixed
2017-04-07 00:46 Muhammad Usama Note Added: 0001405