<div dir="ltr"><div><font face="arial, helvetica, sans-serif">Hi Ishii San</font></div><div><font face="arial, helvetica, sans-serif"><br></font></div><div><font face="arial, helvetica, sans-serif">Thanks for looking into this, As discussed over the call please find the attached pgpool log and stack trace for the stuck issue.</font></div><div><font face="arial, helvetica, sans-serif">I am currently not able to trim down the test case so sorry for throwing a huge log file.</font></div><div><font face="arial, helvetica, sans-serif">There is no special configuration on PostgreSQL server side and this issue only happens when the load balance node and the primary node are same</font></div><div><font face="arial, helvetica, sans-serif">and as you can see from the stack trace the stuck happens in the </font><span style="font-family:monospace,monospace">read_kind_from_backend()</span><span style="font-family:arial,helvetica,sans-serif"> function and the reason for that is</span></div><div><span style="font-family:arial,helvetica,sans-serif">the function is trying to read response from the backend node 1(standby) while it has only sent the query to the backend node 0 (primary)</span></div><div><font face="arial, helvetica, sans-serif"><br></font></div><div><font face="monospace, monospace">--stack-trace--</font></div><div><font face="monospace, monospace">#0 0x00007f1775216c53 in __select_nocancel () at ../sysdeps/unix/syscall-template.S:81<br></font></div><div><font face="monospace, monospace">#1 0x000000000042def6 in pool_check_fd (cp=cp@entry=0x7f1776fb2328) at protocol/pool_process_query.c:696</font></div><div><font face="monospace, monospace">#2 0x000000000042e1c6 in pool_check_fd (cp=cp@entry=0x7f1776fb2328) at protocol/pool_process_query.c:728</font></div><div><font face="monospace, monospace">#3 0x000000000045f92c in pool_read (cp=0x7f1776fb2328, buf=buf@entry=0x7ffebb5f2345, len=len@entry=1) at utils/pool_stream.c:166</font></div><div><font face="monospace, monospace">#4 0x0000000000432eab in read_kind_from_backend (frontend=frontend@entry=0x2292e88, backend=backend@entry=0x7f1776fad6d8, decided_kind=decided_kind@entry=0x7ffebb5f274a "D")</font></div><div><font face="monospace, monospace"> at protocol/pool_process_query.c:3379</font></div><div><font face="monospace, monospace">#5 0x000000000043f232 in ProcessBackendResponse (frontend=frontend@entry=0x2292e88, backend=backend@entry=0x7f1776fad6d8, state=state@entry=0x7ffebb5f27b4, </font></div><div><font face="monospace, monospace"> num_fields=num_fields@entry=0x7ffebb5f27b2) at protocol/pool_proto_modules.c:2653</font></div><div><font face="monospace, monospace">#6 0x0000000000431d17 in pool_process_query (frontend=0x2292e88, backend=0x7f1776fad6d8, reset_request=reset_request@entry=0) at protocol/pool_process_query.c:320</font></div><div><font face="monospace, monospace">#7 0x000000000042cbb9 in do_child (fds=fds@entry=0x2291370) at protocol/child.c:387</font></div><div><font face="monospace, monospace">#8 0x00000000004090a5 in fork_a_child (fds=0x2291370, id=2) at main/pgpool_main.c:659</font></div><div><font face="monospace, monospace">#9 0x000000000040fb73 in PgpoolMain (discard_status=discard_status@entry=0 '\000', clear_memcache_oidmaps=clear_memcache_oidmaps@entry=0 '\000') at main/pgpool_main.c:378</font></div><div><font face="monospace, monospace">#10 0x0000000000407777 in main (argc=<optimized out>, argv=<optimized out>) at main/main.c:361</font></div><div><font face="monospace, monospace"><br></font></div><div>Thanks</div><div>Best Regards</div><div>Muhammad Usama</div><div><br></div><br class="gmail-Apple-interchange-newline"><br><div class="gmail_quote"><div dir="ltr">On Thu, Dec 6, 2018 at 3:52 AM Tatsuo Ishii <<a href="mailto:ishii@sraoss.co.jp">ishii@sraoss.co.jp</a>> wrote:<br></div><blockquote class="gmail_quote" style="margin:0 0 0 .8ex;border-left:1px #ccc solid;padding-left:1ex">> Hi Ishii San<br>
> <br>
> I was investigating the issue faced by one of Pgpool-II user who reported<br>
> that after executing a certain transaction (large amount of data DELETE /<br>
> INSERT / UPDATE, COMMIT), the next execution of the BEGIN statement<br>
> hangs(using the extended query protocol).<br>
> <br>
> I think the problem is in pool_is_node_to_be_sent_in_current_query()<br>
> function. The issue is in streaming replication mode, when<br>
> pool_is_query_in_progress is not set, the function always returns true. Now<br>
> consider that we have two backend servers 1 primary and one standby. And<br>
> for a particular session the primary node gets selected as a load balance<br>
> node. So effectively that session should only be sending queries and<br>
> reading responses from primary server alone. But with the current<br>
> implementation of pool_is_node_to_be_sent_in_current_query() the<br>
> VALID_BACKEND macro will return true for standby node as well when the<br>
> query in progress flag is not set(which is wrong when standby node is not<br>
> selected for load balancing). and if this happens in let say<br>
> read_kind_from_backend() function we will get a stuck, since the<br>
> read_kind_from_backend() will be trying to read the response from standby<br>
> node while we have never sent any query to that node.<br>
> <br>
> <br>
> Can you please take a look at the attached patch, I am not sure if it will<br>
> have some side effects or not.<br>
<br>
Unfortunately the patch would not help and probably would break many<br>
cases which are working today.<br>
<br>
For the scenario you mentioned is already handled by<br>
pool_pending_message_* functions defined in<br>
context/query_context.c. When a message, for example parse, is sent<br>
from frontend and forwarded to backends, the info is recorded in an<br>
FIFO queue by pool_pending_message_add() along with info which of<br>
backend the message is forwarded to. When the parse message will be<br>
replied back with "parse complete message" from the backend,<br>
read_kind_message_from_backend() can know from which of backend it<br>
should read a message by looking at the head of the queue. Once the<br>
message is retrieved (in this example parse complete message), an<br>
entry in the queue (in this example parse message) is pulled out and<br>
removed.<br>
<br>
This mechanism usually works well unless backend sends unpredicted<br>
message. Recently one of such a case was reported:<br>
<a href="https://www.pgpool.net/mantisbt/view.php?id=448" rel="noreferrer" target="_blank">https://www.pgpool.net/mantisbt/view.php?id=448</a><br>
<br>
In the report PostgreSQL sends an error message caused by<br>
idle_in_transaction_timeout setting which Pgpool-II does not expect.<br>
<br>
Does the user has any uncommon setting in postgresql.conf?<br>
<br>
Best regards,<br>
--<br>
Tatsuo Ishii<br>
SRA OSS, Inc. Japan<br>
English: <a href="http://www.sraoss.co.jp/index_en.php" rel="noreferrer" target="_blank">http://www.sraoss.co.jp/index_en.php</a><br>
Japanese:<a href="http://www.sraoss.co.jp" rel="noreferrer" target="_blank">http://www.sraoss.co.jp</a><br>
</blockquote></div></div>