On Thu, 24 Nov 2011 18:19:11 +0900 (JST) Tatsuo Ishii <[email protected]> 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 <[email protected]> > > > >> > 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ć <[email protected]> > >> 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ć <[email protected]> > >> 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@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@7f05238] > >> >>> 23:03:23.150 (1) simple execute, > >> >>> > >> handler=org.postgresql.jdbc2.AbstractJdbc2Statement$StatementResultHandler@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@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 > >> >> > >> >> > >> >> > >> > _______________________________________________ Pgpool-general mailing list [email protected] http://pgfoundry.org/mailman/listinfo/pgpool-general
