<div dir="ltr">Hi<div style>Thanks for your update.</div><div style>I have installed the changes and compile.</div><div style>Will follow the behavior now and update.</div><div style>Do you recommend to upgrade to 3.2.4? Will this fix be included there?</div>
<div style><br></div><div style>Thanks</div><div style>Larisa.</div></div><div class="gmail_extra"><br><br><div class="gmail_quote">On Tue, Jul 16, 2013 at 6:08 AM, Tatsuo Ishii <span dir="ltr">&lt;<a href="mailto:ishii@postgresql.org" target="_blank">ishii@postgresql.org</a>&gt;</span> wrote:<br>
<blockquote class="gmail_quote" style="margin:0 0 0 .8ex;border-left:1px #ccc solid;padding-left:1ex">Oops. Small correction to the patch.<br>
<br>
+               if (health_check_timer_expired &amp;&amp; getpid() != mypid)            /* has health check timer expired */<br>
<br>
should be:<br>
<br>
+               if (health_check_timer_expired &amp;&amp; getpid() == mypid)            /* has health check timer expired */<br>
<br>
Included is the new patch.<br>
--<br>
Tatsuo Ishii<br>
SRA OSS, Inc. Japan<br>
English: <a href="http://www.sraoss.co.jp/index_en.php" target="_blank">http://www.sraoss.co.jp/index_en.php</a><br>
Japanese: <a href="http://www.sraoss.co.jp" target="_blank">http://www.sraoss.co.jp</a><br>
<br>
&gt; Ok. I think I finally understand what&#39;s going on here.<br>
&gt;<br>
&gt; Pgpool main process (14317) started health checking at Jul 12 09:17:04.<br>
&gt;<br>
&gt; Jul 12 09:17:04 purple1-node1-ps pgpool[14317]: starting health checking<br>
&gt;<br>
&gt; Pgpool main process set timer at 09:17:14 because you set<br>
&gt; health_check_timeout 10.  This time the health check successfully<br>
&gt; completed. The timer for 09:17:14 is blocked by calling<br>
&gt; signal(SIGALRM, SIG_IGN).<br>
&gt;<br>
&gt; Unfortunately child life time was expired at 09:17:14 and pgpool main<br>
&gt; process was busy at the time because of this.<br>
&gt;<br>
&gt; Jul 12 09:17:14 purple1-node1-ps pgpool[16789]: child life 300 seconds expired<br>
&gt; Jul 12 09:17:14 purple1-node1-ps pgpool[14317]: reap_handler called<br>
&gt;<br>
&gt; Jul 12 09:17:14 purple1-node1-ps pgpool[14317]: starting health checking<br>
&gt;<br>
&gt; Pgpool main re-enabled the timer and reset the timer variable<br>
&gt; (health_check_timer_expired = 0). But when the timer re-enabled, the<br>
&gt; signal handler for the timer set health_check_timer_expired to 1.  As<br>
&gt; a result pgpool thought that health check timer was expired.<br>
&gt;<br>
&gt; Jul 12 09:17:14 purple1-node1-ps pgpool[14317]: health_check: health check timer has been already expired before attempting to connect to 0 th backend<br>
&gt;<br>
&gt; Thus failover happend even if the backend was running fine.<br>
&gt;<br>
&gt; Besides this,<br>
&gt;<br>
&gt;&gt;&gt; This seems very strange. The error comes here:<br>
&gt;<br>
&gt; I can now think of an explanation. When child life time is expired,<br>
&gt; pgpool fork off new process. If the global variable<br>
&gt; health_check_timer_expired to 1 for the reason above, it is possible<br>
&gt; the problem you saw could happen because child process inherits this.<br>
&gt;<br>
&gt; Includes patch addresses the problems above. Could you try it out?<br>
&gt; --<br>
&gt; Tatsuo Ishii<br>
&gt; SRA OSS, Inc. Japan<br>
&gt; English: <a href="http://www.sraoss.co.jp/index_en.php" target="_blank">http://www.sraoss.co.jp/index_en.php</a><br>
&gt; Japanese: <a href="http://www.sraoss.co.jp" target="_blank">http://www.sraoss.co.jp</a><br>
&gt;<br>
&gt;&gt; Hi, thanks for your reply.<br>
&gt;&gt;<br>
&gt;&gt;&gt;&gt; What kind of pgpool installation are you using?<br>
&gt;&gt;  I comlile pgpool from source code, pgpool-II-3.2.3.tar.gz<br>
&gt;&gt;&gt;&gt;  What kind of platform are you using?<br>
&gt;&gt; We use Ubuntu 12.04 on HP Cloud server.<br>
&gt;&gt;<br>
&gt;&gt;&gt;&gt; How is like your pgpool.conf?<br>
&gt;&gt; Attaching pgpool.conf<br>
&gt;&gt;<br>
&gt;&gt; Also attached syslog file from the time of a problem. You can look for a<br>
&gt;&gt; line<br>
&gt;&gt; &quot;Jul 12 09:32:14 purple1-node1-ps pgpool[11465]: I am 11465 accept fd 7&quot;<br>
&gt;&gt;<br>
&gt;&gt; By the way postgres was up and running at that time, there is nothing in<br>
&gt;&gt; the logs from it and its procceses uptime shows week ago...<br>
&gt;&gt;<br>
&gt;&gt; Thanks in advance for your help<br>
&gt;&gt; Larisa.<br>
&gt;&gt;<br>
&gt;&gt;<br>
&gt;&gt;<br>
&gt;&gt; On Mon, Jul 15, 2013 at 5:00 AM, Tatsuo Ishii &lt;<a href="mailto:ishii@postgresql.org">ishii@postgresql.org</a>&gt; wrote:<br>
&gt;&gt;<br>
&gt;&gt;&gt; &gt; Hi<br>
&gt;&gt;&gt; &gt; I am hitting the same issue as described in the mail [pgpool-general:<br>
&gt;&gt;&gt; 1815]<br>
&gt;&gt;&gt; &gt; Pgpool is unable to connect backend PostgreSQL.<br>
&gt;&gt;&gt;<br>
&gt;&gt;&gt; I guess [pgpool-general: 1815] is different from you (my guess is the<br>
&gt;&gt;&gt; case somewhat related to Amazon EC2 environment problem). Moreover,<br>
&gt;&gt;&gt; you case seems very unique and strange.<br>
&gt;&gt;&gt;<br>
&gt;&gt;&gt; &gt; While connected to a single postgres node, after a while pgpool looses<br>
&gt;&gt;&gt; &gt; connection to a running postgres db, restarts all children processes and<br>
&gt;&gt;&gt; &gt; stays in running state unable to connect to db.<br>
&gt;&gt;&gt; &gt;<br>
&gt;&gt;&gt; &gt; Pgpool version 3.2.3<br>
&gt;&gt;&gt; &gt; Postgres version 9.2.4<br>
&gt;&gt;&gt; &gt;<br>
&gt;&gt;&gt; &gt; Part of the log:<br>
&gt;&gt;&gt; &gt; --------------------<br>
&gt;&gt;&gt; &gt; Jul 12 09:32:14 purple1-node1-ps pgpool[11465]: connection received:<br>
&gt;&gt;&gt; &gt; host=10.4.225.120 port=41090<br>
&gt;&gt;&gt;<br>
&gt;&gt;&gt; Process 11465 is a pgpool child process and is responsible for actual<br>
&gt;&gt;&gt; pgpool functions.<br>
&gt;&gt;&gt;<br>
&gt;&gt;&gt; &gt; Jul 12 09:32:14 purple1-node1-ps pgpool[11465]: Protocol Major: 3 Minor:<br>
&gt;&gt;&gt; 0<br>
&gt;&gt;&gt; &gt; database: hpadb user: hpauser<br>
&gt;&gt;&gt; &gt; Jul 12 09:32:14 purple1-node1-ps pgpool[11465]: new_connection:<br>
&gt;&gt;&gt; connecting<br>
&gt;&gt;&gt; &gt; 0 backend<br>
&gt;&gt;&gt; &gt; Jul 12 09:32:14 purple1-node1-ps pgpool[11465]:<br>
&gt;&gt;&gt; &gt; connect_inet_domain_socket_by_port: health check timer expired<br>
&gt;&gt;&gt;<br>
&gt;&gt;&gt; This seems very strange. The error comes here:<br>
&gt;&gt;&gt;<br>
&gt;&gt;&gt;                 if (health_check_timer_expired)         /* has health<br>
&gt;&gt;&gt; check timer expired */<br>
&gt;&gt;&gt;                 {<br>
&gt;&gt;&gt;                         pool_log(&quot;connect_inet_domain_socket_by_port:<br>
&gt;&gt;&gt; health check timer expired&quot;);<br>
&gt;&gt;&gt;                         close(fd);<br>
&gt;&gt;&gt;                         return -1;<br>
&gt;&gt;&gt;                 }<br>
&gt;&gt;&gt;<br>
&gt;&gt;&gt; &quot;health_check_timer_expired&quot; is a global variable used in pgpool main<br>
&gt;&gt;&gt; process, which is responsible for management of pgpool, including:<br>
&gt;&gt;&gt; health check, failover etc. The variable is only meaningful in the<br>
&gt;&gt;&gt; main process and should not be set to non 0 in pgpool child. Moreover,<br>
&gt;&gt;&gt; the only place set the variable to non 0 is the signal handler which<br>
&gt;&gt;&gt; is set by main process.<br>
&gt;&gt;&gt;<br>
&gt;&gt;&gt; One the error occurs, pgpool starts failover as you see.<br>
&gt;&gt;&gt;<br>
&gt;&gt;&gt; I&#39;ve never seen this kind of report before. What kind of pgpool<br>
&gt;&gt;&gt; installation are you using? (compiled from source code or from<br>
&gt;&gt;&gt; packes?) What kind of platform are you using? How is like your<br>
&gt;&gt;&gt; pgpool.conf?<br>
&gt;&gt;&gt; --<br>
&gt;&gt;&gt; Tatsuo Ishii<br>
&gt;&gt;&gt; SRA OSS, Inc. Japan<br>
&gt;&gt;&gt; English: <a href="http://www.sraoss.co.jp/index_en.php" target="_blank">http://www.sraoss.co.jp/index_en.php</a><br>
&gt;&gt;&gt; Japanese: <a href="http://www.sraoss.co.jp" target="_blank">http://www.sraoss.co.jp</a><br>
&gt;&gt;&gt;<br>
&gt;&gt;&gt; &gt; Jul 12 09:32:14 purple1-node1-ps pgpool[11465]: connection to<br>
&gt;&gt;&gt; &gt; purple1_node1_ps(5432) failed<br>
&gt;&gt;&gt; &gt; Jul 12 09:32:14 purple1-node1-ps pgpool[11465]: new_connection:<br>
&gt;&gt;&gt; create_cp()<br>
&gt;&gt;&gt; &gt; failed<br>
&gt;&gt;&gt; &gt; Jul 12 09:32:14 purple1-node1-ps pgpool[11465]: degenerate_backend_set: 0<br>
&gt;&gt;&gt; &gt; fail over request from pid 11465<br>
&gt;&gt;&gt; &gt; Jul 12 09:32:14 purple1-node1-ps pgpool[14317]: failover_handler called<br>
&gt;&gt;&gt; &gt; Jul 12 09:32:14 purple1-node1-ps pgpool[14317]: failover_handler:<br>
&gt;&gt;&gt; starting<br>
&gt;&gt;&gt; &gt; to select new master node<br>
&gt;&gt;&gt; &gt; Jul 12 09:32:14 purple1-node1-ps pgpool[14317]: starting degeneration.<br>
&gt;&gt;&gt; &gt; shutdown host purple1_node1_ps(5432)<br>
&gt;&gt;&gt; &gt; Jul 12 09:32:14 purple1-node1-ps pgpool[14317]: failover_handler: no<br>
&gt;&gt;&gt; valid<br>
&gt;&gt;&gt; &gt; DB node found<br>
&gt;&gt;&gt; &gt; Jul 12 09:32:14 purple1-node1-ps pgpool[14317]: Restart all children<br>
&gt;&gt;&gt; &gt; Jul 12 09:32:14 purple1-node1-ps pgpool[14317]: failover_handler: kill<br>
&gt;&gt;&gt; 4388<br>
&gt;&gt;&gt; &gt; Jul 12 09:32:14 purple1-node1-ps pgpool[14317]: failover_handler: kill<br>
&gt;&gt;&gt; 9597<br>
&gt;&gt;&gt; &gt; Jul 12 09:32:14 purple1-node1-ps pgpool[18648]: child received shutdown<br>
&gt;&gt;&gt; &gt; request signal 3<br>
&gt;&gt;&gt; &gt; Jul 12 09:32:14 purple1-node1-ps pgpool[4388]: child received shutdown<br>
&gt;&gt;&gt; &gt; request signal 3<br>
&gt;&gt;&gt; &gt; Jul 12 09:32:14 purple1-node1-ps rsyslogd-2177: imuxsock lost 85 messages<br>
&gt;&gt;&gt; &gt; from pid 9597 due to rate-limiting<br>
&gt;&gt;&gt; &gt; Jul 12 09:32:14 purple1-node1-ps pgpool[9597]: child received shutdown<br>
&gt;&gt;&gt; &gt; request signal 3<br>
&gt;&gt;&gt; &gt; Jul 12 09:32:14 purple1-node1-ps pgpool[14317]: failover_handler: kill<br>
&gt;&gt;&gt; 18648<br>
&gt;&gt;&gt; &gt; Jul 12 09:32:14 purple1-node1-ps pgpool[29409]: child received shutdown<br>
&gt;&gt;&gt; &gt; request signal 3<br>
&gt;&gt;&gt; &gt; Jul 12 09:32:14 purple1-node1-ps pgpool[14317]: failover_handler: kill<br>
&gt;&gt;&gt; 29409<br>
&gt;&gt;&gt; &gt; Jul 12 09:32:14 purple1-node1-ps pgpool[14317]: failover_handler: kill<br>
&gt;&gt;&gt; 11454<br>
&gt;&gt;&gt; &gt; Jul 12 09:32:14 purple1-node1-ps pgpool[14323]: child received shutdown<br>
&gt;&gt;&gt; &gt; request signal 3<br>
&gt;&gt;&gt; &gt; Jul 12 09:32:14 purple1-node1-ps pgpool[11454]: child received shutdown<br>
&gt;&gt;&gt; &gt; request signal 3<br>
&gt;&gt;&gt; &gt; Jul 12 09:32:14 purple1-node1-ps pgpool[14317]: failover_handler: kill<br>
&gt;&gt;&gt; 14323<br>
&gt;&gt;&gt; &gt; Jul 12 09:32:14 purple1-node1-ps pgpool[14317]: failover_handler: kill<br>
&gt;&gt;&gt; 22349<br>
&gt;&gt;&gt; &gt; Jul 12 09:32:14 purple1-node1-ps pgpool[22349]: child received shutdown<br>
&gt;&gt;&gt; &gt; request signal 3<br>
&gt;&gt;&gt; &gt; Jul 12 09:32:14 purple1-node1-ps pgpool[14317]: failover_handler: kill<br>
&gt;&gt;&gt; 23617<br>
&gt;&gt;&gt; &gt; Jul 12 09:32:14 purple1-node1-ps pgpool[14317]: failover_handler: kill<br>
&gt;&gt;&gt; 29410<br>
&gt;&gt;&gt; &gt; Jul 12 09:32:14 purple1-node1-ps pgpool[31511]: child received shutdown<br>
&gt;&gt;&gt; &gt; request signal 3<br>
&gt;&gt;&gt; &gt; Jul 12 09:32:14 purple1-node1-ps pgpool[29410]: child received shutdown<br>
&gt;&gt;&gt; &gt; request signal 3<br>
&gt;&gt;&gt; &gt; Jul 12 09:32:14 purple1-node1-ps pgpool[14317]: failover_handler: kill<br>
&gt;&gt;&gt; 31511<br>
&gt;&gt;&gt; &gt; Jul 12 09:32:14 purple1-node1-ps pgpool[4385]: child received shutdown<br>
&gt;&gt;&gt; &gt; request signal 3<br>
&gt;&gt;&gt; &gt; Jul 12 09:32:14 purple1-node1-ps rsyslogd-2177: imuxsock lost 757<br>
&gt;&gt;&gt; messages<br>
&gt;&gt;&gt; &gt; from pid 23617 due to rate-limiting<br>
&gt;&gt;&gt; &gt;<br>
&gt;&gt;&gt; &gt; Could you please explain?<br>
&gt;&gt;&gt; &gt; Thanks<br>
&gt;&gt;&gt; &gt; Larisa.<br>
&gt;&gt;&gt;<br>
</blockquote></div><br></div>