[pgpool-general: 18] Re: [Pgpool-general] pgpool, latency, and postgres protocol

Thu Dec 1 19:48:45 JST 2011

Hi Stevo,

Sorry for delay.

On Fri, 25 Nov 2011 07:09:40 -0700
Stevo Slavić <sslavic at gmail.com> wrote:

> Thanks Toshihiro for the feedback! I very much appreciate that.
> 
> Can you please provide any hints/tips on where blocking occurs in the code,
> and advices on what needs to be changed to have backend messages to be
> processed in parallel? If it's not too significant change affecting rest of
> pgpool features, might decide to do that change in a custom build, at least
> temporarily.

Probably, the function which is blocking is pool_extended_send_and_wait().
pool_extended_send_and_wait() is called from Parse(), Bind(), Describe(),
Execute() and etc. 

I think that to avoid blocking, we need to replace
pool_extended_send_and_wait() with a function which doesn't wait a backend
response and to control skip_reading_from_backends flag.

However...

Changing code is difficult because the handring of extended query protocol
is complex.

I am interested in this issue, but even if I was able to fix it, it will
take long time.

Regards,

-- 
Toshihiro Kitagawa
SRA OSS, Inc. Japan

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