Thanks Toshihiro,<br><br>for responding and for your interest in resolving this issue. This one affects all, regardless of latency, but with higher latency it becomes more dominant.<br><br>Regards,<br>Stevo.<br><br><div class="gmail_quote">
On Thu, Dec 1, 2011 at 3:48 AM, Toshihiro Kitagawa <span dir="ltr"><<a href="mailto:kitagawa@sraoss.co.jp">kitagawa@sraoss.co.jp</a>></span> wrote:<br><blockquote class="gmail_quote" style="margin:0 0 0 .8ex;border-left:1px #ccc solid;padding-left:1ex;">
Hi Stevo,<br>
<br>
Sorry for delay.<br>
<div class="im"><br>
On Fri, 25 Nov 2011 07:09:40 -0700<br>
Stevo Slavić <<a href="mailto:sslavic@gmail.com">sslavic@gmail.com</a>> wrote:<br>
<br>
> Thanks Toshihiro for the feedback! I very much appreciate that.<br>
><br>
> Can you please provide any hints/tips on where blocking occurs in the code,<br>
> and advices on what needs to be changed to have backend messages to be<br>
> processed in parallel? If it's not too significant change affecting rest of<br>
> pgpool features, might decide to do that change in a custom build, at least<br>
> temporarily.<br>
<br>
</div>Probably, the function which is blocking is pool_extended_send_and_wait().<br>
pool_extended_send_and_wait() is called from Parse(), Bind(), Describe(),<br>
Execute() and etc.<br>
<br>
I think that to avoid blocking, we need to replace<br>
pool_extended_send_and_wait() with a function which doesn't wait a backend<br>
response and to control skip_reading_from_backends flag.<br>
<br>
However...<br>
<br>
Changing code is difficult because the handring of extended query protocol<br>
is complex.<br>
<br>
I am interested in this issue, but even if I was able to fix it, it will<br>
take long time.<br>
<br>
Regards,<br>
<div class="HOEnZb"><div class="h5"><br>
--<br>
Toshihiro Kitagawa<br>
SRA OSS, Inc. Japan<br>
<br>
><br>
> Would you consider supporting both concurrent and sequential processing of<br>
> backend messages, make it configurable option and for backward<br>
> compatibility (especially with non-java clients) have it default to<br>
> sequential?<br>
><br>
> Or maybe even go with concurrent for all clients and let non-java drivers<br>
> fix their support to be proper one and aligned with postgres<br>
> frontend/backend protocol specification and capabilities?<br>
><br>
> Regards,<br>
> Stevo.<br>
><br>
> On Fri, Nov 25, 2011 at 12:47 AM, Toshihiro Kitagawa<br>
> <<a href="mailto:kitagawa@sraoss.co.jp">kitagawa@sraoss.co.jp</a>>wrote:<br>
><br>
> > On Thu, 24 Nov 2011 18:19:11 +0900 (JST)<br>
> > Tatsuo Ishii <<a href="mailto:ishii@sraoss.co.jp">ishii@sraoss.co.jp</a>> wrote:<br>
> ><br>
> > > I'm not sure why pgpool need to wait for backend response here. Maybe<br>
> > > Toshihiro has some idea about this. Toshihiro?<br>
> ><br>
> > I guess that the implementation for extended query protocol only succeeded<br>
> > to the simple design which relay a message at every message.<br>
> ><br>
> > I think that pgpool doesn't need to wait for backend response until Sync<br>
> > message, if frontend is JDBC driver. However, it might cause problem with<br>
> > the other drivers.<br>
> ><br>
> > --<br>
> > Toshihiro Kitagawa<br>
> > SRA OSS, Inc. Japan<br>
> ><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>
> > > > Thanks Tatsuo for quick response!<br>
> > > ><br>
> > > > If it was Java based, I would be much more able to contribute in fixing<br>
> > > > this issue. Child processes which handle connections/communication<br>
> > seem to<br>
> > > > be single threaded. Not sure where does pgpool block, must be somewhere<br>
> > > > when reading and/or sending postgres protocol message. Maybe profiling<br>
> > > > pgpool executable would help - any advices on how to do that properly<br>
> > are<br>
> > > > welcome.<br>
> > > ><br>
> > > > Is pgpool issue tracker at pgfoundry still being used (<br>
> > > > <a href="http://pgfoundry.org/tracker/?atid=298&group_id=1000055&func=browse" target="_blank">http://pgfoundry.org/tracker/?atid=298&group_id=1000055&func=browse</a> )<br>
> > ?<br>
> > > > Checking whether to report this issue there or somewhere else.<br>
> > > ><br>
> > > > Would this issue even be considered for fixing or is this design<br>
> > decision<br>
> > > > that's not likely to be changed any time soon? Need this info to decide<br>
> > > > whether to stick with pgpool (much preferred) or look for other<br>
> > solutions.<br>
> > > ><br>
> > > > Regards,<br>
> > > > Stevo.<br>
> > > ><br>
> > > > 2011/11/24 Tatsuo Ishii <<a href="mailto:ishii@sraoss.co.jp">ishii@sraoss.co.jp</a>><br>
> > > ><br>
> > > >> > As temporary solution, is it possible to force pgpool to use v2<br>
> > protocol<br>
> > > >> > when communicating with backend?<br>
> > > >><br>
> > > >> No.<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>
> > > >> > If yes, can pgpool at the same time use v3 protocol to communicate<br>
> > with<br>
> > > >> the<br>
> > > >> > clients (postgresql jdbc driver)?<br>
> > > >> ><br>
> > > >> > Regards,<br>
> > > >> > Stevo.<br>
> > > >> ><br>
> > > >> > On Wed, Nov 23, 2011 at 11:46 AM, Stevo Slavić <<a href="mailto:sslavic@gmail.com">sslavic@gmail.com</a>><br>
> > > >> wrote:<br>
> > > >> ><br>
> > > >> >> It's definitely pgpool issue with serializing postgres<br>
> > frontend/backend<br>
> > > >> >> protocol messages. Tried on environment with actual (non-simulated)<br>
> > > >> >> latency. Same work takes 5 times longer with pgpool then without<br>
> > it.<br>
> > > >> >><br>
> > > >> >> Using pgpool 3.1.<br>
> > > >> >><br>
> > > >> >> Regards,<br>
> > > >> >> Stevo.<br>
> > > >> >><br>
> > > >> >><br>
> > > >> >> On Mon, Nov 21, 2011 at 3:28 PM, Stevo Slavić <<a href="mailto:sslavic@gmail.com">sslavic@gmail.com</a>><br>
> > > >> wrote:<br>
> > > >> >><br>
> > > >> >>> Hello pgpool users,<br>
> > > >> >>><br>
> > > >> >>> Using tc (see <a href="http://linux.die.net/man/8/tc" target="_blank">http://linux.die.net/man/8/tc</a> ) I'm simulating 60ms<br>
> > > >> >>> latency between pgpool and a master backend. When executing a<br>
> > simple<br>
> > > >> query<br>
> > > >> >>> over pgpool, backend messages seem to get serialized (see [1],<br>
> > notice<br>
> > > >> 60ms+<br>
> > > >> >>> between almost every backend message), while when executing same<br>
> > query<br>
> > > >> on<br>
> > > >> >>> same backend but directly (not through pgpool), backend messages<br>
> > get<br>
> > > >> sent<br>
> > > >> >>> concurrently (see [2]) back to the driver/client.<br>
> > > >> >>><br>
> > > >> >>> Query is executed from a simple CLI Java application which makes<br>
> > use of<br>
> > > >> >>> postgresql-9.1-901.jdbc4.jar driver, with logging enabled. See [3]<br>
> > > >> pgpool<br>
> > > >> >>> debug log when this query is executed through pgpool.<br>
> > > >> >>><br>
> > > >> >>> Does anyone have any ideas why is pgpool serializing these backend<br>
> > > >> >>> messages?<br>
> > > >> >>><br>
> > > >> >>> Is there a way to enable postgres protocol messages logging in<br>
> > pgpool?<br>
> > > >> >>> Would like to configure that to see if pgpool is receiving<br>
> > messages.<br>
> > > >> >>><br>
> > > >> >>> Also timestamp log format seems to fixed, and doesn't include<br>
> > > >> >>> milliseconds. Any way to change that?<br>
> > > >> >>><br>
> > > >> >>> Regards,<br>
> > > >> >>> Stevo.<br>
> > > >> >>><br>
> > > >> >>><br>
> > > >> >>> [1] jdbc driver log output, query execution through pgpool<br>
> > > >> >>> 23:03:22.625 (1) PostgreSQL 9.1 JDBC4 (build 901)<br>
> > > >> >>> 23:03:22.646 (1) Trying to establish a protocol version 3<br>
> > connection to<br>
> > > >> >>> pgsql_srv_standby:9999<br>
> > > >> >>> 23:03:22.709 (1)  FE=> StartupPacket(user=foo, database=foo,<br>
> > > >> >>> client_encoding=UTF8, DateStyle=ISO, extra_float_digits=2)<br>
> > > >> >>> 23:03:22.835 (1)  <=BE AuthenticationOk<br>
> > > >> >>> 23:03:22.849 (1)  <=BE ParameterStatus(application_name = )<br>
> > > >> >>> 23:03:22.849 (1)  <=BE ParameterStatus(client_encoding = UTF8)<br>
> > > >> >>> 23:03:22.851 (1)  <=BE ParameterStatus(DateStyle = ISO, MDY)<br>
> > > >> >>> 23:03:22.851 (1)  <=BE ParameterStatus(integer_datetimes = on)<br>
> > > >> >>> 23:03:22.851 (1)  <=BE ParameterStatus(IntervalStyle = postgres)<br>
> > > >> >>> 23:03:22.851 (1)  <=BE ParameterStatus(is_superuser = on)<br>
> > > >> >>> 23:03:22.851 (1)  <=BE ParameterStatus(server_encoding = UTF8)<br>
> > > >> >>> 23:03:22.851 (1)  <=BE ParameterStatus(server_version = 9.1.1)<br>
> > > >> >>> 23:03:22.852 (1)  <=BE ParameterStatus(session_authorization =<br>
> > foo)<br>
> > > >> >>> 23:03:22.852 (1)  <=BE<br>
> > ParameterStatus(standard_conforming_strings =<br>
> > > >> on)<br>
> > > >> >>> 23:03:22.852 (1)  <=BE ParameterStatus(TimeZone =<br>
> > Europe/Amsterdam)<br>
> > > >> >>> 23:03:22.852 (1)  <=BE BackendKeyData(pid=24275,ckey=1498571326)<br>
> > > >> >>> 23:03:22.852 (1)  <=BE ReadyForQuery(I)<br>
> > > >> >>> 23:03:22.858 (1) simple execute,<br>
> > > >> >>><br>
> > > >><br>
> > handler=org.postgresql.core.SetupQueryRunner$SimpleResultHandler@7f54ee6,<br>
> > > >> >>> maxRows=0, fetchSize=0, flags=23<br>
> > > >> >>> 23:03:22.864 (1)  FE=> Parse(stmt=null,query="SET<br>
> > extra_float_digits =<br>
> > > >> >>> 3",oids={})<br>
> > > >> >>> 23:03:22.873 (1)  FE=> Bind(stmt=null,portal=null)<br>
> > > >> >>> 23:03:22.873 (1)  FE=> Execute(portal=null,limit=1)<br>
> > > >> >>> 23:03:22.874 (1)  FE=> Sync<br>
> > > >> >>> 23:03:22.934 (1)  <=BE ParseComplete [null]<br>
> > > >> >>> 23:03:22.995 (1)  <=BE BindComplete [null]<br>
> > > >> >>> 23:03:23.057 (1)  <=BE CommandStatus(SET)<br>
> > > >> >>> 23:03:23.118 (1)  <=BE ReadyForQuery(I)<br>
> > > >> >>> 23:03:23.118 (1)     compatible = 9.1<br>
> > > >> >>> 23:03:23.118 (1)     loglevel = 2<br>
> > > >> >>> 23:03:23.118 (1)     prepare threshold = 5<br>
> > > >> >>> getConnection returning<br>
> > > >> >>><br>
> > driver[className=org.postgresql.Driver,org.postgresql.Driver@7f05238]<br>
> > > >> >>> 23:03:23.150 (1) simple execute,<br>
> > > >> >>><br>
> > > >><br>
> > handler=org.postgresql.jdbc2.AbstractJdbc2Statement$StatementResultHandler@7f64160<br>
> > > >> ,<br>
> > > >> >>> maxRows=0, fetchSize=0, flags=17<br>
> > > >> >>> 23:03:23.150 (1)  FE=> Parse(stmt=null,query="select<br>
> > > >> >>> nextval('hibernate_sequence')",oids={})<br>
> > > >> >>> 23:03:23.150 (1)  FE=> Bind(stmt=null,portal=null)<br>
> > > >> >>> 23:03:23.151 (1)  FE=> Describe(portal=null)<br>
> > > >> >>> 23:03:23.151 (1)  FE=> Execute(portal=null,limit=0)<br>
> > > >> >>> 23:03:23.151 (1)  FE=> Sync<br>
> > > >> >>> 23:03:23.212 (1)  <=BE ParseComplete [null]<br>
> > > >> >>> 23:03:23.273 (1)  <=BE BindComplete [null]<br>
> > > >> >>> 23:03:23.335 (1)  <=BE RowDescription(1)<br>
> > > >> >>> 23:03:23.396 (1)  <=BE DataRow<br>
> > > >> >>> 23:03:23.396 (1)  <=BE CommandStatus(SELECT 1)<br>
> > > >> >>> 23:03:23.456 (1)  <=BE ReadyForQuery(I)<br>
> > > >> >>> 23:03:23.462 (1)  FE=> Terminate<br>
> > > >> >>><br>
> > > >> >>> [2] jdbc driver log output, query execution directly on backend<br>
> > > >> >>> 21:16:05.428 (1) simple execute,<br>
> > > >> >>><br>
> > > >><br>
> > handler=org.postgresql.jdbc2.AbstractJdbc2Statement$StatementResultHandler@7f74161<br>
> > > >> ,<br>
> > > >> >>> maxRows=0, fetchSize=0, flags=17<br>
> > > >> >>> 21:16:05.428 (1)  FE=> Parse(stmt=null,query="select<br>
> > > >> >>> nextval('hibernate_sequence')",oids={})<br>
> > > >> >>> 21:16:05.428 (1)  FE=> Bind(stmt=null,portal=null)<br>
> > > >> >>> 21:16:05.428 (1)  FE=> Describe(portal=null)<br>
> > > >> >>> 21:16:05.428 (1)  FE=> Execute(portal=null,limit=0)<br>
> > > >> >>> 21:16:05.428 (1)  FE=> Sync<br>
> > > >> >>> 21:16:05.489 (1)  <=BE ParseComplete [null]<br>
> > > >> >>> 21:16:05.489 (1)  <=BE BindComplete [null]<br>
> > > >> >>> 21:16:05.489 (1)  <=BE RowDescription(1)<br>
> > > >> >>> 21:16:05.489 (1)  <=BE DataRow<br>
> > > >> >>> 21:16:05.489 (1)  <=BE CommandStatus(SELECT 1)<br>
> > > >> >>> 21:16:05.489 (1)  <=BE ReadyForQuery(I)<br>
> > > >> >>><br>
> > > >> >>> [3] pgpool debug log<br>
> > > >> >>> 2011-11-21 23:03:22 DEBUG: pid 30055: key: pid_file_name<br>
> > > >> >>> 2011-11-21 23:03:22 DEBUG: pid 30055: value:<br>
> > > >> >>> '/var/run/pgpool-II-91/pgpool.pid' kind: 4<br>
> > > >> >>> 2011-11-21 23:03:22 DEBUG: pid 30055: key: logdir<br>
> > > >> >>> 2011-11-21 23:03:22 DEBUG: pid 30055: value: '/data/postgresql_db'<br>
> > > >> kind: 4<br>
> > > >> >>> 2011-11-21 23:03:22 DEBUG: pid 30055: key: connection_cache<br>
> > > >> >>> 2011-11-21 23:03:22 DEBUG: pid 30055: value: off kind: 1<br>
> > > >> >>> 2011-11-21 23:03:22 DEBUG: pid 30055: key: reset_query_list<br>
> > > >> >>> 2011-11-21 23:03:22 DEBUG: pid 30055: value: 'ABORT; DISCARD ALL'<br>
> > > >> kind: 4<br>
> > > >> >>> 2011-11-21 23:03:22 DEBUG: pid 30055: extract_string_tokens:<br>
> > token:<br>
> > > >> ABORT<br>
> > > >> >>> 2011-11-21 23:03:22 DEBUG: pid 30055: extract_string_tokens:<br>
> > token:<br>
> > > >> >>>  DISCARD ALL<br>
> > > >> >>> 2011-11-21 23:03:22 DEBUG: pid 30055: key: replication_mode<br>
> > > >> >>> 2011-11-21 23:03:22 DEBUG: pid 30055: value: off kind: 1<br>
> > > >> >>> 2011-11-21 23:03:22 DEBUG: pid 30055: key: replicate_select<br>
> > > >> >>> 2011-11-21 23:03:22 DEBUG: pid 30055: value: off kind: 1<br>
> > > >> >>> 2011-11-21 23:03:22 DEBUG: pid 30055: replicate_select: 0<br>
> > > >> >>> 2011-11-21 23:03:22 DEBUG: pid 30055: key: insert_lock<br>
> > > >> >>> 2011-11-21 23:03:22 DEBUG: pid 30055: value: off kind: 1<br>
> > > >> >>> 2011-11-21 23:03:22 DEBUG: pid 30055: key: lobj_lock_table<br>
> > > >> >>> 2011-11-21 23:03:22 DEBUG: pid 30055: value: '' kind: 4<br>
> > > >> >>> 2011-11-21 23:03:22 DEBUG: pid 30055: key:<br>
> > replication_stop_on_mismatch<br>
> > > >> >>> 2011-11-21 23:03:22 DEBUG: pid 30055: value: off kind: 1<br>
> > > >> >>> 2011-11-21 23:03:22 DEBUG: pid 30055:<br>
> > replication_stop_on_mismatch: 0<br>
> > > >> >>> 2011-11-21 23:03:22 DEBUG: pid 30055: key:<br>
> > > >> >>> failover_if_affected_tuples_mismatch<br>
> > > >> >>> 2011-11-21 23:03:22 DEBUG: pid 30055: value: off kind: 1<br>
> > > >> >>> 2011-11-21 23:03:22 DEBUG: pid 30055:<br>
> > > >> >>> failover_if_affected_tuples_mismatch: 0<br>
> > > >> >>> 2011-11-21 23:03:22 DEBUG: pid 30055: key: load_balance_mode<br>
> > > >> >>> 2011-11-21 23:03:22 DEBUG: pid 30055: value: off kind: 1<br>
> > > >> >>> 2011-11-21 23:03:22 DEBUG: pid 30055: key:<br>
> > ignore_leading_white_space<br>
> > > >> >>> 2011-11-21 23:03:22 DEBUG: pid 30055: value: on kind: 1<br>
> > > >> >>> 2011-11-21 23:03:22 DEBUG: pid 30055: key: white_function_list<br>
> > > >> >>> 2011-11-21 23:03:22 DEBUG: pid 30055: value: '' kind: 4<br>
> > > >> >>> 2011-11-21 23:03:22 DEBUG: pid 30055: key: black_function_list<br>
> > > >> >>> 2011-11-21 23:03:22 DEBUG: pid 30055: value:<br>
> > > >> >>> 'currval,lastval,nextval,setval' kind: 4<br>
> > > >> >>> 2011-11-21 23:03:22 DEBUG: pid 30055: extract_string_tokens:<br>
> > token:<br>
> > > >> >>> currval<br>
> > > >> >>> 2011-11-21 23:03:22 DEBUG: pid 30055: extract_string_tokens:<br>
> > token:<br>
> > > >> >>> lastval<br>
> > > >> >>> 2011-11-21 23:03:22 DEBUG: pid 30055: extract_string_tokens:<br>
> > token:<br>
> > > >> >>> nextval<br>
> > > >> >>> 2011-11-21 23:03:22 DEBUG: pid 30055: extract_string_tokens:<br>
> > token:<br>
> > > >> setval<br>
> > > >> >>> 2011-11-21 23:03:22 DEBUG: pid 30055: add_to_patterns: regex<br>
> > pattern:<br>
> > > >> >>> ^currval$<br>
> > > >> >>> 2011-11-21 23:03:22 DEBUG: pid 30055: add_to_patterns: regex<br>
> > pattern:<br>
> > > >> >>> ^lastval$<br>
> > > >> >>> 2011-11-21 23:03:22 DEBUG: pid 30055: add_to_patterns: regex<br>
> > pattern:<br>
> > > >> >>> ^nextval$<br>
> > > >> >>> 2011-11-21 23:03:22 DEBUG: pid 30055: add_to_patterns: regex<br>
> > pattern:<br>
> > > >> >>> ^setval$<br>
> > > >> >>> 2011-11-21 23:03:22 DEBUG: pid 30055: key: backend_hostname0<br>
> > > >> >>> 2011-11-21 23:03:22 DEBUG: pid 30055: value: 'pgsql_srv_primary'<br>
> > kind:<br>
> > > >> 4<br>
> > > >> >>> 2011-11-21 23:03:22 DEBUG: pid 30055: key: backend_port0<br>
> > > >> >>> 2011-11-21 23:03:22 DEBUG: pid 30055: value: 5432 kind: 2<br>
> > > >> >>> 2011-11-21 23:03:22 DEBUG: pid 30055: key: backend_weight0<br>
> > > >> >>> 2011-11-21 23:03:22 DEBUG: pid 30055: value: 1 kind: 2<br>
> > > >> >>> 2011-11-21 23:03:22 DEBUG: pid 30055: key: backend_data_directory0<br>
> > > >> >>> 2011-11-21 23:03:22 DEBUG: pid 30055: value: '/data/postgresql_db'<br>
> > > >> kind: 4<br>
> > > >> >>> 2011-11-21 23:03:22 DEBUG: pid 30055: key: backend_flag0<br>
> > > >> >>> 2011-11-21 23:03:22 DEBUG: pid 30055: value: 'ALLOW_TO_FAILOVER'<br>
> > kind:<br>
> > > >> 4<br>
> > > >> >>> 2011-11-21 23:03:22 DEBUG: pid 30055: key: backend_hostname1<br>
> > > >> >>> 2011-11-21 23:03:22 DEBUG: pid 30055: value: '/tmp' kind: 4<br>
> > > >> >>> 2011-11-21 23:03:22 DEBUG: pid 30055: key: backend_port1<br>
> > > >> >>> 2011-11-21 23:03:22 DEBUG: pid 30055: value: 5432 kind: 2<br>
> > > >> >>> 2011-11-21 23:03:22 DEBUG: pid 30055: key: backend_weight1<br>
> > > >> >>> 2011-11-21 23:03:22 DEBUG: pid 30055: value: 1 kind: 2<br>
> > > >> >>> 2011-11-21 23:03:22 DEBUG: pid 30055: key: backend_data_directory1<br>
> > > >> >>> 2011-11-21 23:03:22 DEBUG: pid 30055: value: '/data/postgresql_db'<br>
> > > >> kind: 4<br>
> > > >> >>> 2011-11-21 23:03:22 DEBUG: pid 30055: key: backend_flag1<br>
> > > >> >>> 2011-11-21 23:03:22 DEBUG: pid 30055: value:<br>
> > 'DISALLOW_TO_FAILOVER'<br>
> > > >> kind:<br>
> > > >> >>> 4<br>
> > > >> >>> 2011-11-21 23:03:22 DEBUG: pid 30055: key: master_slave_mode<br>
> > > >> >>> 2011-11-21 23:03:22 DEBUG: pid 30055: value: off kind: 1<br>
> > > >> >>> 2011-11-21 23:03:22 DEBUG: pid 30055: key: master_slave_sub_mode<br>
> > > >> >>> 2011-11-21 23:03:22 DEBUG: pid 30055: value: 'stream' kind: 4<br>
> > > >> >>> 2011-11-21 23:03:22 DEBUG: pid 30055: key: sr_check_period<br>
> > > >> >>> 2011-11-21 23:03:22 DEBUG: pid 30055: value: 10 kind: 2<br>
> > > >> >>> 2011-11-21 23:03:22 DEBUG: pid 30055: key: sr_check_user<br>
> > > >> >>> 2011-11-21 23:03:22 DEBUG: pid 30055: value: 'foo' kind: 4<br>
> > > >> >>> 2011-11-21 23:03:22 DEBUG: pid 30055: key: sr_check_password<br>
> > > >> >>> 2011-11-21 23:03:22 DEBUG: pid 30055: value: '' kind: 4<br>
> > > >> >>> 2011-11-21 23:03:22 DEBUG: pid 30055: key: delay_threshold<br>
> > > >> >>> 2011-11-21 23:03:22 DEBUG: pid 30055: value: 10000000 kind: 2<br>
> > > >> >>> 2011-11-21 23:03:22 DEBUG: pid 30055: key: follow_master_command<br>
> > > >> >>> 2011-11-21 23:03:22 DEBUG: pid 30055: value: '' kind: 4<br>
> > > >> >>> 2011-11-21 23:03:22 DEBUG: pid 30055: key: parallel_mode<br>
> > > >> >>> 2011-11-21 23:03:22 DEBUG: pid 30055: value: off kind: 1<br>
> > > >> >>> 2011-11-21 23:03:22 DEBUG: pid 30055: key: enable_query_cache<br>
> > > >> >>> 2011-11-21 23:03:22 DEBUG: pid 30055: value: off kind: 1<br>
> > > >> >>> 2011-11-21 23:03:22 DEBUG: pid 30055: key: pgpool2_hostname<br>
> > > >> >>> 2011-11-21 23:03:22 DEBUG: pid 30055: value: 'pgsql_srv_standby'<br>
> > kind:<br>
> > > >> 4<br>
> > > >> >>> 2011-11-21 23:03:22 DEBUG: pid 30055: key: system_db_hostname<br>
> > > >> >>> 2011-11-21 23:03:22 DEBUG: pid 30055: value: 'pgsql_srv_primary'<br>
> > kind:<br>
> > > >> 4<br>
> > > >> >>> 2011-11-21 23:03:22 DEBUG: pid 30055: key: system_db_port<br>
> > > >> >>> 2011-11-21 23:03:22 DEBUG: pid 30055: value: 5432 kind: 2<br>
> > > >> >>> 2011-11-21 23:03:22 DEBUG: pid 30055: key: system_db_dbname<br>
> > > >> >>> 2011-11-21 23:03:22 DEBUG: pid 30055: value: 'pgpool' kind: 4<br>
> > > >> >>> 2011-11-21 23:03:22 DEBUG: pid 30055: key: system_db_schema<br>
> > > >> >>> 2011-11-21 23:03:22 DEBUG: pid 30055: value: 'pgpool_catalog'<br>
> > kind: 4<br>
> > > >> >>> 2011-11-21 23:03:22 DEBUG: pid 30055: key: system_db_user<br>
> > > >> >>> 2011-11-21 23:03:22 DEBUG: pid 30055: value: 'postgres' kind: 4<br>
> > > >> >>> 2011-11-21 23:03:22 DEBUG: pid 30055: key: system_db_password<br>
> > > >> >>> 2011-11-21 23:03:22 DEBUG: pid 30055: value: '' kind: 4<br>
> > > >> >>> 2011-11-21 23:03:22 DEBUG: pid 30055: key: health_check_period<br>
> > > >> >>> 2011-11-21 23:03:22 DEBUG: pid 30055: value: 0 kind: 2<br>
> > > >> >>> 2011-11-21 23:03:22 DEBUG: pid 30055: key: health_check_timeout<br>
> > > >> >>> 2011-11-21 23:03:22 DEBUG: pid 30055: value: 20 kind: 2<br>
> > > >> >>> 2011-11-21 23:03:22 DEBUG: pid 30055: key: health_check_user<br>
> > > >> >>> 2011-11-21 23:03:22 DEBUG: pid 30055: value: 'foo' kind: 4<br>
> > > >> >>> 2011-11-21 23:03:22 DEBUG: pid 30055: key: health_check_password<br>
> > > >> >>> 2011-11-21 23:03:22 DEBUG: pid 30055: value: 'foo' kind: 4<br>
> > > >> >>> 2011-11-21 23:03:22 DEBUG: pid 30055: key:<br>
> > fail_over_on_backend_error<br>
> > > >> >>> 2011-11-21 23:03:22 DEBUG: pid 30055: value: on kind: 1<br>
> > > >> >>> 2011-11-21 23:03:22 DEBUG: pid 30055: key: recovery_user<br>
> > > >> >>> 2011-11-21 23:03:22 DEBUG: pid 30055: value: 'nobody' kind: 4<br>
> > > >> >>> 2011-11-21 23:03:22 DEBUG: pid 30055: key: recovery_password<br>
> > > >> >>> 2011-11-21 23:03:22 DEBUG: pid 30055: value: '' kind: 4<br>
> > > >> >>> 2011-11-21 23:03:22 DEBUG: pid 30055: key:<br>
> > recovery_1st_stage_command<br>
> > > >> >>> 2011-11-21 23:03:22 DEBUG: pid 30055: value: '' kind: 4<br>
> > > >> >>> 2011-11-21 23:03:22 DEBUG: pid 30055: key:<br>
> > recovery_2nd_stage_command<br>
> > > >> >>> 2011-11-21 23:03:22 DEBUG: pid 30055: value: '' kind: 4<br>
> > > >> >>> 2011-11-21 23:03:22 DEBUG: pid 30055: key: recovery_timeout<br>
> > > >> >>> 2011-11-21 23:03:22 DEBUG: pid 30055: value: 90 kind: 2<br>
> > > >> >>> 2011-11-21 23:03:22 DEBUG: pid 30055: key:<br>
> > > >> client_idle_limit_in_recovery<br>
> > > >> >>> 2011-11-21 23:03:22 DEBUG: pid 30055: value: 0 kind: 2<br>
> > > >> >>> 2011-11-21 23:03:22 DEBUG: pid 30055: key: relcache_expire<br>
> > > >> >>> 2011-11-21 23:03:22 DEBUG: pid 30055: value: 0 kind: 2<br>
> > > >> >>> 2011-11-21 23:03:22 DEBUG: pid 30055: num_backends: 2<br>
> > total_weight:<br>
> > > >> >>> 2.000000<br>
> > > >> >>> 2011-11-21 23:03:22 DEBUG: pid 30055: backend 0 weight:<br>
> > > >> 1073741823.500000<br>
> > > >> >>> 2011-11-21 23:03:22 DEBUG: pid 30055: backend 0 flag: 0000<br>
> > > >> >>> 2011-11-21 23:03:22 DEBUG: pid 30055: backend 1 weight:<br>
> > > >> 1073741823.500000<br>
> > > >> >>> 2011-11-21 23:03:22 DEBUG: pid 30055: backend 1 flag: 0001<br>
> > > >> >>> 2011-11-21 23:03:22 DEBUG: pid 30055: I am 30055 accept fd 5<br>
> > > >> >>> 2011-11-21 23:03:22 LOG:   pid 30055: connection received:<br>
> > > >> >>> host=pgsql_srv_standby port=32291<br>
> > > >> >>> 2011-11-21 23:03:22 DEBUG: pid 30055: Protocol Major: 3 Minor: 0<br>
> > > >> >>> database: foo user: foo<br>
> > > >> >>> 2011-11-21 23:03:22 DEBUG: pid 30055: new_connection: connecting 0<br>
> > > >> backend<br>
> > > >> >>> 2011-11-21 23:03:22 DEBUG: pid 30055: new_connection: connecting 1<br>
> > > >> backend<br>
> > > >> >>> 2011-11-21 23:03:22 DEBUG: pid 30055: new_connection: skipping<br>
> > slot 1<br>
> > > >> >>> because backend_status = 1<br>
> > > >> >>> 2011-11-21 23:03:22 DEBUG: pid 30055: pool_ssl: SSL requested but<br>
> > SSL<br>
> > > >> >>> support is not available<br>
> > > >> >>> 2011-11-21 23:03:22 DEBUG: pid 30055: pool_read_message_length:<br>
> > slot: 0<br>
> > > >> >>> length: 8<br>
> > > >> >>> 2011-11-21 23:03:22 DEBUG: pid 30055: pool_do_auth: auth kind:0<br>
> > > >> >>> 2011-11-21 23:03:22 DEBUG: pid 30055: pool_read_message_length2:<br>
> > master<br>
> > > >> >>> slot: 0 length: 22<br>
> > > >> >>> 2011-11-21 23:03:22 DEBUG: pid 30055: 0 th backend: name:<br>
> > > >> >>> application_name value:<br>
> > > >> >>> 2011-11-21 23:03:22 DEBUG: pid 30055: pool_read_message_length2:<br>
> > master<br>
> > > >> >>> slot: 0 length: 25<br>
> > > >> >>> 2011-11-21 23:03:22 DEBUG: pid 30055: 0 th backend: name:<br>
> > > >> client_encoding<br>
> > > >> >>> value: UTF8<br>
> > > >> >>> 2011-11-21 23:03:22 DEBUG: pid 30055: pool_read_message_length2:<br>
> > master<br>
> > > >> >>> slot: 0 length: 23<br>
> > > >> >>> 2011-11-21 23:03:22 DEBUG: pid 30055: 0 th backend: name:<br>
> > DateStyle<br>
> > > >> >>> value: ISO, MDY<br>
> > > >> >>> 2011-11-21 23:03:22 DEBUG: pid 30055: pool_read_message_length2:<br>
> > master<br>
> > > >> >>> slot: 0 length: 25<br>
> > > >> >>> 2011-11-21 23:03:22 DEBUG: pid 30055: 0 th backend: name:<br>
> > > >> >>> integer_datetimes value: on<br>
> > > >> >>> 2011-11-21 23:03:22 DEBUG: pid 30055: pool_read_message_length2:<br>
> > master<br>
> > > >> >>> slot: 0 length: 27<br>
> > > >> >>> 2011-11-21 23:03:22 DEBUG: pid 30055: 0 th backend: name:<br>
> > IntervalStyle<br>
> > > >> >>> value: postgres<br>
> > > >> >>> 2011-11-21 23:03:22 DEBUG: pid 30055: pool_read_message_length2:<br>
> > master<br>
> > > >> >>> slot: 0 length: 20<br>
> > > >> >>> 2011-11-21 23:03:22 DEBUG: pid 30055: 0 th backend: name:<br>
> > is_superuser<br>
> > > >> >>> value: on<br>
> > > >> >>> 2011-11-21 23:03:22 DEBUG: pid 30055: pool_read_message_length2:<br>
> > master<br>
> > > >> >>> slot: 0 length: 25<br>
> > > >> >>> 2011-11-21 23:03:22 DEBUG: pid 30055: 0 th backend: name:<br>
> > > >> server_encoding<br>
> > > >> >>> value: UTF8<br>
> > > >> >>> 2011-11-21 23:03:22 DEBUG: pid 30055: pool_read_message_length2:<br>
> > master<br>
> > > >> >>> slot: 0 length: 25<br>
> > > >> >>> 2011-11-21 23:03:22 DEBUG: pid 30055: 0 th backend: name:<br>
> > > >> server_version<br>
> > > >> >>> value: 9.1.1<br>
> > > >> >>> 2011-11-21 23:03:22 DEBUG: pid 30055: pool_read_message_length2:<br>
> > master<br>
> > > >> >>> slot: 0 length: 33<br>
> > > >> >>> 2011-11-21 23:03:22 DEBUG: pid 30055: 0 th backend: name:<br>
> > > >> >>> session_authorization value: foo<br>
> > > >> >>> 2011-11-21 23:03:22 DEBUG: pid 30055: pool_read_message_length2:<br>
> > master<br>
> > > >> >>> slot: 0 length: 35<br>
> > > >> >>> 2011-11-21 23:03:22 DEBUG: pid 30055: 0 th backend: name:<br>
> > > >> >>> standard_conforming_strings value: on<br>
> > > >> >>> 2011-11-21 23:03:22 DEBUG: pid 30055: pool_read_message_length2:<br>
> > master<br>
> > > >> >>> slot: 0 length: 30<br>
> > > >> >>> 2011-11-21 23:03:22 DEBUG: pid 30055: 0 th backend: name: TimeZone<br>
> > > >> value:<br>
> > > >> >>> Europe/Amsterdam<br>
> > > >> >>> 2011-11-21 23:03:22 DEBUG: pid 30055: pool_read_message_length:<br>
> > slot: 0<br>
> > > >> >>> length: 12<br>
> > > >> >>> 2011-11-21 23:03:22 DEBUG: pid 30055: pool_do_auth:<br>
> > > >> >>> cp->info[i]:0x2aacd4239800 pid:24275<br>
> > > >> >>> 2011-11-21 23:03:22 DEBUG: pid 30055: pool_send_auth_ok: send pid<br>
> > 24275<br>
> > > >> >>> to frontend<br>
> > > >> >>> 2011-11-21 23:03:22 DEBUG: pid 30055:<br>
> > pool_unset_query_in_progress:<br>
> > > >> done<br>
> > > >> >>> 2011-11-21 23:03:22 DEBUG: pid 30055: pool_unset_command_success:<br>
> > done<br>
> > > >> >>> 2011-11-21 23:03:22 DEBUG: pid 30055:<br>
> > pool_unset_writing_transaction:<br>
> > > >> done<br>
> > > >> >>> 2011-11-21 23:03:22 DEBUG: pid 30055:<br>
> > pool_unset_failed_transaction:<br>
> > > >> done<br>
> > > >> >>> 2011-11-21 23:03:22 DEBUG: pid 30055:<br>
> > pool_unset_transaction_isolation:<br>
> > > >> >>> done<br>
> > > >> >>> 2011-11-21 23:03:22 DEBUG: pid 30055:<br>
> > > >> >>> pool_unset_skip_reading_from_backends: done<br>
> > > >> >>> 2011-11-21 23:03:22 DEBUG: pid 30055:<br>
> > pool_unset_ignore_till_sync: done<br>
> > > >> >>> 2011-11-21 23:03:22 DEBUG: pid 30055: read_kind_from_backend:<br>
> > read kind<br>
> > > >> >>> from 0 th backend Z NUM_BACKENDS: 2<br>
> > > >> >>> 2011-11-21 23:03:22 DEBUG: pid 30055: ProcessBackendResponse:<br>
> > kind from<br>
> > > >> >>> backend: Z<br>
> > > >> >>> 2011-11-21 23:03:22 DEBUG: pid 30055: pool_read_message_length:<br>
> > slot: 0<br>
> > > >> >>> length: 5<br>
> > > >> >>> 2011-11-21 23:03:22 DEBUG: pid 30055: ReadyForQuery: transaction<br>
> > > >> state:NUL<br>
> > > >> >>> 2011-11-21 23:03:22 DEBUG: pid 30055: ProcessFrontendResponse:<br>
> > kind<br>
> > > >> from<br>
> > > >> >>> frontend P(50)<br>
> > > >> >>> 2011-11-21 23:03:22 DEBUG: pid 30055:<br>
> > > >> >>> pool_unset_doing_extended_query_message: done<br>
> > > >> >>> 2011-11-21 23:03:22 DEBUG: pid 30055:<br>
> > > >> >>> pool_set_doing_extended_query_message: done<br>
> > > >> >>> 2011-11-21 23:03:22 DEBUG: pid 30055: pool_set_query_in_progress:<br>
> > done<br>
> > > >> >>> 2011-11-21 23:03:22 DEBUG: pid 30055: Parse: statement name <><br>
> > > >> >>> 2011-11-21 23:03:22 DEBUG: pid 30055: pool_set_query_in_progress:<br>
> > done<br>
> > > >> >>> 2011-11-21 23:03:22 LOG:   pid 30055: DB node id: 0 backend pid:<br>
> > 24275<br>
> > > >> >>> statement: Parse: SET extra_float_digits = 3<br>
> > > >> >>> 2011-11-21 23:03:22 DEBUG: pid 30055: wait_for_query_response:<br>
> > waiting<br>
> > > >> >>> for backend 0 completing the query<br>
> > > >> >>> 2011-11-21 23:03:22 DEBUG: pid 30055: read_kind_from_backend:<br>
> > read kind<br>
> > > >> >>> from 0 th backend 1 NUM_BACKENDS: 2<br>
> > > >> >>> 2011-11-21 23:03:22 DEBUG: pid 30055: ProcessBackendResponse:<br>
> > kind from<br>
> > > >> >>> backend: 1<br>
> > > >> >>> 2011-11-21 23:03:22 DEBUG: pid 30055: pool_set_command_success:<br>
> > done<br>
> > > >> >>> 2011-11-21 23:03:22 DEBUG: pid 30055:<br>
> > pool_unset_query_in_progress:<br>
> > > >> done<br>
> > > >> >>> 2011-11-21 23:03:22 DEBUG: pid 30055: ProcessFrontendResponse:<br>
> > kind<br>
> > > >> from<br>
> > > >> >>> frontend B(42)<br>
> > > >> >>> 2011-11-21 23:03:22 DEBUG: pid 30055:<br>
> > > >> >>> pool_unset_doing_extended_query_message: done<br>
> > > >> >>> 2011-11-21 23:03:22 DEBUG: pid 30055:<br>
> > > >> >>> pool_set_doing_extended_query_message: done<br>
> > > >> >>> 2011-11-21 23:03:22 DEBUG: pid 30055: pool_set_query_in_progress:<br>
> > done<br>
> > > >> >>> 2011-11-21 23:03:22 DEBUG: pid 30055: Bind: waiting for master<br>
> > > >> completing<br>
> > > >> >>> the query<br>
> > > >> >>> 2011-11-21 23:03:22 LOG:   pid 30055: DB node id: 0 backend pid:<br>
> > 24275<br>
> > > >> >>> statement: B message<br>
> > > >> >>> 2011-11-21 23:03:22 DEBUG: pid 30055: wait_for_query_response:<br>
> > waiting<br>
> > > >> >>> for backend 0 completing the query<br>
> > > >> >>> 2011-11-21 23:03:22 DEBUG: pid 30055: read_kind_from_backend:<br>
> > read kind<br>
> > > >> >>> from 0 th backend 2 NUM_BACKENDS: 2<br>
> > > >> >>> 2011-11-21 23:03:22 DEBUG: pid 30055: ProcessBackendResponse:<br>
> > kind from<br>
> > > >> >>> backend: 2<br>
> > > >> >>> 2011-11-21 23:03:22 DEBUG: pid 30055: pool_set_command_success:<br>
> > done<br>
> > > >> >>> 2011-11-21 23:03:22 DEBUG: pid 30055:<br>
> > pool_unset_query_in_progress:<br>
> > > >> done<br>
> > > >> >>> 2011-11-21 23:03:22 DEBUG: pid 30055: ProcessFrontendResponse:<br>
> > kind<br>
> > > >> from<br>
> > > >> >>> frontend E(45)<br>
> > > >> >>> 2011-11-21 23:03:22 DEBUG: pid 30055:<br>
> > > >> >>> pool_unset_doing_extended_query_message: done<br>
> > > >> >>> 2011-11-21 23:03:22 DEBUG: pid 30055:<br>
> > > >> >>> pool_set_doing_extended_query_message: done<br>
> > > >> >>> 2011-11-21 23:03:22 DEBUG: pid 30055: pool_set_query_in_progress:<br>
> > done<br>
> > > >> >>> 2011-11-21 23:03:22 DEBUG: pid 30055: Execute: portal name <><br>
> > > >> >>> 2011-11-21 23:03:22 DEBUG: pid 30055: Execute: query: SET<br>
> > > >> >>> extra_float_digits = 3<br>
> > > >> >>> 2011-11-21 23:03:22 LOG:   pid 30055: DB node id: 0 backend pid:<br>
> > 24275<br>
> > > >> >>> statement: Execute: SET extra_float_digits = 3<br>
> > > >> >>> 2011-11-21 23:03:22 DEBUG: pid 30055: wait_for_query_response:<br>
> > waiting<br>
> > > >> >>> for backend 0 completing the query<br>
> > > >> >>> 2011-11-21 23:03:23 DEBUG: pid 30055: read_kind_from_backend:<br>
> > read kind<br>
> > > >> >>> from 0 th backend C NUM_BACKENDS: 2<br>
> > > >> >>> 2011-11-21 23:03:23 DEBUG: pid 30055: ProcessBackendResponse:<br>
> > kind from<br>
> > > >> >>> backend: C<br>
> > > >> >>> 2011-11-21 23:03:23 DEBUG: pid 30055: pool_set_command_success:<br>
> > done<br>
> > > >> >>> 2011-11-21 23:03:23 DEBUG: pid 30055:<br>
> > pool_unset_query_in_progress:<br>
> > > >> done<br>
> > > >> >>> 2011-11-21 23:03:23 DEBUG: pid 30055: ProcessFrontendResponse:<br>
> > kind<br>
> > > >> from<br>
> > > >> >>> frontend S(53)<br>
> > > >> >>> 2011-11-21 23:03:23 DEBUG: pid 30055:<br>
> > > >> >>> pool_unset_doing_extended_query_message: done<br>
> > > >> >>> 2011-11-21 23:03:23 DEBUG: pid 30055:<br>
> > > >> >>> pool_set_doing_extended_query_message: done<br>
> > > >> >>> 2011-11-21 23:03:23 DEBUG: pid 30055: pool_set_query_in_progress:<br>
> > done<br>
> > > >> >>> 2011-11-21 23:03:23 DEBUG: pid 30055: read_kind_from_backend:<br>
> > read kind<br>
> > > >> >>> from 0 th backend Z NUM_BACKENDS: 2<br>
> > > >> >>> 2011-11-21 23:03:23 DEBUG: pid 30055: ProcessBackendResponse:<br>
> > kind from<br>
> > > >> >>> backend: Z<br>
> > > >> >>> 2011-11-21 23:03:23 DEBUG: pid 30055: pool_read_message_length:<br>
> > slot: 0<br>
> > > >> >>> length: 5<br>
> > > >> >>> 2011-11-21 23:03:23 DEBUG: pid 30055: ReadyForQuery: transaction<br>
> > > >> state:I<br>
> > > >> >>> 2011-11-21 23:03:23 DEBUG: pid 30055:<br>
> > pool_set_writing_transaction:<br>
> > > >> done<br>
> > > >> >>> 2011-11-21 23:03:23 DEBUG: pid 30055:<br>
> > pool_unset_query_in_progress:<br>
> > > >> done<br>
> > > >> >>> 2011-11-21 23:03:23 DEBUG: pid 30055: ProcessFrontendResponse:<br>
> > kind<br>
> > > >> from<br>
> > > >> >>> frontend P(50)<br>
> > > >> >>> 2011-11-21 23:03:23 DEBUG: pid 30055:<br>
> > > >> >>> pool_unset_doing_extended_query_message: done<br>
> > > >> >>> 2011-11-21 23:03:23 DEBUG: pid 30055:<br>
> > > >> >>> pool_set_doing_extended_query_message: done<br>
> > > >> >>> 2011-11-21 23:03:23 DEBUG: pid 30055: pool_set_query_in_progress:<br>
> > done<br>
> > > >> >>> 2011-11-21 23:03:23 DEBUG: pid 30055: Parse: statement name <><br>
> > > >> >>> 2011-11-21 23:03:23 DEBUG: pid 30055: pool_set_query_in_progress:<br>
> > done<br>
> > > >> >>> 2011-11-21 23:03:23 LOG:   pid 30055: DB node id: 0 backend pid:<br>
> > 24275<br>
> > > >> >>> statement: Parse: select nextval('hibernate_sequence')<br>
> > > >> >>> 2011-11-21 23:03:23 DEBUG: pid 30055: wait_for_query_response:<br>
> > waiting<br>
> > > >> >>> for backend 0 completing the query<br>
> > > >> >>> 2011-11-21 23:03:23 DEBUG: pid 30055: read_kind_from_backend:<br>
> > read kind<br>
> > > >> >>> from 0 th backend 1 NUM_BACKENDS: 2<br>
> > > >> >>> 2011-11-21 23:03:23 DEBUG: pid 30055: ProcessBackendResponse:<br>
> > kind from<br>
> > > >> >>> backend: 1<br>
> > > >> >>> 2011-11-21 23:03:23 DEBUG: pid 30055: pool_add_sent_message:<br>
> > prepared<br>
> > > >> >>> statement "" already exists<br>
> > > >> >>> 2011-11-21 23:03:23 DEBUG: pid 30055: can_query_context_destroy:<br>
> > query<br>
> > > >> >>> context is still used.<br>
> > > >> >>> 2011-11-21 23:03:23 DEBUG: pid 30055: pool_set_command_success:<br>
> > done<br>
> > > >> >>> 2011-11-21 23:03:23 DEBUG: pid 30055:<br>
> > pool_unset_query_in_progress:<br>
> > > >> done<br>
> > > >> >>> 2011-11-21 23:03:23 DEBUG: pid 30055: ProcessFrontendResponse:<br>
> > kind<br>
> > > >> from<br>
> > > >> >>> frontend B(42)<br>
> > > >> >>> 2011-11-21 23:03:23 DEBUG: pid 30055:<br>
> > > >> >>> pool_unset_doing_extended_query_message: done<br>
> > > >> >>> 2011-11-21 23:03:23 DEBUG: pid 30055:<br>
> > > >> >>> pool_set_doing_extended_query_message: done<br>
> > > >> >>> 2011-11-21 23:03:23 DEBUG: pid 30055: pool_set_query_in_progress:<br>
> > done<br>
> > > >> >>> 2011-11-21 23:03:23 DEBUG: pid 30055: Bind: waiting for master<br>
> > > >> completing<br>
> > > >> >>> the query<br>
> > > >> >>> 2011-11-21 23:03:23 LOG:   pid 30055: DB node id: 0 backend pid:<br>
> > 24275<br>
> > > >> >>> statement: B message<br>
> > > >> >>> 2011-11-21 23:03:23 DEBUG: pid 30055: wait_for_query_response:<br>
> > waiting<br>
> > > >> >>> for backend 0 completing the query<br>
> > > >> >>> 2011-11-21 23:03:23 DEBUG: pid 30055: read_kind_from_backend:<br>
> > read kind<br>
> > > >> >>> from 0 th backend 2 NUM_BACKENDS: 2<br>
> > > >> >>> 2011-11-21 23:03:23 DEBUG: pid 30055: ProcessBackendResponse:<br>
> > kind from<br>
> > > >> >>> backend: 2<br>
> > > >> >>> 2011-11-21 23:03:23 DEBUG: pid 30055: pool_add_sent_message:<br>
> > portal ""<br>
> > > >> >>> already exists<br>
> > > >> >>> 2011-11-21 23:03:23 DEBUG: pid 30055:<br>
> > pool_unset_query_in_progress:<br>
> > > >> done<br>
> > > >> >>> 2011-11-21 23:03:23 DEBUG: pid 30055: pool_set_query_in_progress:<br>
> > done<br>
> > > >> >>> 2011-11-21 23:03:23 DEBUG: pid 30055: pool_set_command_success:<br>
> > done<br>
> > > >> >>> 2011-11-21 23:03:23 DEBUG: pid 30055:<br>
> > pool_unset_query_in_progress:<br>
> > > >> done<br>
> > > >> >>> 2011-11-21 23:03:23 DEBUG: pid 30055: ProcessFrontendResponse:<br>
> > kind<br>
> > > >> from<br>
> > > >> >>> frontend D(44)<br>
> > > >> >>> 2011-11-21 23:03:23 DEBUG: pid 30055:<br>
> > > >> >>> pool_unset_doing_extended_query_message: done<br>
> > > >> >>> 2011-11-21 23:03:23 DEBUG: pid 30055:<br>
> > > >> >>> pool_set_doing_extended_query_message: done<br>
> > > >> >>> 2011-11-21 23:03:23 DEBUG: pid 30055: pool_set_query_in_progress:<br>
> > done<br>
> > > >> >>> 2011-11-21 23:03:23 DEBUG: pid 30055: Describe: waiting for master<br>
> > > >> >>> completing the query<br>
> > > >> >>> 2011-11-21 23:03:23 LOG:   pid 30055: DB node id: 0 backend pid:<br>
> > 24275<br>
> > > >> >>> statement: D message<br>
> > > >> >>> 2011-11-21 23:03:23 DEBUG: pid 30055: wait_for_query_response:<br>
> > waiting<br>
> > > >> >>> for backend 0 completing the query<br>
> > > >> >>> 2011-11-21 23:03:23 DEBUG: pid 30055: read_kind_from_backend:<br>
> > read kind<br>
> > > >> >>> from 0 th backend T NUM_BACKENDS: 2<br>
> > > >> >>> 2011-11-21 23:03:23 DEBUG: pid 30055: ProcessBackendResponse:<br>
> > kind from<br>
> > > >> >>> backend: T<br>
> > > >> >>> 2011-11-21 23:03:23 DEBUG: pid 30055:<br>
> > pool_unset_query_in_progress:<br>
> > > >> done<br>
> > > >> >>> 2011-11-21 23:03:23 DEBUG: pid 30055: ProcessFrontendResponse:<br>
> > kind<br>
> > > >> from<br>
> > > >> >>> frontend E(45)<br>
> > > >> >>> 2011-11-21 23:03:23 DEBUG: pid 30055:<br>
> > > >> >>> pool_unset_doing_extended_query_message: done<br>
> > > >> >>> 2011-11-21 23:03:23 DEBUG: pid 30055:<br>
> > > >> >>> pool_set_doing_extended_query_message: done<br>
> > > >> >>> 2011-11-21 23:03:23 DEBUG: pid 30055: pool_set_query_in_progress:<br>
> > done<br>
> > > >> >>> 2011-11-21 23:03:23 DEBUG: pid 30055: Execute: portal name <><br>
> > > >> >>> 2011-11-21 23:03:23 DEBUG: pid 30055: Execute: query: select<br>
> > > >> >>> nextval('hibernate_sequence')<br>
> > > >> >>> 2011-11-21 23:03:23 LOG:   pid 30055: DB node id: 0 backend pid:<br>
> > 24275<br>
> > > >> >>> statement: Execute: select nextval('hibernate_sequence')<br>
> > > >> >>> 2011-11-21 23:03:23 DEBUG: pid 30055: wait_for_query_response:<br>
> > waiting<br>
> > > >> >>> for backend 0 completing the query<br>
> > > >> >>> 2011-11-21 23:03:23 DEBUG: pid 30055: read_kind_from_backend:<br>
> > read kind<br>
> > > >> >>> from 0 th backend D NUM_BACKENDS: 2<br>
> > > >> >>> 2011-11-21 23:03:23 DEBUG: pid 30055: ProcessBackendResponse:<br>
> > kind from<br>
> > > >> >>> backend: D<br>
> > > >> >>> 2011-11-21 23:03:23 DEBUG: pid 30055: read_kind_from_backend:<br>
> > read kind<br>
> > > >> >>> from 0 th backend C NUM_BACKENDS: 2<br>
> > > >> >>> 2011-11-21 23:03:23 DEBUG: pid 30055: ProcessBackendResponse:<br>
> > kind from<br>
> > > >> >>> backend: C<br>
> > > >> >>> 2011-11-21 23:03:23 DEBUG: pid 30055: pool_set_command_success:<br>
> > done<br>
> > > >> >>> 2011-11-21 23:03:23 DEBUG: pid 30055:<br>
> > pool_unset_query_in_progress:<br>
> > > >> done<br>
> > > >> >>> 2011-11-21 23:03:23 DEBUG: pid 30055: ProcessFrontendResponse:<br>
> > kind<br>
> > > >> from<br>
> > > >> >>> frontend S(53)<br>
> > > >> >>> 2011-11-21 23:03:23 DEBUG: pid 30055:<br>
> > > >> >>> pool_unset_doing_extended_query_message: done<br>
> > > >> >>> 2011-11-21 23:03:23 DEBUG: pid 30055:<br>
> > > >> >>> pool_set_doing_extended_query_message: done<br>
> > > >> >>> 2011-11-21 23:03:23 DEBUG: pid 30055: pool_set_query_in_progress:<br>
> > done<br>
> > > >> >>> 2011-11-21 23:03:23 DEBUG: pid 30055: read_kind_from_backend:<br>
> > read kind<br>
> > > >> >>> from 0 th backend Z NUM_BACKENDS: 2<br>
> > > >> >>> 2011-11-21 23:03:23 DEBUG: pid 30055: ProcessBackendResponse:<br>
> > kind from<br>
> > > >> >>> backend: Z<br>
> > > >> >>> 2011-11-21 23:03:23 DEBUG: pid 30055: pool_read_message_length:<br>
> > slot: 0<br>
> > > >> >>> length: 5<br>
> > > >> >>> 2011-11-21 23:03:23 DEBUG: pid 30055: ReadyForQuery: transaction<br>
> > > >> state:I<br>
> > > >> >>> 2011-11-21 23:03:23 DEBUG: pid 30055:<br>
> > pool_unset_query_in_progress:<br>
> > > >> done<br>
> > > >> >>> 2011-11-21 23:03:23 DEBUG: pid 30055: ProcessFrontendResponse:<br>
> > kind<br>
> > > >> from<br>
> > > >> >>> frontend X(58)<br>
> > > >> >>> 2011-11-21 23:03:23 DEBUG: pid 30055:<br>
> > > >> >>> pool_unset_doing_extended_query_message: done<br>
> > > >> >>> 2011-11-21 23:03:23 DEBUG: pid 30055:<br>
> > pool_unset_query_in_progress:<br>
> > > >> done<br>
> > > >> >>> 2011-11-21 23:03:23 DEBUG: pid 30055: can_query_context_destroy:<br>
> > query<br>
> > > >> >>> context is still used.<br>
> > > >> >>> 2011-11-21 23:03:23 DEBUG: pid 30055:<br>
> > pool_unset_query_in_progress:<br>
> > > >> done<br>
> > > >> >><br>
> > > >> >><br>
> > > >> >><br>
> > > >><br>
> > ><br>
> ><br>
> ><br>
<br>
</div></div></blockquote></div><br>