<html xmlns:v="urn:schemas-microsoft-com:vml" xmlns:o="urn:schemas-microsoft-com:office:office" xmlns:w="urn:schemas-microsoft-com:office:word" xmlns:x="urn:schemas-microsoft-com:office:excel" xmlns:m="http://schemas.microsoft.com/office/2004/12/omml" xmlns="http://www.w3.org/TR/REC-html40">
<head>
<meta http-equiv="Content-Type" content="text/html; charset=us-ascii">
<meta name="Generator" content="Microsoft Word 15 (filtered medium)">
<style><!--
/* Font Definitions */
@font-face
{font-family:"Cambria Math";
panose-1:2 4 5 3 5 4 6 3 2 4;}
@font-face
{font-family:Calibri;
panose-1:2 15 5 2 2 2 4 3 2 4;}
/* Style Definitions */
p.MsoNormal, li.MsoNormal, div.MsoNormal
{margin:0cm;
margin-bottom:.0001pt;
font-size:11.0pt;
font-family:"Calibri","sans-serif";
mso-fareast-language:EN-US;}
a:link, span.MsoHyperlink
{mso-style-priority:99;
color:#0563C1;
text-decoration:underline;}
a:visited, span.MsoHyperlinkFollowed
{mso-style-priority:99;
color:#954F72;
text-decoration:underline;}
p.MsoPlainText, li.MsoPlainText, div.MsoPlainText
{mso-style-priority:99;
mso-style-link:"Plain Text Char";
margin:0cm;
margin-bottom:.0001pt;
font-size:11.0pt;
font-family:"Calibri","sans-serif";
mso-fareast-language:EN-US;}
span.PlainTextChar
{mso-style-name:"Plain Text Char";
mso-style-priority:99;
mso-style-link:"Plain Text";
font-family:"Calibri","sans-serif";}
.MsoChpDefault
{mso-style-type:export-only;
font-family:"Calibri","sans-serif";
mso-fareast-language:EN-US;}
@page WordSection1
{size:612.0pt 792.0pt;
margin:72.0pt 72.0pt 72.0pt 72.0pt;}
div.WordSection1
{page:WordSection1;}
--></style><!--[if gte mso 9]><xml>
<o:shapedefaults v:ext="edit" spidmax="1026" />
</xml><![endif]--><!--[if gte mso 9]><xml>
<o:shapelayout v:ext="edit">
<o:idmap v:ext="edit" data="1" />
</o:shapelayout></xml><![endif]-->
</head>
<body lang="EN-AU" link="#0563C1" vlink="#954F72">
<div class="WordSection1">
<p class="MsoPlainText">So my question is, why did it timeout too soon without waiting for 10 seconds? Please check my log below<o:p></o:p></p>
<p class="MsoPlainText"><o:p> </o:p></p>
<p class="MsoPlainText">2014-05-13 12:14:43 DEBUG: pid 15822: health_check: 0 th DB node status: 1<o:p></o:p></p>
<p class="MsoPlainText">2014-05-13 12:14:44 LOG: pid 15857: connect_inet_domain_socket: select() timed out. retrying...<o:p></o:p></p>
<p class="MsoPlainText">2014-05-13 12:14:44 ERROR: pid 15822: connect_inet_domain_socket: select() timed out<o:p></o:p></p>
<p class="MsoPlainText">2014-05-13 12:14:44 ERROR: pid 15822: make_persistent_db_connection: connection to 10.0.0.5(5432) failed<o:p></o:p></p>
<p class="MsoPlainText">2014-05-13 12:14:44 DEBUG: pid 15822: health_check: 0 th DB node status: 1<o:p></o:p></p>
<p class="MsoPlainText">2014-05-13 12:14:45 LOG: pid 15857: connect_inet_domain_socket: select() timed out. retrying...<o:p></o:p></p>
<p class="MsoPlainText"><b>2014-05-13 12:14:45 ERROR: pid 15822: connect_inet_domain_socket: select() timed out<o:p></o:p></b></p>
<p class="MsoPlainText">2014-05-13 12:14:45 ERROR: pid 15822: make_persistent_db_connection: connection to 10.0.0.5(5432) failed<o:p></o:p></p>
<p class="MsoPlainText">2014-05-13 12:14:45 ERROR: pid 15822: health check failed. 0 th host 10.0.0.5 at port 5432 is down<o:p></o:p></p>
<p class="MsoPlainText">2014-05-13 12:14:45 DEBUG: pid 15822: health check: clearing alarm<o:p></o:p></p>
<p class="MsoPlainText">2014-05-13 12:14:45 DEBUG: pid 15822: health check: clearing alarm<o:p></o:p></p>
<p class="MsoPlainText">2014-05-13 12:14:45 LOG: pid 15822: health check retry sleep time: 2 second(s)<o:p></o:p></p>
<p class="MsoPlainText">2014-05-13 12:14:46 LOG: pid 15857: connect_inet_domain_socket: select() timed out. retrying...<o:p></o:p></p>
<p class="MsoPlainText">2014-05-13 12:14:47 LOG: pid 15857: connect_inet_domain_socket: select() timed out. retrying...<o:p></o:p></p>
<p class="MsoPlainText"><b>2014-05-13 12:14:47 DEBUG: pid 15822: retrying 1 th health checking<o:p></o:p></b></p>
<p class="MsoPlainText">2014-05-13 12:14:47 DEBUG: pid 15822: health check: clearing alarm<o:p></o:p></p>
<p class="MsoPlainText">2014-05-13 12:14:47 DEBUG: pid 15822: health_check: 0 th DB node status: 1<o:p></o:p></p>
<p class="MsoPlainText">2014-05-13 12:14:48 LOG: pid 15857: connect_inet_domain_socket: select() timed out. retrying...<o:p></o:p></p>
<p class="MsoPlainText"><b>2014-05-13 12:14:48 ERROR: pid 15822: connect_inet_domain_socket: select() timed out<o:p></o:p></b></p>
<p class="MsoPlainText">2014-05-13 12:14:48 ERROR: pid 15822: make_persistent_db_connection: connection to 10.0.0.5(5432) failed<o:p></o:p></p>
<p class="MsoPlainText">2014-05-13 12:14:48 ERROR: pid 15822: health check failed. 0 th host 10.0.0.5 at port 5432 is down<o:p></o:p></p>
<p class="MsoPlainText">2014-05-13 12:14:48 DEBUG: pid 15822: health check: clearing alarm<o:p></o:p></p>
<p class="MsoPlainText">2014-05-13 12:14:48 DEBUG: pid 15822: health check: clearing alarm<o:p></o:p></p>
<p class="MsoPlainText">2014-05-13 12:14:48 LOG: pid 15822: health check retry sleep time: 2 second(s)<o:p></o:p></p>
<p class="MsoPlainText">2014-05-13 12:14:49 LOG: pid 15857: connect_inet_domain_socket: select() timed out. retrying...<o:p></o:p></p>
<p class="MsoPlainText">2014-05-13 12:14:50 LOG: pid 15857: connect_inet_domain_socket: select() timed out. retrying...<o:p></o:p></p>
<p class="MsoPlainText">2014-05-13 12:14:50 DEBUG: pid 15822: retrying 2 th health checking<o:p></o:p></p>
<p class="MsoPlainText">2014-05-13 12:14:50 DEBUG: pid 15822: health check: clearing alarm<o:p></o:p></p>
<p class="MsoPlainText">2014-05-13 12:14:50 DEBUG: pid 15822: health_check: 0 th DB node status: 1<o:p></o:p></p>
<p class="MsoPlainText">2014-05-13 12:14:51 LOG: pid 15857: connect_inet_domain_socket: select() timed out. retrying...<o:p></o:p></p>
<p class="MsoPlainText">2014-05-13 12:14:51 ERROR: pid 15822: connect_inet_domain_socket: select() timed out<o:p></o:p></p>
<p class="MsoPlainText">2014-05-13 12:14:51 ERROR: pid 15822: make_persistent_db_connection: connection to 10.0.0.5(5432) failed<o:p></o:p></p>
<p class="MsoPlainText">2014-05-13 12:14:51 ERROR: pid 15822: health check failed. 0 th host 10.0.0.5 at port 5432 is down<o:p></o:p></p>
<p class="MsoPlainText">2014-05-13 12:14:51 DEBUG: pid 15822: health check: clearing alarm<o:p></o:p></p>
<p class="MsoPlainText">2014-05-13 12:14:51 DEBUG: pid 15822: health check: clearing alarm<o:p></o:p></p>
<p class="MsoPlainText">2014-05-13 12:14:51 LOG: pid 15822: set 0 th backend down status<o:p></o:p></p>
<p class="MsoPlainText">2014-05-13 12:14:51 DEBUG: pid 15822: failover_handler called<o:p></o:p></p>
<p class="MsoPlainText">2014-05-13 12:14:51 DEBUG: pid 15822: failover_handler: starting to select new master node<o:p></o:p></p>
<p class="MsoPlainText"><o:p> </o:p></p>
<p class="MsoPlainText">Thanks & Regards,<o:p></o:p></p>
<p class="MsoPlainText">Shyalika<o:p></o:p></p>
<p class="MsoPlainText"><o:p> </o:p></p>
<p class="MsoPlainText"><span lang="EN-US" style="mso-fareast-language:EN-AU">-----Original Message-----<br>
From: Tatsuo Ishii [mailto:ishii@postgresql.org] <br>
Sent: Friday, 16 May 2014 12:16 PM<br>
To: Shyalika Benthotage<br>
Cc: pgpool-general@pgpool.net<br>
Subject: Re: [pgpool-general: 2835] Issue with pgpool health check timeout</span></p>
<p class="MsoPlainText"><o:p> </o:p></p>
<p class="MsoPlainText">From: Shyalika Benthotage <<a href="mailto:shyalika_benthotage@dialog.com.au"><span style="color:windowtext;text-decoration:none">shyalika_benthotage@dialog.com.au</span></a>><o:p></o:p></p>
<p class="MsoPlainText">Subject: RE: [pgpool-general: 2835] Issue with pgpool health check timeout<o:p></o:p></p>
<p class="MsoPlainText">Date: Fri, 16 May 2014 02:11:27 +0000<o:p></o:p></p>
<p class="MsoPlainText">Message-ID: <<a href="mailto:0C34193B8C9D1249A95AD902CCF181CF14CB66AD@otwdgmxbox01.dialoggroup.internal"><span style="color:windowtext;text-decoration:none">0C34193B8C9D1249A95AD902CCF181CF14CB66AD@otwdgmxbox01.dialoggroup.internal</span></a>><o:p></o:p></p>
<p class="MsoPlainText"><o:p> </o:p></p>
<p class="MsoPlainText">> Hi Ishii,<o:p></o:p></p>
<p class="MsoPlainText">> <o:p></o:p></p>
<p class="MsoPlainText">> Thanks for the quick reply. I tested the pgpool settings using a DROP rule in iptables. I.e. the DROP rule will silently drop data packets without sending a response to the sender, making the sender to wait and then the request to
time out. So I believe in this case the network related system call does not actually return so it should time out. Am I correct?<o:p></o:p></p>
<p class="MsoPlainText"><o:p> </o:p></p>
<p class="MsoPlainText">Yes,correct. More precisely, <o:p></o:p></p>
<p class="MsoPlainText"><o:p> </o:p></p>
<p class="MsoPlainText">non blocking connect(2) issued then select(2) waits for something comes in:<o:p></o:p></p>
<p class="MsoPlainText">>> 2014-05-13 12:14:43 DEBUG: pid 15822: health_check: 0 th DB node<o:p></o:p></p>
<p class="MsoPlainText"><o:p> </o:p></p>
<p class="MsoPlainText">Then select(2) timed out because there is 1 second time out set in the select(2) parameter.<o:p></o:p></p>
<p class="MsoPlainText">>> 2014-05-13 12:14:44 LOG: pid 15857: connect_inet_domain_socket: select() timed out. retrying...<o:p></o:p></p>
<p class="MsoPlainText"><o:p> </o:p></p>
<p class="MsoPlainText">> Thanks & Regards,<o:p></o:p></p>
<p class="MsoPlainText">> Shyalika<o:p></o:p></p>
<p class="MsoPlainText">> <o:p></o:p></p>
<p class="MsoPlainText">> -----Original Message-----<o:p></o:p></p>
<p class="MsoPlainText">> From: Tatsuo Ishii [<a href="mailto:ishii@postgresql.org"><span style="color:windowtext;text-decoration:none">mailto:ishii@postgresql.org</span></a>]<o:p></o:p></p>
<p class="MsoPlainText">> Sent: Friday, 16 May 2014 10:17 AM<o:p></o:p></p>
<p class="MsoPlainText">> To: Shyalika Benthotage<o:p></o:p></p>
<p class="MsoPlainText">> Cc: <a href="mailto:pgpool-general@pgpool.net"><span style="color:windowtext;text-decoration:none">pgpool-general@pgpool.net</span></a><o:p></o:p></p>
<p class="MsoPlainText">> Subject: Re: [pgpool-general: 2835] Issue with pgpool health check
<o:p></o:p></p>
<p class="MsoPlainText">> timeout<o:p></o:p></p>
<p class="MsoPlainText">> <o:p></o:p></p>
<p class="MsoPlainText">>> Hi,<o:p></o:p></p>
<p class="MsoPlainText">>> <o:p></o:p></p>
<p class="MsoPlainText">>> We have configured pgpool 3.3 for our PostgreSQL db in aws. And using the healthcheck parameters as below.<o:p></o:p></p>
<p class="MsoPlainText">>> <o:p></o:p></p>
<p class="MsoPlainText">>> health_check_period = 40<o:p></o:p></p>
<p class="MsoPlainText">>> health_check_timeout = 10<o:p></o:p></p>
<p class="MsoPlainText">>> health_check_max_retries = 2<o:p></o:p></p>
<p class="MsoPlainText">>> health_check_retry_delay = 2<o:p></o:p></p>
<p class="MsoPlainText">>> <o:p></o:p></p>
<p class="MsoPlainText">>> I am trying to test this by using an iptables rule in the active server. When I add a drop rule to the PostgreSQL db port it does trigger a timeout but I think it timeout too soon. I.e. according to my understanding it should wait
for the time period specified in "health_check_timeout " in this case, but actually times out in less than a second.(Please see the log below). Shouldn't it wait for 10 secs before time out or is my understanding incorrect.
<o:p></o:p></p>
<p class="MsoPlainText">> <o:p></o:p></p>
<p class="MsoPlainText">> No. health_check_timeout is a timeout before network related system calls returns. If any of system calls returns error immediately, it is possible that it detects error less than 10 seconds.<o:p></o:p></p>
<p class="MsoPlainText">> <o:p></o:p></p>
<p class="MsoPlainText">>> Please note that I checked my DROP rule with telnet and it takes 60 seconds to time out.<o:p></o:p></p>
<p class="MsoPlainText">>> I have restarted pgpool every time I tested this (I know just
<o:p></o:p></p>
<p class="MsoPlainText">>> reloading would do)<o:p></o:p></p>
<p class="MsoPlainText">>> <o:p></o:p></p>
<p class="MsoPlainText">>> I have enabled debug mode just to check this.<o:p></o:p></p>
<p class="MsoPlainText">>> <o:p></o:p></p>
<p class="MsoPlainText">>> 2014-05-13 12:14:43 DEBUG: pid 15822: health_check: 0 th DB node<o:p></o:p></p>
<p class="MsoPlainText">>> status: 1<o:p></o:p></p>
<p class="MsoPlainText">>> 2014-05-13 12:14:44 LOG: pid 15857: connect_inet_domain_socket: select() timed out. retrying...<o:p></o:p></p>
<p class="MsoPlainText">>> 2014-05-13 12:14:44 ERROR: pid 15822: connect_inet_domain_socket:
<o:p></o:p></p>
<p class="MsoPlainText">>> select() timed out<o:p></o:p></p>
<p class="MsoPlainText">>> 2014-05-13 12:14:44 ERROR: pid 15822: make_persistent_db_connection:
<o:p></o:p></p>
<p class="MsoPlainText">>> connection to 10.0.0.5(5432) failed<o:p></o:p></p>
<p class="MsoPlainText">>> 2014-05-13 12:14:44 DEBUG: pid 15822: health_check: 0 th DB node<o:p></o:p></p>
<p class="MsoPlainText">>> status: 1<o:p></o:p></p>
<p class="MsoPlainText">>> 2014-05-13 12:14:45 LOG: pid 15857: connect_inet_domain_socket: select() timed out. retrying...<o:p></o:p></p>
<p class="MsoPlainText">>> 2014-05-13 12:14:45 ERROR: pid 15822: connect_inet_domain_socket:
<o:p></o:p></p>
<p class="MsoPlainText">>> select() timed out<o:p></o:p></p>
<p class="MsoPlainText">>> 2014-05-13 12:14:45 ERROR: pid 15822: make_persistent_db_connection:
<o:p></o:p></p>
<p class="MsoPlainText">>> connection to 10.0.0.5(5432) failed<o:p></o:p></p>
<p class="MsoPlainText">>> 2014-05-13 12:14:45 ERROR: pid 15822: health check failed. 0 th host<o:p></o:p></p>
<p class="MsoPlainText">>> 10.0.0.5 at port 5432 is down<o:p></o:p></p>
<p class="MsoPlainText">>> 2014-05-13 12:14:45 DEBUG: pid 15822: health check: clearing alarm<o:p></o:p></p>
<p class="MsoPlainText">>> 2014-05-13 12:14:45 DEBUG: pid 15822: health check: clearing alarm<o:p></o:p></p>
<p class="MsoPlainText">>> 2014-05-13 12:14:45 LOG: pid 15822: health check retry sleep time: 2<o:p></o:p></p>
<p class="MsoPlainText">>> second(s)<o:p></o:p></p>
<p class="MsoPlainText">>> 2014-05-13 12:14:46 LOG: pid 15857: connect_inet_domain_socket: select() timed out. retrying...<o:p></o:p></p>
<p class="MsoPlainText">>> 2014-05-13 12:14:47 LOG: pid 15857: connect_inet_domain_socket: select() timed out. retrying...<o:p></o:p></p>
<p class="MsoPlainText">>> 2014-05-13 12:14:47 DEBUG: pid 15822: retrying 1 th health checking<o:p></o:p></p>
<p class="MsoPlainText">>> 2014-05-13 12:14:47 DEBUG: pid 15822: health check: clearing alarm<o:p></o:p></p>
<p class="MsoPlainText">>> 2014-05-13 12:14:47 DEBUG: pid 15822: health_check: 0 th DB node<o:p></o:p></p>
<p class="MsoPlainText">>> status: 1<o:p></o:p></p>
<p class="MsoPlainText">>> 2014-05-13 12:14:48 LOG: pid 15857: connect_inet_domain_socket: select() timed out. retrying...<o:p></o:p></p>
<p class="MsoPlainText">>> 2014-05-13 12:14:48 ERROR: pid 15822: connect_inet_domain_socket:
<o:p></o:p></p>
<p class="MsoPlainText">>> select() timed out<o:p></o:p></p>
<p class="MsoPlainText">>> 2014-05-13 12:14:48 ERROR: pid 15822: make_persistent_db_connection:
<o:p></o:p></p>
<p class="MsoPlainText">>> connection to 10.0.0.5(5432) failed<o:p></o:p></p>
<p class="MsoPlainText">>> 2014-05-13 12:14:48 ERROR: pid 15822: health check failed. 0 th host<o:p></o:p></p>
<p class="MsoPlainText">>> 10.0.0.5 at port 5432 is down<o:p></o:p></p>
<p class="MsoPlainText">>> 2014-05-13 12:14:48 DEBUG: pid 15822: health check: clearing alarm<o:p></o:p></p>
<p class="MsoPlainText">>> 2014-05-13 12:14:48 DEBUG: pid 15822: health check: clearing alarm<o:p></o:p></p>
<p class="MsoPlainText">>> 2014-05-13 12:14:48 LOG: pid 15822: health check retry sleep time: 2<o:p></o:p></p>
<p class="MsoPlainText">>> second(s)<o:p></o:p></p>
<p class="MsoPlainText">>> 2014-05-13 12:14:49 LOG: pid 15857: connect_inet_domain_socket: select() timed out. retrying...<o:p></o:p></p>
<p class="MsoPlainText">>> 2014-05-13 12:14:50 LOG: pid 15857: connect_inet_domain_socket: select() timed out. retrying...<o:p></o:p></p>
<p class="MsoPlainText">>> 2014-05-13 12:14:50 DEBUG: pid 15822: retrying 2 th health checking<o:p></o:p></p>
<p class="MsoPlainText">>> 2014-05-13 12:14:50 DEBUG: pid 15822: health check: clearing alarm<o:p></o:p></p>
<p class="MsoPlainText">>> 2014-05-13 12:14:50 DEBUG: pid 15822: health_check: 0 th DB node<o:p></o:p></p>
<p class="MsoPlainText">>> status: 1<o:p></o:p></p>
<p class="MsoPlainText">>> 2014-05-13 12:14:51 LOG: pid 15857: connect_inet_domain_socket: select() timed out. retrying...<o:p></o:p></p>
<p class="MsoPlainText">>> 2014-05-13 12:14:51 ERROR: pid 15822: connect_inet_domain_socket:
<o:p></o:p></p>
<p class="MsoPlainText">>> select() timed out<o:p></o:p></p>
<p class="MsoPlainText">>> 2014-05-13 12:14:51 ERROR: pid 15822: make_persistent_db_connection:
<o:p></o:p></p>
<p class="MsoPlainText">>> connection to 10.0.0.5(5432) failed<o:p></o:p></p>
<p class="MsoPlainText">>> 2014-05-13 12:14:51 ERROR: pid 15822: health check failed. 0 th host<o:p></o:p></p>
<p class="MsoPlainText">>> 10.0.0.5 at port 5432 is down<o:p></o:p></p>
<p class="MsoPlainText">>> 2014-05-13 12:14:51 DEBUG: pid 15822: health check: clearing alarm<o:p></o:p></p>
<p class="MsoPlainText">>> 2014-05-13 12:14:51 DEBUG: pid 15822: health check: clearing alarm<o:p></o:p></p>
<p class="MsoPlainText">>> 2014-05-13 12:14:51 LOG: pid 15822: set 0 th backend down status<o:p></o:p></p>
<p class="MsoPlainText">>> 2014-05-13 12:14:51 DEBUG: pid 15822: failover_handler called<o:p></o:p></p>
<p class="MsoPlainText">>> 2014-05-13 12:14:51 DEBUG: pid 15822: failover_handler: starting to
<o:p></o:p></p>
<p class="MsoPlainText">>> select new master node<o:p></o:p></p>
<p class="MsoPlainText">>> <o:p></o:p></p>
<p class="MsoPlainText">>> I even tried setting health_check_timeout to 0 to see whether it defaults to TCP/IP timeout. No difference.<o:p></o:p></p>
<p class="MsoPlainText">>> <o:p></o:p></p>
<p class="MsoPlainText">>> Regards,<o:p></o:p></p>
<p class="MsoPlainText">>> Shyalika<o:p></o:p></p>
<p class="MsoPlainText">>> <o:p></o:p></p>
</div>
</body>
</html>