<html><body><div style="color:#000; background-color:#fff; font-family:HelveticaNeue, Helvetica Neue, Helvetica, Arial, Lucida Grande, sans-serif;font-size:16px"><div id="yui_3_16_0_1_1429845726565_5971">Thanks for your explanation.</div><div id="yui_3_16_0_1_1429845726565_8027"><br></div><div id="yui_3_16_0_1_1429845726565_5972" dir="ltr">I agree that it probably is a postgres timeout issue and not a problem with pgpool, per se. But if you can explain a little more on what is happening with pgpool, I will be able to work out a solution for the problem.</div><div id="yui_3_16_0_1_1429845726565_6418" dir="ltr"><br></div><div id="yui_3_16_0_1_1429845726565_5973" dir="ltr">The error message says ---<br></div><div id="yui_3_16_0_1_1429845726565_5974" dir="ltr"><br></div><div id="yui_3_16_0_1_1429845726565_5975" dir="ltr">kind mismatch among backends. Possible last query was: "COMMIT" kind
details are: 0[C] 1[E: canceling statement due to statement timeout]</div><div id="yui_3_16_0_1_1429845726565_5976"><br><span></span></div><div id="yui_3_16_0_1_1429845726565_5979" dir="ltr"><span id="yui_3_16_0_1_1429845726565_6417">I am assuming that means that the operation completed on node 0[C] and got an error on node 1[E]. So here are my questions -</span></div><div id="yui_3_16_0_1_1429845726565_10448" dir="ltr"><span id="yui_3_16_0_1_1429845726565_6417">1) Node 0 is the primary node, which means that commit should only happen on node 0 ?<br></span></div><div id="yui_3_16_0_1_1429845726565_10449" dir="ltr"><span id="yui_3_16_0_1_1429845726565_6417">2) Or is the commit sent to node 1 (hot standby) also ? I am using explicit transaction begin and commit.</span></div><div id="yui_3_16_0_1_1429845726565_10450" dir="ltr"><span id="yui_3_16_0_1_1429845726565_6417">3) If the commit is sent to node 1 also, then I am assuming actual updates are not happeing in this transaction but only through replication. So node 1 should not ideally not take too long to commit and finish quickly.</span></div><div id="yui_3_16_0_1_1429845726565_10451" dir="ltr"><span id="yui_3_16_0_1_1429845726565_6417">4) Is it that the commit to node 1 goes after the node 0 has been committed and node 1 has run out of time.</span></div><div id="yui_3_16_0_1_1429845726565_10452" dir="ltr"><span id="yui_3_16_0_1_1429845726565_6417">5) This happens only in production and not in test env, so pg_locks will not help because I come to know of the issue after several hours. Is there a way to capture the lock state just before or after the failure.</span></div><div id="yui_3_16_0_1_1429845726565_10646" dir="ltr"><span id="yui_3_16_0_1_1429845726565_6417">6) One last question, even though node 1 times out, the data has actually been updated. Since node 0 reports success, can we just ignore the error from node 1 until we find a correct solution to the problem.</span></div><div id="yui_3_16_0_1_1429845726565_11459" dir="ltr"><br><span id="yui_3_16_0_1_1429845726565_6417"></span></div><div id="yui_3_16_0_1_1429845726565_11458" dir="ltr"><span id="yui_3_16_0_1_1429845726565_6417">Thanks for any help you can provide.</span></div><div id="yui_3_16_0_1_1429845726565_11457" dir="ltr"><br><span id="yui_3_16_0_1_1429845726565_6417"></span></div><div id="yui_3_16_0_1_1429845726565_11456" dir="ltr"><span id="yui_3_16_0_1_1429845726565_6417">Regards,</span></div><div id="yui_3_16_0_1_1429845726565_11455" dir="ltr"><span id="yui_3_16_0_1_1429845726565_6417">Anupama.</span></div><div id="yui_3_16_0_1_1429845726565_11641" dir="ltr"><span id="yui_3_16_0_1_1429845726565_6417"><br></span></div><div id="yui_3_16_0_1_1429845726565_11642" dir="ltr"><br><span id="yui_3_16_0_1_1429845726565_6417"></span></div><div id="yui_3_16_0_1_1429845726565_11643" dir="ltr"><span id="yui_3_16_0_1_1429845726565_6417"></span></div> <br><div class="qtdSeparateBR"><br><br></div><div style="display: block;" class="yahoo_quoted"> <div style="font-family: HelveticaNeue, Helvetica Neue, Helvetica, Arial, Lucida Grande, sans-serif; font-size: 16px;"> <div style="font-family: HelveticaNeue, Helvetica Neue, Helvetica, Arial, Lucida Grande, sans-serif; font-size: 16px;"> <div dir="ltr"> <font face="Arial" size="2"> On Friday, April 24, 2015 4:29 AM, Tatsuo Ishii <ishii@postgresql.org> wrote:<br> </font> </div> <br><br> <div class="y_msg_container">Sounds like a PostgreSQL issue and irrelevant to pgpool-II.<br clear="none"><br clear="none">> My pg-pool setup is as follows -<br clear="none">> I use Pgpool II - 3.3.1<br clear="none">> Two 9.1 backends in load balanced mode. The 2 backends use postgres streaming replication.DB node 0 - primary node, DB node 1 - hot standby<br clear="none">> We are __not__ using pgpool for connection pool or replication.Front end is a web application using JDBC + DBCP connection pool.<br clear="none">> <br clear="none">> I see the error in the pgpool logs as shown below, for one of the updates in my application.<br clear="none">> Some details on the nature of the transaction -<br clear="none">> There are several records updated across multiple tables, in a single transaction. Each update statement updates only a few records. 2 of these tables have deferred update triggers.<br clear="none">> Total time consumed in completing all the updates could be high (say 1-2 minutes), but each update could take only 1-2 seconds, not more. The default statement timeout is set at 30 seconds.<br clear="none">> I have increased the statement timeout to 3 minutes, just to make sure that the transaction goes to completion.The above error happens only some times and not always. <br clear="none"><br clear="none">Apparently the statement took more than 30 seconds.<br clear="none"><br clear="none">> Apr 23 09:54:27 auhhisapp01 pgpool[25760]: DB node id: 1 backend pid: 28735 statement: Parse: set statement_timeout = 30000<br clear="none"><br clear="none">This sets the timeout to 30 seconds, not 3 minutes. The only solution<br clear="none">I can think of is, disabling the statement_timeout or increasing it.<br clear="none"><br clear="none">Another possiblity is, the COMMIT on node 1 was waiting for taking a<br clear="none">lock hold by someone else. You could check the siuation by using<br clear="none">pg_locks view.<div class="yqt7487084623" id="yqtfd39522"><br clear="none"><br clear="none">> Looks like, node 0 reports completion of transaction, while node 1 reports an statement timeout error.<br clear="none">> <br clear="none">> What am I doing wrong and how do I go about troubleshooting this ?<br clear="none">> Thanks for your help. <br clear="none">> <br clear="none">> ================ Pgpool error logs ===============================================Apr 23 09:54:27 auhhisapp01 pgpool[25760]: DB node id: 0 backend pid: 944 statement: Execute: set search_path = 'nmc'<br clear="none">> Apr 23 09:54:27 auhhisapp01 pgpool[25760]: DB node id: 1 backend pid: 28735 statement: Execute: set search_path = 'nmc'<br clear="none">> Apr 23 09:54:27 auhhisapp01 pgpool[25760]: DB node id: 0 backend pid: 944 statement: Parse: set statement_timeout = 30000<br clear="none">> Apr 23 09:54:27 auhhisapp01 pgpool[25760]: DB node id: 1 backend pid: 28735 statement: Parse: set statement_timeout = 30000<br clear="none">> Apr 23 09:54:27 auhhisapp01 rsyslogd-2177: imuxsock begins to drop messages from pid 25760 due to rate-limiting<br clear="none">> Apr 23 09:54:29 auhhisapp01 pgpool[12387]: DB node id: 1 backend pid: 28738 statement: Execute: COMMIT<br clear="none">> Apr 23 09:54:29 auhhisapp01 pgpool[12387]: pool_send_and_wait: Error or notice message from backend: : DB node id: 1 backend pid: 28738 statement: COMMIT message: canceling statement due to statement timeout<br clear="none">> Apr 23 09:54:29 auhhisapp01 pgpool[12387]: read_kind_from_backend: 1 th kind E does not match with master or majority connection kind C<br clear="none">> Apr 23 09:54:29 auhhisapp01 pgpool[12387]: kind mismatch among backends. Possible last query was: "COMMIT" kind details are: 0[C] 1[E: canceling statement due to statement timeout]<br clear="none">> Apr 23 09:54:29 auhhisapp01 pgpool[12387]: do_child: exits with status 1 due to error<br clear="none">> Apr 23 09:54:30 auhhisapp01 pgpool[15802]: DB node id: 0 backend pid: 15013 statement: Parse: set search_path = 'nmc'<br clear="none">> Apr 23 09:54:30 auhhisapp01 pgpool[15802]: DB node id: 1 backend pid: 5694 statement: Parse: set search_path = 'nmc'<br clear="none">> Apr 23 09:54:30 auhhisapp01 pgpool[15802]: DB node id: 0 backend pid: 15013 statement: B message<br clear="none">> =============================================================================================<br clear="none">> <br clear="none">> <br clear="none">> </div><br><br></div> </div> </div> </div></div></body></html>