> 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
