View Issue Details

IDProjectCategoryView StatusLast Update
0000211Pgpool-IIBugpublic2016-09-28 10:33
Reporterzh1029Assigned Tot-ishii 
PriorityhighSeveritymajorReproducibilityalways
Status closedResolutionopen 
Product Version3.5.2 
Target VersionFixed in Version 
Summary0000211: YCSB can't connect to PGPool-II in master-slave mode.
DescriptionI installed PGPOOL-II 3.5.2 and PostgreSQL 9.3.6 as backend. PGPOOL-II is configured as master-slave mode.I use YCSB(Yahoo Cloud Serving Benchmark) as frontend to connect PGPOOL to have benchmark testing. but YCSB is hanging in connect PGPOOL-II. Seems is blocked at "SET extra_float_digits = 3".
Please note. While I change PGPOOL-II configuration as replication mode, YCSB works well.


# /root/pgpool/bin/pgpool -f /root/pgpool/etc/pgpool.conf.master-slave -a /root/pgpool/etc/pool_hba.conf -F /root/pgpool/etc/pcp.conf
2016-06-28 10:47:41: pid 26776: DEBUG: key: pid_file_name
2016-06-28 10:47:41: pid 26776: LOCATION: pool_config.l:500
2016-06-28 10:47:41: pid 26776: DEBUG: value: '/var/run/pgpool/pgpool.pid' kind: 4
2016-06-28 10:47:41: pid 26776: LOCATION: pool_config.l:507
2016-06-28 10:47:41: pid 26776: DEBUG: key: logdir
2016-06-28 10:47:41: pid 26776: LOCATION: pool_config.l:500
2016-06-28 10:47:41: pid 26776: DEBUG: value: '/tmp' kind: 4
2016-06-28 10:47:41: pid 26776: LOCATION: pool_config.l:507
2016-06-28 10:47:41: pid 26776: DEBUG: key: connection_cache
2016-06-28 10:47:41: pid 26776: LOCATION: pool_config.l:500
2016-06-28 10:47:41: pid 26776: DEBUG: value: on kind: 1
2016-06-28 10:47:41: pid 26776: LOCATION: pool_config.l:507
2016-06-28 10:47:41: pid 26776: DEBUG: key: reset_query_list
2016-06-28 10:47:41: pid 26776: LOCATION: pool_config.l:500
2016-06-28 10:47:41: pid 26776: DEBUG: value: 'ABORT; DISCARD ALL' kind: 4
2016-06-28 10:47:41: pid 26776: LOCATION: pool_config.l:507
2016-06-28 10:47:41: pid 26776: DEBUG: initializing pool configuration
2016-06-28 10:47:41: pid 26776: DETAIL: extracting string tokens [token: ABORT]
2016-06-28 10:47:41: pid 26776: LOCATION: pool_config.l:3567
2016-06-28 10:47:41: pid 26776: DEBUG: initializing pool configuration
2016-06-28 10:47:41: pid 26776: DETAIL: extracting string tokens [token: DISCARD ALL]
2016-06-28 10:47:41: pid 26776: LOCATION: pool_config.l:3567
2016-06-28 10:47:41: pid 26776: DEBUG: key: replication_mode
2016-06-28 10:47:41: pid 26776: LOCATION: pool_config.l:500
2016-06-28 10:47:41: pid 26776: DEBUG: value: off kind: 1
2016-06-28 10:47:41: pid 26776: LOCATION: pool_config.l:507
2016-06-28 10:47:41: pid 26776: DEBUG: key: replicate_select
2016-06-28 10:47:41: pid 26776: LOCATION: pool_config.l:500
2016-06-28 10:47:41: pid 26776: DEBUG: value: off kind: 1
2016-06-28 10:47:41: pid 26776: LOCATION: pool_config.l:507
2016-06-28 10:47:41: pid 26776: DEBUG: initializing pool configuration
2016-06-28 10:47:41: pid 26776: DETAIL: replicate_select: 0
2016-06-28 10:47:41: pid 26776: LOCATION: pool_config.l:1029
2016-06-28 10:47:41: pid 26776: DEBUG: key: insert_lock
2016-06-28 10:47:41: pid 26776: LOCATION: pool_config.l:500
2016-06-28 10:47:41: pid 26776: DEBUG: value: off kind: 1
2016-06-28 10:47:41: pid 26776: LOCATION: pool_config.l:507
2016-06-28 10:47:41: pid 26776: DEBUG: key: lobj_lock_table
2016-06-28 10:47:41: pid 26776: LOCATION: pool_config.l:500
2016-06-28 10:47:41: pid 26776: DEBUG: value: '' kind: 4
2016-06-28 10:47:41: pid 26776: LOCATION: pool_config.l:507
2016-06-28 10:47:41: pid 26776: DEBUG: key: replication_stop_on_mismatch
2016-06-28 10:47:41: pid 26776: LOCATION: pool_config.l:500
2016-06-28 10:47:41: pid 26776: DEBUG: value: off kind: 1
2016-06-28 10:47:41: pid 26776: LOCATION: pool_config.l:507
2016-06-28 10:47:41: pid 26776: DEBUG: initializing pool configuration
2016-06-28 10:47:41: pid 26776: DETAIL: replication_stop_on_mismatch: 0
2016-06-28 10:47:41: pid 26776: LOCATION: pool_config.l:991
2016-06-28 10:47:41: pid 26776: DEBUG: key: failover_if_affected_tuples_mismatch
2016-06-28 10:47:41: pid 26776: LOCATION: pool_config.l:500
2016-06-28 10:47:41: pid 26776: DEBUG: value: off kind: 1
2016-06-28 10:47:41: pid 26776: LOCATION: pool_config.l:507
2016-06-28 10:47:41: pid 26776: DEBUG: initializing pool configuration
2016-06-28 10:47:41: pid 26776: DETAIL: failover_if_affected_tuples_mismatch: 0
2016-06-28 10:47:41: pid 26776: LOCATION: pool_config.l:1010
2016-06-28 10:47:41: pid 26776: DEBUG: key: load_balance_mode
2016-06-28 10:47:41: pid 26776: LOCATION: pool_config.l:500
2016-06-28 10:47:41: pid 26776: DEBUG: value: on kind: 1
2016-06-28 10:47:41: pid 26776: LOCATION: pool_config.l:507
2016-06-28 10:47:41: pid 26776: DEBUG: key: ignore_leading_white_space
2016-06-28 10:47:41: pid 26776: LOCATION: pool_config.l:500
2016-06-28 10:47:41: pid 26776: DEBUG: value: on kind: 1
2016-06-28 10:47:41: pid 26776: LOCATION: pool_config.l:507
2016-06-28 10:47:41: pid 26776: DEBUG: key: white_function_list
2016-06-28 10:47:41: pid 26776: LOCATION: pool_config.l:500
2016-06-28 10:47:41: pid 26776: DEBUG: value: '' kind: 4
2016-06-28 10:47:41: pid 26776: LOCATION: pool_config.l:507
2016-06-28 10:47:41: pid 26776: DEBUG: key: black_function_list
2016-06-28 10:47:41: pid 26776: LOCATION: pool_config.l:500
2016-06-28 10:47:41: pid 26776: DEBUG: value: 'currval,lastval,nextval,setval' kind: 4
2016-06-28 10:47:41: pid 26776: LOCATION: pool_config.l:507
2016-06-28 10:47:41: pid 26776: DEBUG: initializing pool configuration
2016-06-28 10:47:41: pid 26776: DETAIL: extracting string tokens [token: currval]
2016-06-28 10:47:41: pid 26776: LOCATION: pool_config.l:3567
2016-06-28 10:47:41: pid 26776: DEBUG: initializing pool configuration
2016-06-28 10:47:41: pid 26776: DETAIL: extracting string tokens [token: lastval]
2016-06-28 10:47:41: pid 26776: LOCATION: pool_config.l:3567
2016-06-28 10:47:41: pid 26776: DEBUG: initializing pool configuration
2016-06-28 10:47:41: pid 26776: DETAIL: extracting string tokens [token: nextval]
2016-06-28 10:47:41: pid 26776: LOCATION: pool_config.l:3567
2016-06-28 10:47:41: pid 26776: DEBUG: initializing pool configuration
2016-06-28 10:47:41: pid 26776: DETAIL: extracting string tokens [token: setval]
2016-06-28 10:47:41: pid 26776: LOCATION: pool_config.l:3567
2016-06-28 10:47:41: pid 26776: DEBUG: initializing pool configuration
2016-06-28 10:47:41: pid 26776: DETAIL: adding regex pattern for "black_function_list" pattern: ^currval$
2016-06-28 10:47:41: pid 26776: LOCATION: pool_config.l:362
2016-06-28 10:47:41: pid 26776: DEBUG: initializing pool configuration
2016-06-28 10:47:41: pid 26776: DETAIL: adding regex pattern for "black_function_list" pattern: ^lastval$
2016-06-28 10:47:41: pid 26776: LOCATION: pool_config.l:362
2016-06-28 10:47:41: pid 26776: DEBUG: initializing pool configuration
2016-06-28 10:47:41: pid 26776: DETAIL: adding regex pattern for "black_function_list" pattern: ^nextval$
2016-06-28 10:47:41: pid 26776: LOCATION: pool_config.l:362
2016-06-28 10:47:41: pid 26776: DEBUG: initializing pool configuration
2016-06-28 10:47:41: pid 26776: DETAIL: adding regex pattern for "black_function_list" pattern: ^setval$
2016-06-28 10:47:41: pid 26776: LOCATION: pool_config.l:362
2016-06-28 10:47:41: pid 26776: DEBUG: key: database_redirect_preference_list
2016-06-28 10:47:41: pid 26776: LOCATION: pool_config.l:500
2016-06-28 10:47:41: pid 26776: DEBUG: value: '' kind: 4
2016-06-28 10:47:41: pid 26776: LOCATION: pool_config.l:507
2016-06-28 10:47:41: pid 26776: DEBUG: key: app_name_redirect_preference_list
2016-06-28 10:47:41: pid 26776: LOCATION: pool_config.l:500
2016-06-28 10:47:41: pid 26776: DEBUG: value: '' kind: 4
2016-06-28 10:47:41: pid 26776: LOCATION: pool_config.l:507
2016-06-28 10:47:41: pid 26776: DEBUG: key: allow_sql_comments
2016-06-28 10:47:41: pid 26776: LOCATION: pool_config.l:500
2016-06-28 10:47:41: pid 26776: DEBUG: value: off kind: 1
2016-06-28 10:47:41: pid 26776: LOCATION: pool_config.l:507
2016-06-28 10:47:41: pid 26776: DEBUG: key: master_slave_mode
2016-06-28 10:47:41: pid 26776: LOCATION: pool_config.l:500
2016-06-28 10:47:41: pid 26776: DEBUG: value: on kind: 1
2016-06-28 10:47:41: pid 26776: LOCATION: pool_config.l:507
2016-06-28 10:47:41: pid 26776: DEBUG: key: master_slave_sub_mode
2016-06-28 10:47:41: pid 26776: LOCATION: pool_config.l:500
2016-06-28 10:47:41: pid 26776: DEBUG: value: 'slony' kind: 4
2016-06-28 10:47:41: pid 26776: LOCATION: pool_config.l:507
2016-06-28 10:47:41: pid 26776: DEBUG: key: sr_check_period
2016-06-28 10:47:41: pid 26776: LOCATION: pool_config.l:500
2016-06-28 10:47:41: pid 26776: DEBUG: value: 0 kind: 2
2016-06-28 10:47:41: pid 26776: LOCATION: pool_config.l:507
2016-06-28 10:47:41: pid 26776: DEBUG: key: sr_check_user
2016-06-28 10:47:41: pid 26776: LOCATION: pool_config.l:500
2016-06-28 10:47:41: pid 26776: DEBUG: value: 'nobody' kind: 4
2016-06-28 10:47:41: pid 26776: LOCATION: pool_config.l:507
2016-06-28 10:47:41: pid 26776: DEBUG: key: sr_check_password
2016-06-28 10:47:41: pid 26776: LOCATION: pool_config.l:500
2016-06-28 10:47:41: pid 26776: DEBUG: value: '' kind: 4
2016-06-28 10:47:41: pid 26776: LOCATION: pool_config.l:507
2016-06-28 10:47:41: pid 26776: DEBUG: key: sr_check_database
2016-06-28 10:47:41: pid 26776: LOCATION: pool_config.l:500
2016-06-28 10:47:41: pid 26776: DEBUG: value: 'postgres' kind: 4
2016-06-28 10:47:41: pid 26776: LOCATION: pool_config.l:507
2016-06-28 10:47:41: pid 26776: DEBUG: key: delay_threshold
2016-06-28 10:47:41: pid 26776: LOCATION: pool_config.l:500
2016-06-28 10:47:41: pid 26776: DEBUG: value: 0 kind: 2
2016-06-28 10:47:41: pid 26776: LOCATION: pool_config.l:507
2016-06-28 10:47:41: pid 26776: DEBUG: key: follow_master_command
2016-06-28 10:47:41: pid 26776: LOCATION: pool_config.l:500
2016-06-28 10:47:41: pid 26776: DEBUG: value: '' kind: 4
2016-06-28 10:47:41: pid 26776: LOCATION: pool_config.l:507
2016-06-28 10:47:41: pid 26776: DEBUG: key: health_check_period
2016-06-28 10:47:41: pid 26776: LOCATION: pool_config.l:500
2016-06-28 10:47:41: pid 26776: DEBUG: value: 0 kind: 2
2016-06-28 10:47:41: pid 26776: LOCATION: pool_config.l:507
2016-06-28 10:47:41: pid 26776: DEBUG: key: health_check_timeout
2016-06-28 10:47:41: pid 26776: LOCATION: pool_config.l:500
2016-06-28 10:47:41: pid 26776: DEBUG: value: 20 kind: 2
2016-06-28 10:47:41: pid 26776: LOCATION: pool_config.l:507
2016-06-28 10:47:41: pid 26776: DEBUG: key: health_check_user
2016-06-28 10:47:41: pid 26776: LOCATION: pool_config.l:500
2016-06-28 10:47:41: pid 26776: DEBUG: value: 'nobody' kind: 4
2016-06-28 10:47:41: pid 26776: LOCATION: pool_config.l:507
2016-06-28 10:47:41: pid 26776: DEBUG: key: health_check_password
2016-06-28 10:47:41: pid 26776: LOCATION: pool_config.l:500
2016-06-28 10:47:41: pid 26776: DEBUG: value: '' kind: 4
2016-06-28 10:47:41: pid 26776: LOCATION: pool_config.l:507
2016-06-28 10:47:41: pid 26776: DEBUG: key: health_check_database
2016-06-28 10:47:41: pid 26776: LOCATION: pool_config.l:500
2016-06-28 10:47:41: pid 26776: DEBUG: value: '' kind: 4
2016-06-28 10:47:41: pid 26776: LOCATION: pool_config.l:507
2016-06-28 10:47:41: pid 26776: DEBUG: key: health_check_max_retries
2016-06-28 10:47:41: pid 26776: LOCATION: pool_config.l:500
2016-06-28 10:47:41: pid 26776: DEBUG: value: 0 kind: 2
2016-06-28 10:47:41: pid 26776: LOCATION: pool_config.l:507
2016-06-28 10:47:41: pid 26776: DEBUG: key: health_check_retry_delay
2016-06-28 10:47:41: pid 26776: LOCATION: pool_config.l:500
2016-06-28 10:47:41: pid 26776: DEBUG: value: 1 kind: 2
2016-06-28 10:47:41: pid 26776: LOCATION: pool_config.l:507
2016-06-28 10:47:41: pid 26776: DEBUG: key: connect_timeout
2016-06-28 10:47:41: pid 26776: LOCATION: pool_config.l:500
2016-06-28 10:47:41: pid 26776: DEBUG: value: 10000 kind: 2
2016-06-28 10:47:41: pid 26776: LOCATION: pool_config.l:507
2016-06-28 10:47:41: pid 26776: DEBUG: key: failover_command
2016-06-28 10:47:41: pid 26776: LOCATION: pool_config.l:500
2016-06-28 10:47:41: pid 26776: DEBUG: value: '' kind: 4
2016-06-28 10:47:41: pid 26776: LOCATION: pool_config.l:507
2016-06-28 10:47:41: pid 26776: DEBUG: key: failback_command
2016-06-28 10:47:41: pid 26776: LOCATION: pool_config.l:500
2016-06-28 10:47:41: pid 26776: DEBUG: value: '' kind: 4
2016-06-28 10:47:41: pid 26776: LOCATION: pool_config.l:507
2016-06-28 10:47:41: pid 26776: DEBUG: key: fail_over_on_backend_error
2016-06-28 10:47:41: pid 26776: LOCATION: pool_config.l:500
2016-06-28 10:47:41: pid 26776: DEBUG: value: on kind: 1
2016-06-28 10:47:41: pid 26776: LOCATION: pool_config.l:507
2016-06-28 10:47:41: pid 26776: DEBUG: key: search_primary_node_timeout
2016-06-28 10:47:41: pid 26776: LOCATION: pool_config.l:500
2016-06-28 10:47:41: pid 26776: DEBUG: value: 10 kind: 2
2016-06-28 10:47:41: pid 26776: LOCATION: pool_config.l:507
2016-06-28 10:47:41: pid 26776: DEBUG: key: recovery_user
2016-06-28 10:47:41: pid 26776: LOCATION: pool_config.l:500
2016-06-28 10:47:41: pid 26776: DEBUG: value: 'nobody' kind: 4
2016-06-28 10:47:41: pid 26776: LOCATION: pool_config.l:507
2016-06-28 10:47:41: pid 26776: DEBUG: key: recovery_password
2016-06-28 10:47:41: pid 26776: LOCATION: pool_config.l:500
2016-06-28 10:47:41: pid 26776: DEBUG: value: '' kind: 4
2016-06-28 10:47:41: pid 26776: LOCATION: pool_config.l:507
2016-06-28 10:47:41: pid 26776: DEBUG: key: recovery_1st_stage_command
2016-06-28 10:47:41: pid 26776: LOCATION: pool_config.l:500
2016-06-28 10:47:41: pid 26776: DEBUG: value: '' kind: 4
2016-06-28 10:47:41: pid 26776: LOCATION: pool_config.l:507
2016-06-28 10:47:41: pid 26776: DEBUG: key: recovery_2nd_stage_command
2016-06-28 10:47:41: pid 26776: LOCATION: pool_config.l:500
2016-06-28 10:47:41: pid 26776: DEBUG: value: '' kind: 4
2016-06-28 10:47:41: pid 26776: LOCATION: pool_config.l:507
2016-06-28 10:47:41: pid 26776: DEBUG: key: recovery_timeout
2016-06-28 10:47:41: pid 26776: LOCATION: pool_config.l:500
2016-06-28 10:47:41: pid 26776: DEBUG: value: 90 kind: 2
2016-06-28 10:47:41: pid 26776: LOCATION: pool_config.l:507
2016-06-28 10:47:41: pid 26776: DEBUG: key: client_idle_limit_in_recovery
2016-06-28 10:47:41: pid 26776: LOCATION: pool_config.l:500
2016-06-28 10:47:41: pid 26776: DEBUG: value: 0 kind: 2
2016-06-28 10:47:41: pid 26776: LOCATION: pool_config.l:507
2016-06-28 10:47:41: pid 26776: DEBUG: key: use_watchdog
2016-06-28 10:47:41: pid 26776: LOCATION: pool_config.l:500
2016-06-28 10:47:41: pid 26776: DEBUG: value: off kind: 1
2016-06-28 10:47:41: pid 26776: LOCATION: pool_config.l:507
2016-06-28 10:47:41: pid 26776: DEBUG: key: trusted_servers
2016-06-28 10:47:41: pid 26776: LOCATION: pool_config.l:500
2016-06-28 10:47:41: pid 26776: DEBUG: value: '' kind: 4
2016-06-28 10:47:41: pid 26776: LOCATION: pool_config.l:507
2016-06-28 10:47:41: pid 26776: DEBUG: key: ping_path
2016-06-28 10:47:41: pid 26776: LOCATION: pool_config.l:500
2016-06-28 10:47:41: pid 26776: DEBUG: value: '/bin' kind: 4
2016-06-28 10:47:41: pid 26776: LOCATION: pool_config.l:507
2016-06-28 10:47:41: pid 26776: DEBUG: key: wd_hostname
2016-06-28 10:47:41: pid 26776: LOCATION: pool_config.l:500
2016-06-28 10:47:41: pid 26776: DEBUG: value: '' kind: 4
2016-06-28 10:47:41: pid 26776: LOCATION: pool_config.l:507
2016-06-28 10:47:41: pid 26776: DEBUG: key: wd_port
2016-06-28 10:47:41: pid 26776: LOCATION: pool_config.l:500
2016-06-28 10:47:41: pid 26776: DEBUG: value: 9000 kind: 2
2016-06-28 10:47:41: pid 26776: LOCATION: pool_config.l:507
2016-06-28 10:47:41: pid 26776: DEBUG: key: wd_priority
2016-06-28 10:47:41: pid 26776: LOCATION: pool_config.l:500
2016-06-28 10:47:41: pid 26776: DEBUG: value: 1 kind: 2
2016-06-28 10:47:41: pid 26776: LOCATION: pool_config.l:507
2016-06-28 10:47:41: pid 26776: DEBUG: key: wd_authkey
2016-06-28 10:47:41: pid 26776: LOCATION: pool_config.l:500
2016-06-28 10:47:41: pid 26776: DEBUG: value: '' kind: 4
2016-06-28 10:47:41: pid 26776: LOCATION: pool_config.l:507
2016-06-28 10:47:41: pid 26776: DEBUG: key: wd_ipc_socket_dir
2016-06-28 10:47:41: pid 26776: LOCATION: pool_config.l:500
2016-06-28 10:47:41: pid 26776: DEBUG: value: '/tmp' kind: 4
2016-06-28 10:47:41: pid 26776: LOCATION: pool_config.l:507
2016-06-28 10:47:41: pid 26776: DEBUG: key: delegate_IP
2016-06-28 10:47:41: pid 26776: LOCATION: pool_config.l:500
2016-06-28 10:47:41: pid 26776: DEBUG: value: '' kind: 4
2016-06-28 10:47:41: pid 26776: LOCATION: pool_config.l:507
2016-06-28 10:47:41: pid 26776: DEBUG: key: if_cmd_path
2016-06-28 10:47:41: pid 26776: LOCATION: pool_config.l:500
2016-06-28 10:47:41: pid 26776: DEBUG: value: '/sbin' kind: 4
2016-06-28 10:47:41: pid 26776: LOCATION: pool_config.l:507
2016-06-28 10:47:41: pid 26776: DEBUG: key: if_up_cmd
2016-06-28 10:47:41: pid 26776: LOCATION: pool_config.l:500
2016-06-28 10:47:41: pid 26776: DEBUG: value: 'ip addr add $_IP_$/24 dev eth0 label eth0:0' kind: 4
2016-06-28 10:47:41: pid 26776: LOCATION: pool_config.l:507
2016-06-28 10:47:41: pid 26776: DEBUG: key: if_down_cmd
2016-06-28 10:47:41: pid 26776: LOCATION: pool_config.l:500
2016-06-28 10:47:41: pid 26776: DEBUG: value: 'ip addr del $_IP_$/24 dev eth0' kind: 4
2016-06-28 10:47:41: pid 26776: LOCATION: pool_config.l:507
2016-06-28 10:47:41: pid 26776: DEBUG: key: arping_path
2016-06-28 10:47:41: pid 26776: LOCATION: pool_config.l:500
2016-06-28 10:47:41: pid 26776: DEBUG: value: '/usr/sbin' kind: 4
2016-06-28 10:47:41: pid 26776: LOCATION: pool_config.l:507
2016-06-28 10:47:41: pid 26776: DEBUG: key: arping_cmd
2016-06-28 10:47:41: pid 26776: LOCATION: pool_config.l:500
2016-06-28 10:47:41: pid 26776: DEBUG: value: 'arping -U $_IP_$ -w 1' kind: 4
2016-06-28 10:47:41: pid 26776: LOCATION: pool_config.l:507
2016-06-28 10:47:41: pid 26776: DEBUG: key: clear_memqcache_on_escalation
2016-06-28 10:47:41: pid 26776: LOCATION: pool_config.l:500
2016-06-28 10:47:41: pid 26776: DEBUG: value: on kind: 1
2016-06-28 10:47:41: pid 26776: LOCATION: pool_config.l:507
2016-06-28 10:47:41: pid 26776: DEBUG: key: wd_escalation_command
2016-06-28 10:47:41: pid 26776: LOCATION: pool_config.l:500
2016-06-28 10:47:41: pid 26776: DEBUG: value: '' kind: 4
2016-06-28 10:47:41: pid 26776: LOCATION: pool_config.l:507
2016-06-28 10:47:41: pid 26776: DEBUG: key: wd_de_escalation_command
2016-06-28 10:47:41: pid 26776: LOCATION: pool_config.l:500
2016-06-28 10:47:41: pid 26776: DEBUG: value: '' kind: 4
2016-06-28 10:47:41: pid 26776: LOCATION: pool_config.l:507
2016-06-28 10:47:41: pid 26776: DEBUG: key: wd_monitoring_interfaces_list
2016-06-28 10:47:41: pid 26776: LOCATION: pool_config.l:500
2016-06-28 10:47:41: pid 26776: DEBUG: value: '' kind: 4
2016-06-28 10:47:41: pid 26776: LOCATION: pool_config.l:507
2016-06-28 10:47:41: pid 26776: DEBUG: key: wd_lifecheck_method
2016-06-28 10:47:41: pid 26776: LOCATION: pool_config.l:500
2016-06-28 10:47:41: pid 26776: DEBUG: value: 'heartbeat' kind: 4
2016-06-28 10:47:41: pid 26776: LOCATION: pool_config.l:507
2016-06-28 10:47:41: pid 26776: DEBUG: key: wd_interval
2016-06-28 10:47:41: pid 26776: LOCATION: pool_config.l:500
2016-06-28 10:47:41: pid 26776: DEBUG: value: 10 kind: 2
2016-06-28 10:47:41: pid 26776: LOCATION: pool_config.l:507
2016-06-28 10:47:41: pid 26776: DEBUG: key: wd_heartbeat_port
2016-06-28 10:47:41: pid 26776: LOCATION: pool_config.l:500
2016-06-28 10:47:41: pid 26776: DEBUG: value: 9694 kind: 2
2016-06-28 10:47:41: pid 26776: LOCATION: pool_config.l:507
2016-06-28 10:47:41: pid 26776: DEBUG: key: wd_heartbeat_keepalive
2016-06-28 10:47:41: pid 26776: LOCATION: pool_config.l:500
2016-06-28 10:47:41: pid 26776: DEBUG: value: 2 kind: 2
2016-06-28 10:47:41: pid 26776: LOCATION: pool_config.l:507
2016-06-28 10:47:41: pid 26776: DEBUG: key: wd_heartbeat_deadtime
2016-06-28 10:47:41: pid 26776: LOCATION: pool_config.l:500
2016-06-28 10:47:41: pid 26776: DEBUG: value: 30 kind: 2
2016-06-28 10:47:41: pid 26776: LOCATION: pool_config.l:507
2016-06-28 10:47:41: pid 26776: DEBUG: key: heartbeat_destination0
2016-06-28 10:47:41: pid 26776: LOCATION: pool_config.l:500
2016-06-28 10:47:41: pid 26776: DEBUG: value: 'host0_ip1' kind: 4
2016-06-28 10:47:41: pid 26776: LOCATION: pool_config.l:507
2016-06-28 10:47:41: pid 26776: DEBUG: key: heartbeat_destination_port0
2016-06-28 10:47:41: pid 26776: LOCATION: pool_config.l:500
2016-06-28 10:47:41: pid 26776: DEBUG: value: 9694 kind: 2
2016-06-28 10:47:41: pid 26776: LOCATION: pool_config.l:507
2016-06-28 10:47:41: pid 26776: DEBUG: key: heartbeat_device0
2016-06-28 10:47:41: pid 26776: LOCATION: pool_config.l:500
2016-06-28 10:47:41: pid 26776: DEBUG: value: '' kind: 4
2016-06-28 10:47:41: pid 26776: LOCATION: pool_config.l:507
2016-06-28 10:47:41: pid 26776: DEBUG: key: wd_life_point
2016-06-28 10:47:41: pid 26776: LOCATION: pool_config.l:500
2016-06-28 10:47:41: pid 26776: DEBUG: value: 3 kind: 2
2016-06-28 10:47:41: pid 26776: LOCATION: pool_config.l:507
2016-06-28 10:47:41: pid 26776: DEBUG: key: wd_lifecheck_query
2016-06-28 10:47:41: pid 26776: LOCATION: pool_config.l:500
2016-06-28 10:47:41: pid 26776: DEBUG: value: 'SELECT 1' kind: 4
2016-06-28 10:47:41: pid 26776: LOCATION: pool_config.l:507
2016-06-28 10:47:41: pid 26776: DEBUG: key: wd_lifecheck_dbname
2016-06-28 10:47:41: pid 26776: LOCATION: pool_config.l:500
2016-06-28 10:47:41: pid 26776: DEBUG: value: 'template1' kind: 4
2016-06-28 10:47:41: pid 26776: LOCATION: pool_config.l:507
2016-06-28 10:47:41: pid 26776: DEBUG: key: wd_lifecheck_user
2016-06-28 10:47:41: pid 26776: LOCATION: pool_config.l:500
2016-06-28 10:47:41: pid 26776: DEBUG: value: 'nobody' kind: 4
2016-06-28 10:47:41: pid 26776: LOCATION: pool_config.l:507
2016-06-28 10:47:41: pid 26776: DEBUG: key: wd_lifecheck_password
2016-06-28 10:47:41: pid 26776: LOCATION: pool_config.l:500
2016-06-28 10:47:41: pid 26776: DEBUG: value: '' kind: 4
2016-06-28 10:47:41: pid 26776: LOCATION: pool_config.l:507
2016-06-28 10:47:41: pid 26776: DEBUG: key: relcache_expire
2016-06-28 10:47:41: pid 26776: LOCATION: pool_config.l:500
2016-06-28 10:47:41: pid 26776: DEBUG: value: 0 kind: 2
2016-06-28 10:47:41: pid 26776: LOCATION: pool_config.l:507
2016-06-28 10:47:41: pid 26776: DEBUG: key: relcache_size
2016-06-28 10:47:41: pid 26776: LOCATION: pool_config.l:500
2016-06-28 10:47:41: pid 26776: DEBUG: value: 256 kind: 2
2016-06-28 10:47:41: pid 26776: LOCATION: pool_config.l:507
2016-06-28 10:47:41: pid 26776: DEBUG: key: check_temp_table
2016-06-28 10:47:41: pid 26776: LOCATION: pool_config.l:500
2016-06-28 10:47:41: pid 26776: DEBUG: value: on kind: 1
2016-06-28 10:47:41: pid 26776: LOCATION: pool_config.l:507
2016-06-28 10:47:41: pid 26776: DEBUG: key: check_unlogged_table
2016-06-28 10:47:41: pid 26776: LOCATION: pool_config.l:500
2016-06-28 10:47:41: pid 26776: DEBUG: value: on kind: 1
2016-06-28 10:47:41: pid 26776: LOCATION: pool_config.l:507
2016-06-28 10:47:41: pid 26776: DEBUG: key: memory_cache_enabled
2016-06-28 10:47:41: pid 26776: LOCATION: pool_config.l:500
2016-06-28 10:47:41: pid 26776: DEBUG: value: off kind: 1
2016-06-28 10:47:41: pid 26776: LOCATION: pool_config.l:507
2016-06-28 10:47:41: pid 26776: DEBUG: key: memqcache_method
2016-06-28 10:47:41: pid 26776: LOCATION: pool_config.l:500
2016-06-28 10:47:41: pid 26776: DEBUG: value: 'memcached' kind: 4
2016-06-28 10:47:41: pid 26776: LOCATION: pool_config.l:507
2016-06-28 10:47:41: pid 26776: DEBUG: key: memqcache_memcached_host
2016-06-28 10:47:41: pid 26776: LOCATION: pool_config.l:500
2016-06-28 10:47:41: pid 26776: DEBUG: value: 'localhost' kind: 4
2016-06-28 10:47:41: pid 26776: LOCATION: pool_config.l:507
2016-06-28 10:47:41: pid 26776: DEBUG: key: memqcache_memcached_port
2016-06-28 10:47:41: pid 26776: LOCATION: pool_config.l:500
2016-06-28 10:47:41: pid 26776: DEBUG: value: 11211 kind: 2
2016-06-28 10:47:41: pid 26776: LOCATION: pool_config.l:507
2016-06-28 10:47:41: pid 26776: DEBUG: key: memqcache_total_size
2016-06-28 10:47:41: pid 26776: LOCATION: pool_config.l:500
2016-06-28 10:47:41: pid 26776: DEBUG: value: 67108864 kind: 2
2016-06-28 10:47:41: pid 26776: LOCATION: pool_config.l:507
2016-06-28 10:47:41: pid 26776: DEBUG: key: memqcache_max_num_cache
2016-06-28 10:47:41: pid 26776: LOCATION: pool_config.l:500
2016-06-28 10:47:41: pid 26776: DEBUG: value: 1000000 kind: 2
2016-06-28 10:47:41: pid 26776: LOCATION: pool_config.l:507
2016-06-28 10:47:41: pid 26776: DEBUG: key: memqcache_expire
2016-06-28 10:47:41: pid 26776: LOCATION: pool_config.l:500
2016-06-28 10:47:41: pid 26776: DEBUG: value: 0 kind: 2
2016-06-28 10:47:41: pid 26776: LOCATION: pool_config.l:507
2016-06-28 10:47:41: pid 26776: DEBUG: key: memqcache_auto_cache_invalidation
2016-06-28 10:47:41: pid 26776: LOCATION: pool_config.l:500
2016-06-28 10:47:41: pid 26776: DEBUG: value: on kind: 1
2016-06-28 10:47:41: pid 26776: LOCATION: pool_config.l:507
2016-06-28 10:47:41: pid 26776: DEBUG: key: memqcache_maxcache
2016-06-28 10:47:41: pid 26776: LOCATION: pool_config.l:500
2016-06-28 10:47:41: pid 26776: DEBUG: value: 409600 kind: 2
2016-06-28 10:47:41: pid 26776: LOCATION: pool_config.l:507
2016-06-28 10:47:41: pid 26776: DEBUG: key: memqcache_cache_block_size
2016-06-28 10:47:41: pid 26776: LOCATION: pool_config.l:500
2016-06-28 10:47:41: pid 26776: DEBUG: value: 1048576 kind: 2
2016-06-28 10:47:41: pid 26776: LOCATION: pool_config.l:507
2016-06-28 10:47:41: pid 26776: DEBUG: key: memqcache_oiddir
2016-06-28 10:47:41: pid 26776: LOCATION: pool_config.l:500
2016-06-28 10:47:41: pid 26776: DEBUG: value: '/var/log/pgpool/oiddir' kind: 4
2016-06-28 10:47:41: pid 26776: LOCATION: pool_config.l:507
2016-06-28 10:47:41: pid 26776: DEBUG: key: white_memqcache_table_list
2016-06-28 10:47:41: pid 26776: LOCATION: pool_config.l:500
2016-06-28 10:47:41: pid 26776: DEBUG: value: '' kind: 4
2016-06-28 10:47:41: pid 26776: LOCATION: pool_config.l:507
2016-06-28 10:47:41: pid 26776: DEBUG: key: black_memqcache_table_list
2016-06-28 10:47:41: pid 26776: LOCATION: pool_config.l:500
2016-06-28 10:47:41: pid 26776: DEBUG: value: '' kind: 4
2016-06-28 10:47:41: pid 26776: LOCATION: pool_config.l:507
2016-06-28 10:47:41: pid 26776: DEBUG: initializing pool configuration
2016-06-28 10:47:41: pid 26776: DETAIL: num_backends: 3 total_weight: 3.000000
2016-06-28 10:47:41: pid 26776: LOCATION: pool_config.l:3394
2016-06-28 10:47:41: pid 26776: DEBUG: initializing pool configuration
2016-06-28 10:47:41: pid 26776: DETAIL: backend 0 weight: 715827882.333333 flag: 0000
2016-06-28 10:47:41: pid 26776: LOCATION: pool_config.l:3413
2016-06-28 10:47:41: pid 26776: DEBUG: initializing pool configuration
2016-06-28 10:47:41: pid 26776: DETAIL: backend 1 weight: 715827882.333333 flag: 0000
2016-06-28 10:47:41: pid 26776: LOCATION: pool_config.l:3413
2016-06-28 10:47:41: pid 26776: DEBUG: initializing pool configuration
2016-06-28 10:47:41: pid 26776: DETAIL: backend 2 weight: 715827882.333333 flag: 0000
2016-06-28 10:47:41: pid 26776: LOCATION: pool_config.l:3413
2016-06-28 10:47:41: pid 26776: DEBUG: shmem_exit(-1): 2 callbacks to make
2016-06-28 10:47:41: pid 26776: LOCATION: elog.c:2563
2016-06-28 10:47:41: pid 26776: DEBUG: proc_exit(-1): 0 callbacks to make
2016-06-28 10:47:41: pid 26776: LOCATION: elog.c:2535


Jun 28 11:04:47 MMN-0 pgpool[26802]: [15-1] 2016-06-28 11:04:47: pid 26802: DEBUG: I am 26802 accept fd 8
Jun 28 11:04:47 MMN-0 pgpool[26802]: [15-2] 2016-06-28 11:04:47: pid 26802: LOCATION: child.c:2097
Jun 28 11:04:47 MMN-0 pgpool[26802]: [16-1] 2016-06-28 11:04:47: pid 26802: LOG: new connection received
Jun 28 11:04:47 MMN-0 pgpool[26802]: [16-2] 2016-06-28 11:04:47: pid 26802: DETAIL: connecting host=MMN-0.internalnet.localdomain port=64473
Jun 28 11:04:47 MMN-0 pgpool[26802]: [16-3] 2016-06-28 11:04:47: pid 26802: LOCATION: child.c:2110
Jun 28 11:04:47 MMN-0 pgpool[26802]: [17-1] 2016-06-28 11:04:47: pid 26802: DEBUG: reading startup packet
Jun 28 11:04:47 MMN-0 pgpool[26802]: [17-2] 2016-06-28 11:04:47: pid 26802: DETAIL: Protocol Major: 3 Minor: 0 database: ycsb user: _nokfssystestpostgres
Jun 28 11:04:47 MMN-0 pgpool[26802]: [17-3] 2016-06-28 11:04:47: pid 26802: LOCATION: child.c:614
Jun 28 11:04:47 MMN-0 pgpool[26802]: [18-1] 2016-06-28 11:04:47: pid 26802: DEBUG: creating new connection to backend
Jun 28 11:04:47 MMN-0 pgpool[26802]: [18-2] 2016-06-28 11:04:47: pid 26802: DETAIL: connecting 0 backend
Jun 28 11:04:47 MMN-0 pgpool[26802]: [18-3] 2016-06-28 11:04:47: pid 26802: LOCATION: pool_connection_pool.c:830
Jun 28 11:04:47 MMN-0 pgpool[26802]: [19-1] 2016-06-28 11:04:47: pid 26802: DEBUG: creating new connection to backend
Jun 28 11:04:47 MMN-0 pgpool[26802]: [19-2] 2016-06-28 11:04:47: pid 26802: DETAIL: connecting 1 backend
Jun 28 11:04:47 MMN-0 pgpool[26802]: [19-3] 2016-06-28 11:04:47: pid 26802: LOCATION: pool_connection_pool.c:830
Jun 28 11:04:47 MMN-0 pgpool[26802]: [20-1] 2016-06-28 11:04:47: pid 26802: DEBUG: creating new connection to backend
Jun 28 11:04:47 MMN-0 pgpool[26802]: [20-2] 2016-06-28 11:04:47: pid 26802: DETAIL: skipping backend slot 1 because backend_status = 3
Jun 28 11:04:47 MMN-0 pgpool[26802]: [20-3] 2016-06-28 11:04:47: pid 26802: LOCATION: pool_connection_pool.c:837
Jun 28 11:04:47 MMN-0 pgpool[26802]: [21-1] 2016-06-28 11:04:47: pid 26802: DEBUG: creating new connection to backend
Jun 28 11:04:47 MMN-0 pgpool[26802]: [21-2] 2016-06-28 11:04:47: pid 26802: DETAIL: connecting 2 backend
Jun 28 11:04:47 MMN-0 pgpool[26802]: [21-3] 2016-06-28 11:04:47: pid 26802: LOCATION: pool_connection_pool.c:830
Jun 28 11:04:47 MMN-0 pgpool[26802]: [22-1] 2016-06-28 11:04:47: pid 26802: DEBUG: creating new connection to backend
Jun 28 11:04:47 MMN-0 pgpool[26802]: [22-2] 2016-06-28 11:04:47: pid 26802: DETAIL: skipping backend slot 2 because backend_status = 3
Jun 28 11:04:47 MMN-0 pgpool[26802]: [22-3] 2016-06-28 11:04:47: pid 26802: LOCATION: pool_connection_pool.c:837
Jun 28 11:04:47 MMN-0 postgres[23480]: [17152-1] [23480-576a1f04.5bb8-34308] 2016-06-28 03:04:47.621 GMT < > DEBUG: 00000: forked new backend, pid=31010 socket=10
Jun 28 11:04:47 MMN-0 postgres[23480]: [17152-2] [23480-576a1f04.5bb8-34309] 2016-06-28 03:04:47.621 GMT < > LOCATION: BackendStartup, postmaster.c:3760
Jun 28 11:04:47 MMN-0 postgres[31010]: [17152-1] [31010-5771e94f.7922-1] 2016-06-28 03:04:47.621 GMT <169.254.0.4 authentication> DEBUG: 00000: postgres child[31010]: starting with (
Jun 28 11:04:47 MMN-0 postgres[31010]: [17152-2] [31010-5771e94f.7922-2] 2016-06-28 03:04:47.621 GMT <169.254.0.4 authentication> LOCATION: BackendRun, postmaster.c:4051
Jun 28 11:04:47 MMN-0 postgres[31010]: [17153-1] [31010-5771e94f.7922-3] 2016-06-28 03:04:47.621 GMT <169.254.0.4 authentication> DEBUG: 00000: postgres
Jun 28 11:04:47 MMN-0 postgres[31010]: [17153-2] [31010-5771e94f.7922-4] 2016-06-28 03:04:47.621 GMT <169.254.0.4 authentication> LOCATION: BackendRun, postmaster.c:4054
Jun 28 11:04:47 MMN-0 postgres[31010]: [17154-1] [31010-5771e94f.7922-5] 2016-06-28 03:04:47.621 GMT <169.254.0.4 authentication> DEBUG: 00000: )
Jun 28 11:04:47 MMN-0 postgres[31010]: [17154-2] [31010-5771e94f.7922-6] 2016-06-28 03:04:47.621 GMT <169.254.0.4 authentication> LOCATION: BackendRun, postmaster.c:4056
Jun 28 11:04:47 MMN-0 postgres[31010]: [17155-1] [31010-5771e94f.7922-7] 2016-06-28 03:04:47.621 GMT <169.254.0.4 authentication> DEBUG: 00000: InitPostgres
Jun 28 11:04:47 MMN-0 postgres[31010]: [17155-2] [31010-5771e94f.7922-8] 2016-06-28 03:04:47.621 GMT <169.254.0.4 authentication> LOCATION: InitPostgres, postinit.c:506
Jun 28 11:04:47 MMN-0 postgres[31010]: [17156-1] [31010-5771e94f.7922-9] 2016-06-28 03:04:47.621 GMT <169.254.0.4 authentication> DEBUG: 00000: my backend ID is 5
Jun 28 11:04:47 MMN-0 postgres[31010]: [17156-2] [31010-5771e94f.7922-10] 2016-06-28 03:04:47.621 GMT <169.254.0.4 authentication> LOCATION: SharedInvalBackendInit, sinvaladt.c:330
Jun 28 11:04:47 MMN-0 postgres[31010]: [17157-1] [31010-5771e94f.7922-11] 2016-06-28 03:04:47.622 GMT <169.254.0.4 authentication> DEBUG: 00000: StartTransaction
Jun 28 11:04:47 MMN-0 postgres[31010]: [17157-2] [31010-5771e94f.7922-12] 2016-06-28 03:04:47.622 GMT <169.254.0.4 authentication> LOCATION: ShowTransactionState, xact.c:4469
Jun 28 11:04:47 MMN-0 postgres[31010]: [17158-1] [31010-5771e94f.7922-13] 2016-06-28 03:04:47.622 GMT <169.254.0.4 authentication> DEBUG: 00000: name: unnamed; blockState: DEFAULT; state: INPROGR, xid/subid/cid: 0/1/0, nestlvl: 1, children:
Jun 28 11:04:47 MMN-0 postgres[31010]: [17158-2] [31010-5771e94f.7922-14] 2016-06-28 03:04:47.622 GMT <169.254.0.4 authentication> LOCATION: ShowTransactionStateRec, xact.c:4507
Jun 28 11:04:47 MMN-0 postgres[31010]: [17159-1] [31010-5771e94f.7922-15] 2016-06-28 03:04:47.623 GMT <169.254.0.4 startup> DEBUG: 00000: CommitTransaction
Jun 28 11:04:47 MMN-0 postgres[31010]: [17159-2] [31010-5771e94f.7922-16] 2016-06-28 03:04:47.623 GMT <169.254.0.4 startup> LOCATION: ShowTransactionState, xact.c:4469
Jun 28 11:04:47 MMN-0 postgres[31010]: [17160-1] [31010-5771e94f.7922-17] 2016-06-28 03:04:47.623 GMT <169.254.0.4 startup> DEBUG: 00000: name: unnamed; blockState: STARTED; state: INPROGR, xid/subid/cid: 0/1/0, nestlvl: 1, children:
Jun 28 11:04:47 MMN-0 postgres[31010]: [17160-2] [31010-5771e94f.7922-18] 2016-06-28 03:04:47.623 GMT <169.254.0.4 startup> LOCATION: ShowTransactionStateRec, xact.c:4507
Jun 28 11:04:47 MMN-0 pgpool[26802]: [23-1] 2016-06-28 11:04:47: pid 26802: DEBUG: pool_read: read 341 bytes from backend 0
Jun 28 11:04:47 MMN-0 pgpool[26802]: [23-2] 2016-06-28 11:04:47: pid 26802: LOCATION: pool_stream.c:190
Jun 28 11:04:47 MMN-0 pgpool[26802]: [24-1] 2016-06-28 11:04:47: pid 26802: DEBUG: reading message length
Jun 28 11:04:47 MMN-0 pgpool[26802]: [24-2] 2016-06-28 11:04:47: pid 26802: DETAIL: slot: 0 length: 8
Jun 28 11:04:47 MMN-0 pgpool[26802]: [24-3] 2016-06-28 11:04:47: pid 26802: LOCATION: pool_auth.c:1107
Jun 28 11:04:47 MMN-0 pgpool[26802]: [25-1] 2016-06-28 11:04:47: pid 26802: DEBUG: authentication backend
Jun 28 11:04:47 MMN-0 pgpool[26802]: [25-2] 2016-06-28 11:04:47: pid 26802: DETAIL: auth kind:0
Jun 28 11:04:47 MMN-0 pgpool[26802]: [25-3] 2016-06-28 11:04:47: pid 26802: LOCATION: pool_auth.c:142
Jun 28 11:04:47 MMN-0 pgpool[26802]: [26-1] 2016-06-28 11:04:47: pid 26802: DEBUG: reading message length
Jun 28 11:04:47 MMN-0 pgpool[26802]: [26-2] 2016-06-28 11:04:47: pid 26802: DETAIL: master slot: 0 length: 22
Jun 28 11:04:47 MMN-0 pgpool[26802]: [26-3] 2016-06-28 11:04:47: pid 26802: LOCATION: pool_auth.c:1161
Jun 28 11:04:47 MMN-0 pgpool[26802]: [27-1] 2016-06-28 11:04:47: pid 26802: DEBUG: process parameter status
Jun 28 11:04:47 MMN-0 pgpool[26802]: [27-2] 2016-06-28 11:04:47: pid 26802: DETAIL: backend:0 name:"application_name" value:""
Jun 28 11:04:47 MMN-0 pgpool[26802]: [27-3] 2016-06-28 11:04:47: pid 26802: LOCATION: pool_process_query.c:927
Jun 28 11:04:47 MMN-0 pgpool[26802]: [28-1] 2016-06-28 11:04:47: pid 26802: DEBUG: reading message length
Jun 28 11:04:47 MMN-0 pgpool[26802]: [28-2] 2016-06-28 11:04:47: pid 26802: DETAIL: master slot: 0 length: 25
Jun 28 11:04:47 MMN-0 pgpool[26802]: [28-3] 2016-06-28 11:04:47: pid 26802: LOCATION: pool_auth.c:1161
Jun 28 11:04:47 MMN-0 pgpool[26802]: [29-1] 2016-06-28 11:04:47: pid 26802: DEBUG: process parameter status
Jun 28 11:04:47 MMN-0 pgpool[26802]: [29-2] 2016-06-28 11:04:47: pid 26802: DETAIL: backend:0 name:"client_encoding" value:"UTF8"
Jun 28 11:04:47 MMN-0 pgpool[26802]: [29-3] 2016-06-28 11:04:47: pid 26802: LOCATION: pool_process_query.c:927
Jun 28 11:04:47 MMN-0 pgpool[26802]: [30-1] 2016-06-28 11:04:47: pid 26802: DEBUG: reading message length
Jun 28 11:04:47 MMN-0 pgpool[26802]: [30-2] 2016-06-28 11:04:47: pid 26802: DETAIL: master slot: 0 length: 23
Jun 28 11:04:47 MMN-0 pgpool[26802]: [30-3] 2016-06-28 11:04:47: pid 26802: LOCATION: pool_auth.c:1161
Jun 28 11:04:47 MMN-0 pgpool[26802]: [31-1] 2016-06-28 11:04:47: pid 26802: DEBUG: process parameter status
Jun 28 11:04:47 MMN-0 pgpool[26802]: [31-2] 2016-06-28 11:04:47: pid 26802: DETAIL: backend:0 name:"DateStyle" value:"ISO, MDY"
Jun 28 11:04:47 MMN-0 pgpool[26802]: [31-3] 2016-06-28 11:04:47: pid 26802: LOCATION: pool_process_query.c:927
Jun 28 11:04:47 MMN-0 pgpool[26802]: [32-1] 2016-06-28 11:04:47: pid 26802: DEBUG: reading message length
Jun 28 11:04:47 MMN-0 pgpool[26802]: [32-2] 2016-06-28 11:04:47: pid 26802: DETAIL: master slot: 0 length: 25
Jun 28 11:04:47 MMN-0 pgpool[26802]: [32-3] 2016-06-28 11:04:47: pid 26802: LOCATION: pool_auth.c:1161
Jun 28 11:04:47 MMN-0 pgpool[26802]: [33-1] 2016-06-28 11:04:47: pid 26802: DEBUG: process parameter status
Jun 28 11:04:47 MMN-0 pgpool[26802]: [33-2] 2016-06-28 11:04:47: pid 26802: DETAIL: backend:0 name:"integer_datetimes" value:"on"
Jun 28 11:04:47 MMN-0 pgpool[26802]: [33-3] 2016-06-28 11:04:47: pid 26802: LOCATION: pool_process_query.c:927
Jun 28 11:04:47 MMN-0 pgpool[26802]: [34-1] 2016-06-28 11:04:47: pid 26802: DEBUG: reading message length
Jun 28 11:04:47 MMN-0 pgpool[26802]: [34-2] 2016-06-28 11:04:47: pid 26802: DETAIL: master slot: 0 length: 27
Jun 28 11:04:47 MMN-0 pgpool[26802]: [34-3] 2016-06-28 11:04:47: pid 26802: LOCATION: pool_auth.c:1161
Jun 28 11:04:47 MMN-0 pgpool[26802]: [35-1] 2016-06-28 11:04:47: pid 26802: DEBUG: process parameter status
Jun 28 11:04:47 MMN-0 pgpool[26802]: [35-2] 2016-06-28 11:04:47: pid 26802: DETAIL: backend:0 name:"IntervalStyle" value:"postgres"
Jun 28 11:04:47 MMN-0 pgpool[26802]: [35-3] 2016-06-28 11:04:47: pid 26802: LOCATION: pool_process_query.c:927
Jun 28 11:04:47 MMN-0 pgpool[26802]: [36-1] 2016-06-28 11:04:47: pid 26802: DEBUG: reading message length
Jun 28 11:04:47 MMN-0 pgpool[26802]: [36-2] 2016-06-28 11:04:47: pid 26802: DETAIL: master slot: 0 length: 20
Jun 28 11:04:47 MMN-0 pgpool[26802]: [36-3] 2016-06-28 11:04:47: pid 26802: LOCATION: pool_auth.c:1161
Jun 28 11:04:47 MMN-0 pgpool[26802]: [37-1] 2016-06-28 11:04:47: pid 26802: DEBUG: process parameter status
Jun 28 11:04:47 MMN-0 pgpool[26802]: [37-2] 2016-06-28 11:04:47: pid 26802: DETAIL: backend:0 name:"is_superuser" value:"on"
Jun 28 11:04:47 MMN-0 pgpool[26802]: [37-3] 2016-06-28 11:04:47: pid 26802: LOCATION: pool_process_query.c:927
Jun 28 11:04:47 MMN-0 pgpool[26802]: [38-1] 2016-06-28 11:04:47: pid 26802: DEBUG: reading message length
Jun 28 11:04:47 MMN-0 pgpool[26802]: [38-2] 2016-06-28 11:04:47: pid 26802: DETAIL: master slot: 0 length: 25
Jun 28 11:04:47 MMN-0 pgpool[26802]: [38-3] 2016-06-28 11:04:47: pid 26802: LOCATION: pool_auth.c:1161
Jun 28 11:04:47 MMN-0 pgpool[26802]: [39-1] 2016-06-28 11:04:47: pid 26802: DEBUG: process parameter status
Jun 28 11:04:47 MMN-0 pgpool[26802]: [39-2] 2016-06-28 11:04:47: pid 26802: DETAIL: backend:0 name:"server_encoding" value:"UTF8"
Jun 28 11:04:47 MMN-0 pgpool[26802]: [39-3] 2016-06-28 11:04:47: pid 26802: LOCATION: pool_process_query.c:927
Jun 28 11:04:47 MMN-0 pgpool[26802]: [40-1] 2016-06-28 11:04:47: pid 26802: DEBUG: reading message length
Jun 28 11:04:47 MMN-0 pgpool[26802]: [40-2] 2016-06-28 11:04:47: pid 26802: DETAIL: master slot: 0 length: 25
Jun 28 11:04:47 MMN-0 pgpool[26802]: [40-3] 2016-06-28 11:04:47: pid 26802: LOCATION: pool_auth.c:1161
Jun 28 11:04:47 MMN-0 pgpool[26802]: [41-1] 2016-06-28 11:04:47: pid 26802: DEBUG: process parameter status
Jun 28 11:04:47 MMN-0 pgpool[26802]: [41-2] 2016-06-28 11:04:47: pid 26802: DETAIL: backend:0 name:"server_version" value:"9.3.6"
Jun 28 11:04:47 MMN-0 pgpool[26802]: [41-3] 2016-06-28 11:04:47: pid 26802: LOCATION: pool_process_query.c:927
Jun 28 11:04:47 MMN-0 pgpool[26802]: [42-1] 2016-06-28 11:04:47: pid 26802: DEBUG: reading message length
Jun 28 11:04:47 MMN-0 pgpool[26802]: [42-2] 2016-06-28 11:04:47: pid 26802: DETAIL: master slot: 0 length: 48
Jun 28 11:04:47 MMN-0 pgpool[26802]: [42-3] 2016-06-28 11:04:47: pid 26802: LOCATION: pool_auth.c:1161
Jun 28 11:04:47 MMN-0 pgpool[26802]: [43-1] 2016-06-28 11:04:47: pid 26802: DEBUG: process parameter status
Jun 28 11:04:47 MMN-0 pgpool[26802]: [43-2] 2016-06-28 11:04:47: pid 26802: DETAIL: backend:0 name:"session_authorization" value:"_nokfssystestpostgres"
Jun 28 11:04:47 MMN-0 pgpool[26802]: [43-3] 2016-06-28 11:04:47: pid 26802: LOCATION: pool_process_query.c:927
Jun 28 11:04:47 MMN-0 pgpool[26802]: [44-1] 2016-06-28 11:04:47: pid 26802: DEBUG: reading message length
Jun 28 11:04:47 MMN-0 pgpool[26802]: [44-2] 2016-06-28 11:04:47: pid 26802: DETAIL: master slot: 0 length: 35
Jun 28 11:04:47 MMN-0 pgpool[26802]: [44-3] 2016-06-28 11:04:47: pid 26802: LOCATION: pool_auth.c:1161
Jun 28 11:04:47 MMN-0 pgpool[26802]: [45-1] 2016-06-28 11:04:47: pid 26802: DEBUG: process parameter status
Jun 28 11:04:47 MMN-0 pgpool[26802]: [45-2] 2016-06-28 11:04:47: pid 26802: DETAIL: backend:0 name:"standard_conforming_strings" value:"on"
Jun 28 11:04:47 MMN-0 pgpool[26802]: [45-3] 2016-06-28 11:04:47: pid 26802: LOCATION: pool_process_query.c:927
Jun 28 11:04:47 MMN-0 pgpool[26802]: [46-1] 2016-06-28 11:04:47: pid 26802: DEBUG: reading message length
Jun 28 11:04:47 MMN-0 pgpool[26802]: [46-2] 2016-06-28 11:04:47: pid 26802: DETAIL: master slot: 0 length: 27
Jun 28 11:04:47 MMN-0 pgpool[26802]: [46-3] 2016-06-28 11:04:47: pid 26802: LOCATION: pool_auth.c:1161
Jun 28 11:04:47 MMN-0 pgpool[26802]: [47-1] 2016-06-28 11:04:47: pid 26802: DEBUG: process parameter status
Jun 28 11:04:47 MMN-0 pgpool[26802]: [47-2] 2016-06-28 11:04:47: pid 26802: DETAIL: backend:0 name:"TimeZone" value:"Asia/Shanghai"
Jun 28 11:04:47 MMN-0 pgpool[26802]: [47-3] 2016-06-28 11:04:47: pid 26802: LOCATION: pool_process_query.c:927
Jun 28 11:04:47 MMN-0 pgpool[26802]: [48-1] 2016-06-28 11:04:47: pid 26802: DEBUG: reading message length
Jun 28 11:04:47 MMN-0 pgpool[26802]: [48-2] 2016-06-28 11:04:47: pid 26802: DETAIL: slot: 0 length: 12
Jun 28 11:04:47 MMN-0 pgpool[26802]: [48-3] 2016-06-28 11:04:47: pid 26802: LOCATION: pool_auth.c:1107
Jun 28 11:04:47 MMN-0 pgpool[26802]: [49-1] 2016-06-28 11:04:47: pid 26802: DEBUG: authentication backend
Jun 28 11:04:47 MMN-0 pgpool[26802]: [49-2] 2016-06-28 11:04:47: pid 26802: DETAIL: cp->info[i]:0x7f20426e6000 pid:31010
Jun 28 11:04:47 MMN-0 pgpool[26802]: [49-3] 2016-06-28 11:04:47: pid 26802: LOCATION: pool_auth.c:391
Jun 28 11:04:47 MMN-0 pgpool[26802]: [50-1] 2016-06-28 11:04:47: pid 26802: DEBUG: sending backend key data
Jun 28 11:04:47 MMN-0 pgpool[26802]: [50-2] 2016-06-28 11:04:47: pid 26802: DETAIL: send pid 31010 to frontend
Jun 28 11:04:47 MMN-0 pgpool[26802]: [50-3] 2016-06-28 11:04:47: pid 26802: LOCATION: pool_auth.c:519
Jun 28 11:04:47 MMN-0 pgpool[26802]: [51-1] 2016-06-28 11:04:47: pid 26802: DEBUG: selecting load balance node
Jun 28 11:04:47 MMN-0 pgpool[26802]: [51-2] 2016-06-28 11:04:47: pid 26802: DETAIL: selected backend id is 0
Jun 28 11:04:47 MMN-0 pgpool[26802]: [51-3] 2016-06-28 11:04:47: pid 26802: LOCATION: child.c:1720
Jun 28 11:04:47 MMN-0 pgpool[26802]: [52-1] 2016-06-28 11:04:47: pid 26802: DEBUG: initializing session context
Jun 28 11:04:47 MMN-0 pgpool[26802]: [52-2] 2016-06-28 11:04:47: pid 26802: DETAIL: selected load balancing node: 0
Jun 28 11:04:47 MMN-0 pgpool[26802]: [52-3] 2016-06-28 11:04:47: pid 26802: LOCATION: pool_session_context.c:99
Jun 28 11:04:47 MMN-0 pgpool[26802]: [53-1] 2016-06-28 11:04:47: pid 26802: DEBUG: session context: unsetting query in progress. DONE
Jun 28 11:04:47 MMN-0 pgpool[26802]: [53-2] 2016-06-28 11:04:47: pid 26802: LOCATION: pool_session_context.c:219
Jun 28 11:04:47 MMN-0 pgpool[26802]: [54-1] 2016-06-28 11:04:47: pid 26802: DEBUG: session context: clearing transaction isolation. DONE
Jun 28 11:04:47 MMN-0 pgpool[26802]: [54-2] 2016-06-28 11:04:47: pid 26802: LOCATION: pool_session_context.c:731
Jun 28 11:04:47 MMN-0 pgpool[26802]: [55-1] 2016-06-28 11:04:47: pid 26802: DEBUG: session context: clearing writing transaction. DONE
Jun 28 11:04:47 MMN-0 pgpool[26802]: [55-2] 2016-06-28 11:04:47: pid 26802: LOCATION: pool_session_context.c:565
Jun 28 11:04:47 MMN-0 pgpool[26802]: [56-1] 2016-06-28 11:04:47: pid 26802: DEBUG: session context: clearing failed transaction. DONE
Jun 28 11:04:47 MMN-0 pgpool[26802]: [56-2] 2016-06-28 11:04:47: pid 26802: LOCATION: pool_session_context.c:594
Jun 28 11:04:47 MMN-0 pgpool[26802]: [57-1] 2016-06-28 11:04:47: pid 26802: DEBUG: session context: clearing failed transaction. DONE
Jun 28 11:04:47 MMN-0 pgpool[26802]: [57-2] 2016-06-28 11:04:47: pid 26802: LOCATION: pool_session_context.c:624
Jun 28 11:04:47 MMN-0 pgpool[26802]: [58-1] 2016-06-28 11:04:47: pid 26802: DEBUG: session context: clearing skip reading from backends. DONE
Jun 28 11:04:47 MMN-0 pgpool[26802]: [58-2] 2016-06-28 11:04:47: pid 26802: LOCATION: pool_session_context.c:250
Jun 28 11:04:47 MMN-0 pgpool[26802]: [59-1] 2016-06-28 11:04:47: pid 26802: DEBUG: session context: clearing ignore till sync. DONE
Jun 28 11:04:47 MMN-0 pgpool[26802]: [59-2] 2016-06-28 11:04:47: pid 26802: LOCATION: pool_session_context.c:310
Jun 28 11:04:47 MMN-0 pgpool[26802]: [60-1] 2016-06-28 11:04:47: pid 26802: DEBUG: pool_process_query
Jun 28 11:04:47 MMN-0 pgpool[26802]: [60-2] 2016-06-28 11:04:47: pid 26802: LOCATION: pool_process_query.c:213
Jun 28 11:04:47 MMN-0 pgpool[26802]: [61-1] 2016-06-28 11:04:47: pid 26802: DEBUG: processing backend response
Jun 28 11:04:47 MMN-0 pgpool[26802]: [61-2] 2016-06-28 11:04:47: pid 26802: LOCATION: pool_proto_modules.c:2411
Jun 28 11:04:47 MMN-0 pgpool[26802]: [62-1] 2016-06-28 11:04:47: pid 26802: DEBUG: pool_use_sync_map: we cannot use sync map because STREAM: 0 query in progress: 0 doing extended query: 0
Jun 28 11:04:47 MMN-0 pgpool[26802]: [62-2] 2016-06-28 11:04:47: pid 26802: LOCATION: pool_session_context.c:969
Jun 28 11:04:47 MMN-0 pgpool[26802]: [63-1] 2016-06-28 11:04:47: pid 26802: DEBUG: read_kind_from_backend from 0
Jun 28 11:04:47 MMN-0 pgpool[26802]: [63-2] 2016-06-28 11:04:47: pid 26802: LOCATION: pool_process_query.c:3297
Jun 28 11:04:47 MMN-0 pgpool[26802]: [64-1] 2016-06-28 11:04:47: pid 26802: DEBUG: reading backend data packet kind
Jun 28 11:04:47 MMN-0 pgpool[26802]: [64-2] 2016-06-28 11:04:47: pid 26802: DETAIL: backend:0 kind:'Z'
Jun 28 11:04:47 MMN-0 pgpool[26802]: [64-3] 2016-06-28 11:04:47: pid 26802: LOCATION: pool_process_query.c:3316
Jun 28 11:04:47 MMN-0 pgpool[26802]: [65-1] 2016-06-28 11:04:47: pid 26802: DEBUG: reading backend data packet kind
Jun 28 11:04:47 MMN-0 pgpool[26802]: [65-2] 2016-06-28 11:04:47: pid 26802: DETAIL: backend:0 of 3 kind = 'Z'
Jun 28 11:04:47 MMN-0 pgpool[26802]: [65-3] 2016-06-28 11:04:47: pid 26802: LOCATION: pool_process_query.c:3357
Jun 28 11:04:47 MMN-0 pgpool[26802]: [66-1] 2016-06-28 11:04:47: pid 26802: DEBUG: read_kind_from_backend max_count:1.000000 num_executed_nodes:1
Jun 28 11:04:47 MMN-0 pgpool[26802]: [66-2] 2016-06-28 11:04:47: pid 26802: LOCATION: pool_process_query.c:3373
Jun 28 11:04:47 MMN-0 pgpool[26802]: [67-1] 2016-06-28 11:04:47: pid 26802: DEBUG: processing backend response
Jun 28 11:04:47 MMN-0 pgpool[26802]: [67-2] 2016-06-28 11:04:47: pid 26802: DETAIL: received kind 'Z'(5a) from backend
Jun 28 11:04:47 MMN-0 pgpool[26802]: [67-3] 2016-06-28 11:04:47: pid 26802: LOCATION: pool_proto_modules.c:2425
Jun 28 11:04:47 MMN-0 pgpool[26802]: [68-1] 2016-06-28 11:04:47: pid 26802: DEBUG: processing backend response
Jun 28 11:04:47 MMN-0 pgpool[26802]: [68-2] 2016-06-28 11:04:47: pid 26802: DETAIL: Ready For Query received
Jun 28 11:04:47 MMN-0 pgpool[26802]: [68-3] 2016-06-28 11:04:47: pid 26802: LOCATION: pool_proto_modules.c:2443
Jun 28 11:04:47 MMN-0 pgpool[26802]: [69-1] 2016-06-28 11:04:47: pid 26802: DEBUG: session context: clearing ignore till sync. DONE
Jun 28 11:04:47 MMN-0 pgpool[26802]: [69-2] 2016-06-28 11:04:47: pid 26802: LOCATION: pool_session_context.c:310
Jun 28 11:04:47 MMN-0 pgpool[26802]: [70-1] 2016-06-28 11:04:47: pid 26802: DEBUG: pool_use_sync_map: we cannot use sync map because STREAM: 0 query in progress: 0 doing extended query: 0
Jun 28 11:04:47 MMN-0 pgpool[26802]: [70-2] 2016-06-28 11:04:47: pid 26802: LOCATION: pool_session_context.c:969
Jun 28 11:04:47 MMN-0 pgpool[26802]: [71-1] 2016-06-28 11:04:47: pid 26802: DEBUG: pool_use_sync_map: we cannot use sync map because STREAM: 0 query in progress: 0 doing extended query: 0
Jun 28 11:04:47 MMN-0 pgpool[26802]: [71-2] 2016-06-28 11:04:47: pid 26802: LOCATION: pool_session_context.c:969
Jun 28 11:04:47 MMN-0 pgpool[26802]: [72-1] 2016-06-28 11:04:47: pid 26802: DEBUG: pool_use_sync_map: we cannot use sync map because STREAM: 0 query in progress: 0 doing extended query: 0
Jun 28 11:04:47 MMN-0 pgpool[26802]: [72-2] 2016-06-28 11:04:47: pid 26802: LOCATION: pool_session_context.c:969
Jun 28 11:04:47 MMN-0 pgpool[26802]: [73-1] 2016-06-28 11:04:47: pid 26802: DEBUG: reading message length
Jun 28 11:04:47 MMN-0 pgpool[26802]: [73-2] 2016-06-28 11:04:47: pid 26802: DETAIL: slot: 0 length: 5
Jun 28 11:04:47 MMN-0 pgpool[26802]: [73-3] 2016-06-28 11:04:47: pid 26802: LOCATION: pool_auth.c:1107
Jun 28 11:04:47 MMN-0 pgpool[26802]: [74-1] 2016-06-28 11:04:47: pid 26802: DEBUG: processing ReadyForQuery
Jun 28 11:04:47 MMN-0 pgpool[26802]: [74-2] 2016-06-28 11:04:47: pid 26802: DETAIL: transaction state '
Jun 28 11:04:47 MMN-0 pgpool[26802]: [74-3] 2016-06-28 11:04:47: pid 26802: LOCATION: pool_proto_modules.c:1612
Jun 28 11:04:47 MMN-0 pgpool[26802]: [75-1] 2016-06-28 11:04:47: pid 26802: DEBUG: processing frontend response
Jun 28 11:04:47 MMN-0 pgpool[26802]: [75-2] 2016-06-28 11:04:47: pid 26802: DETAIL: received kind 'P'(50) from frontend
Jun 28 11:04:47 MMN-0 pgpool[26802]: [75-3] 2016-06-28 11:04:47: pid 26802: LOCATION: pool_proto_modules.c:2188
Jun 28 11:04:47 MMN-0 pgpool[26802]: [76-1] 2016-06-28 11:04:47: pid 26802: DEBUG: session context: clearing doing extended query messaging. DONE
Jun 28 11:04:47 MMN-0 pgpool[26802]: [76-2] 2016-06-28 11:04:47: pid 26802: LOCATION: pool_session_context.c:280
Jun 28 11:04:47 MMN-0 pgpool[26802]: [77-1] 2016-06-28 11:04:47: pid 26802: DEBUG: session context: setting doing extended query messaging. DONE
Jun 28 11:04:47 MMN-0 pgpool[26802]: [77-2] 2016-06-28 11:04:47: pid 26802: LOCATION: pool_session_context.c:269
Jun 28 11:04:47 MMN-0 pgpool[26802]: [78-1] 2016-06-28 11:04:47: pid 26802: DEBUG: Parse: statement name <>
Jun 28 11:04:47 MMN-0 pgpool[26802]: [78-2] 2016-06-28 11:04:47: pid 26802: LOCATION: pool_proto_modules.c:817
Jun 28 11:04:47 MMN-0 pgpool[26802]: [79-1] 2016-06-28 11:04:47: pid 26802: DEBUG: session context: setting query in progress. DONE
Jun 28 11:04:47 MMN-0 pgpool[26802]: [79-2] 2016-06-28 11:04:47: pid 26802: LOCATION: pool_session_context.c:208
Jun 28 11:04:47 MMN-0 pgpool[26802]: [80-1] 2016-06-28 11:04:47: pid 26802: DEBUG: decide where to send the queries
Jun 28 11:04:47 MMN-0 pgpool[26802]: [80-2] 2016-06-28 11:04:47: pid 26802: DETAIL: destination = 3 for query= "SET extra_float_digits = 3"
Jun 28 11:04:47 MMN-0 pgpool[26802]: [80-3] 2016-06-28 11:04:47: pid 26802: LOCATION: pool_query_context.c:370
Jun 28 11:04:47 MMN-0 pgpool[26802]: [81-1] 2016-06-28 11:04:47: pid 26802: DEBUG: Parse: waiting for master completing the query
Jun 28 11:04:47 MMN-0 pgpool[26802]: [81-2] 2016-06-28 11:04:47: pid 26802: LOCATION: pool_proto_modules.c:1064
Jun 28 11:04:47 MMN-0 pgpool[26802]: [82-1] 2016-06-28 11:04:47: pid 26802: LOG: DB node id: 0 backend pid: 31010 statement: Parse: SET extra_float_digits = 3
Jun 28 11:04:47 MMN-0 pgpool[26802]: [82-2] 2016-06-28 11:04:47: pid 26802: LOCATION: pool_proto_modules.c:2966
Jun 28 11:04:47 MMN-0 pgpool[26802]: [83-1] 2016-06-28 11:04:47: pid 26802: DEBUG: pool_send_and_wait: pool_set_sync_map: 0
Jun 28 11:04:47 MMN-0 pgpool[26802]: [83-2] 2016-06-28 11:04:47: pid 26802: LOCATION: pool_query_context.c:854
Jun 28 11:04:47 MMN-0 pgpool[26802]: [84-1] 2016-06-28 11:04:47: pid 26802: DEBUG: pool_write: to backend: kind:P
Jun 28 11:04:47 MMN-0 pgpool[26802]: [84-2] 2016-06-28 11:04:47: pid 26802: LOCATION: pool_stream.c:431
Jun 28 11:04:47 MMN-0 pgpool[26802]: [85-1] 2016-06-28 11:04:47: pid 26802: DEBUG: pool_write: to backend: kind:H
Jun 28 11:04:47 MMN-0 pgpool[26802]: [85-2] 2016-06-28 11:04:47: pid 26802: LOCATION: pool_stream.c:431
Jun 28 11:04:47 MMN-0 pgpool[26802]: [86-1] 2016-06-28 11:04:47: pid 26802: DEBUG: waiting for query response
Jun 28 11:04:47 MMN-0 pgpool[26802]: [86-2] 2016-06-28 11:04:47: pid 26802: DETAIL: waiting for backend:0 to complete the query
Jun 28 11:04:47 MMN-0 pgpool[26802]: [86-3] 2016-06-28 11:04:47: pid 26802: LOCATION: pool_process_query.c:483
Jun 28 11:04:47 MMN-0 postgres[31010]: [17161-1] [31010-5771e94f.7922-19] 2016-06-28 03:04:47.647 GMT <169.254.0.4 PARSE> DEBUG: 00000: parse <unnamed>: SET extra_float_digits = 3
Jun 28 11:04:47 MMN-0 postgres[31010]: [17161-2] [31010-5771e94f.7922-20] 2016-06-28 03:04:47.647 GMT <169.254.0.4 PARSE> LOCATION: exec_parse_message, postgres.c:1201
Jun 28 11:04:47 MMN-0 postgres[31010]: [17161-3] [31010-5771e94f.7922-21] 2016-06-28 03:04:47.647 GMT <169.254.0.4 PARSE> STATEMENT: SET extra_float_digits = 3
Jun 28 11:04:47 MMN-0 postgres[31010]: [17162-1] [31010-5771e94f.7922-22] 2016-06-28 03:04:47.647 GMT <169.254.0.4 PARSE> DEBUG: 00000: StartTransactionCommand
Jun 28 11:04:47 MMN-0 postgres[31010]: [17162-2] [31010-5771e94f.7922-23] 2016-06-28 03:04:47.647 GMT <169.254.0.4 PARSE> LOCATION: start_xact_command, postgres.c:2414
Jun 28 11:04:47 MMN-0 postgres[31010]: [17162-3] [31010-5771e94f.7922-24] 2016-06-28 03:04:47.647 GMT <169.254.0.4 PARSE> STATEMENT: SET extra_float_digits = 3
Jun 28 11:04:47 MMN-0 postgres[31010]: [17163-1] [31010-5771e94f.7922-25] 2016-06-28 03:04:47.647 GMT <169.254.0.4 PARSE> DEBUG: 00000: StartTransaction
Jun 28 11:04:47 MMN-0 postgres[31010]: [17163-2] [31010-5771e94f.7922-26] 2016-06-28 03:04:47.647 GMT <169.254.0.4 PARSE> LOCATION: ShowTransactionState, xact.c:4469
Jun 28 11:04:47 MMN-0 postgres[31010]: [17163-3] [31010-5771e94f.7922-27] 2016-06-28 03:04:47.647 GMT <169.254.0.4 PARSE> STATEMENT: SET extra_float_digits = 3
Jun 28 11:04:47 MMN-0 postgres[31010]: [17164-1] [31010-5771e94f.7922-28] 2016-06-28 03:04:47.647 GMT <169.254.0.4 PARSE> DEBUG: 00000: name: unnamed; blockState: DEFAULT; state: INPROGR, xid/subid/cid: 0/1/0, nestlvl: 1, children:
Jun 28 11:04:47 MMN-0 postgres[31010]: [17164-2] [31010-5771e94f.7922-29] 2016-06-28 03:04:47.647 GMT <169.254.0.4 PARSE> LOCATION: ShowTransactionStateRec, xact.c:4507
Jun 28 11:04:47 MMN-0 postgres[31010]: [17164-3] [31010-5771e94f.7922-30] 2016-06-28 03:04:47.647 GMT <169.254.0.4 PARSE> STATEMENT: SET extra_float_digits = 3
Jun 28 11:04:47 MMN-0 pgpool[26802]: [87-1] 2016-06-28 11:04:47: pid 26802: DEBUG: pool_read: read 5 bytes from backend 0
Jun 28 11:04:47 MMN-0 pgpool[26802]: [87-2] 2016-06-28 11:04:47: pid 26802: LOCATION: pool_stream.c:190
Jun 28 11:04:47 MMN-0 pgpool[26802]: [88-1] 2016-06-28 11:04:47: pid 26802: DEBUG: detect error: kind: '1'
Jun 28 11:04:47 MMN-0 pgpool[26802]: [88-2] 2016-06-28 11:04:47: pid 26802: LOCATION: pool_process_query.c:4174
Jun 28 11:04:47 MMN-0 pgpool[26802]: [89-1] 2016-06-28 11:04:47: pid 26802: DEBUG: pool_process_query
Jun 28 11:04:47 MMN-0 pgpool[26802]: [89-2] 2016-06-28 11:04:47: pid 26802: LOCATION: pool_process_query.c:213
Jun 28 11:04:47 MMN-0 pgpool[26802]: [90-1] 2016-06-28 11:04:47: pid 26802: DEBUG: processing backend response
Jun 28 11:04:47 MMN-0 pgpool[26802]: [90-2] 2016-06-28 11:04:47: pid 26802: LOCATION: pool_proto_modules.c:2411
Jun 28 11:04:47 MMN-0 pgpool[26802]: [91-1] 2016-06-28 11:04:47: pid 26802: DEBUG: pool_use_sync_map: we cannot use sync map because STREAM: 0 query in progress: 1 doing extended query: 1
Jun 28 11:04:47 MMN-0 pgpool[26802]: [91-2] 2016-06-28 11:04:47: pid 26802: LOCATION: pool_session_context.c:969
Jun 28 11:04:47 MMN-0 pgpool[26802]: [92-1] 2016-06-28 11:04:47: pid 26802: DEBUG: read_kind_from_backend from 0
Jun 28 11:04:47 MMN-0 pgpool[26802]: [92-2] 2016-06-28 11:04:47: pid 26802: LOCATION: pool_process_query.c:3297
Jun 28 11:04:47 MMN-0 pgpool[26802]: [93-1] 2016-06-28 11:04:47: pid 26802: DEBUG: reading backend data packet kind
Jun 28 11:04:47 MMN-0 pgpool[26802]: [93-2] 2016-06-28 11:04:47: pid 26802: DETAIL: backend:0 kind:'1'
Jun 28 11:04:47 MMN-0 pgpool[26802]: [93-3] 2016-06-28 11:04:47: pid 26802: LOCATION: pool_process_query.c:3316
Jun 28 11:04:47 MMN-0 pgpool[26802]: [94-1] 2016-06-28 11:04:47: pid 26802: DEBUG: reading backend data packet kind
Jun 28 11:04:47 MMN-0 pgpool[26802]: [94-2] 2016-06-28 11:04:47: pid 26802: DETAIL: backend:0 of 3 kind = '1'
Jun 28 11:04:47 MMN-0 pgpool[26802]: [94-3] 2016-06-28 11:04:47: pid 26802: LOCATION: pool_process_query.c:3357
Jun 28 11:04:47 MMN-0 pgpool[26802]: [95-1] 2016-06-28 11:04:47: pid 26802: DEBUG: read_kind_from_backend max_count:1.000000 num_executed_nodes:1
Jun 28 11:04:47 MMN-0 pgpool[26802]: [95-2] 2016-06-28 11:04:47: pid 26802: LOCATION: pool_process_query.c:3373
Jun 28 11:04:47 MMN-0 pgpool[26802]: [96-1] 2016-06-28 11:04:47: pid 26802: DEBUG: processing backend response
Jun 28 11:04:47 MMN-0 pgpool[26802]: [96-2] 2016-06-28 11:04:47: pid 26802: DETAIL: received kind '1'(31) from backend
Jun 28 11:04:47 MMN-0 pgpool[26802]: [96-3] 2016-06-28 11:04:47: pid 26802: LOCATION: pool_proto_modules.c:2425
Jun 28 11:04:47 MMN-0 pgpool[26802]: [97-1] 2016-06-28 11:04:47: pid 26802: DEBUG: called by pool_add_sent_message: sent message: address: 21e9880 kind: P name: ==
Jun 28 11:04:47 MMN-0 pgpool[26802]: [97-2] 2016-06-28 11:04:47: pid 26802: LOCATION: pool_session_context.c:436
Jun 28 11:04:47 MMN-0 pgpool[26802]: [98-1] 2016-06-28 11:04:47: pid 26802: DEBUG: pool_use_sync_map: we cannot use sync map because STREAM: 0 query in progress: 1 doing extended query: 1
Jun 28 11:04:47 MMN-0 pgpool[26802]: [98-2] 2016-06-28 11:04:47: pid 26802: LOCATION: pool_session_context.c:969
Jun 28 11:04:47 MMN-0 pgpool[26802]: [99-1] 2016-06-28 11:04:47: pid 26802: DEBUG: SimpleForwardToFrontend
Jun 28 11:04:47 MMN-0 pgpool[26802]: [99-2] 2016-06-28 11:04:47: pid 26802: LOCATION: pool_process_query.c:735
Jun 28 11:04:47 MMN-0 pgpool[26802]: [100-1] 2016-06-28 11:04:47: pid 26802: DEBUG: SimpleForwardToFrontend
Jun 28 11:04:47 MMN-0 pgpool[26802]: [100-2] 2016-06-28 11:04:47: pid 26802: LOCATION: pool_process_query.c:742
Jun 28 11:04:47 MMN-0 pgpool[26802]: [101-1] 2016-06-28 11:04:47: pid 26802: DEBUG: SimpleForwardToFrontend: packet:1 length:0
Jun 28 11:04:47 MMN-0 pgpool[26802]: [101-2] 2016-06-28 11:04:47: pid 26802: LOCATION: pool_process_query.c:798
Jun 28 11:04:47 MMN-0 pgpool[26802]: [102-1] 2016-06-28 11:04:47: pid 26802: DEBUG: session context: setting command success. DONE
Jun 28 11:04:47 MMN-0 pgpool[26802]: [102-2] 2016-06-28 11:04:47: pid 26802: LOCATION: pool_session_context.c:741
Jun 28 11:04:47 MMN-0 pgpool[26802]: [103-1] 2016-06-28 11:04:47: pid 26802: DEBUG: pool_process_query
Jun 28 11:04:47 MMN-0 pgpool[26802]: [103-2] 2016-06-28 11:04:47: pid 26802: LOCATION: pool_process_query.c:213
Jun 28 11:04:47 MMN-0 pgpool[26802]: [104-1] 2016-06-28 11:04:47: pid 26802: DEBUG: processing backend response
Jun 28 11:04:47 MMN-0 pgpool[26802]: [104-2] 2016-06-28 11:04:47: pid 26802: LOCATION: pool_proto_modules.c:2411
Jun 28 11:04:47 MMN-0 pgpool[26802]: [105-1] 2016-06-28 11:04:47: pid 26802: DEBUG: pool_use_sync_map: we cannot use sync map because STREAM: 0 query in progress: 1 doing extended query: 1
Jun 28 11:04:47 MMN-0 pgpool[26802]: [105-2] 2016-06-28 11:04:47: pid 26802: LOCATION: pool_session_context.c:969
Jun 28 11:04:47 MMN-0 pgpool[26802]: [106-1] 2016-06-28 11:04:47: pid 26802: DEBUG: read_kind_from_backend from 0
Jun 28 11:04:47 MMN-0 pgpool[26802]: [106-2] 2016-06-28 11:04:47: pid 26802: LOCATION: pool_process_query.c:3297
TagsNo tags attached.

Activities

t-ishii

2016-07-04 11:00

developer   ~0000880

I am not familiar with YCSB. If it's a Java application, can you show the log when debug option is enabled in JDBC driver?

zh1029

2016-07-15 14:04

reporter   ~0000914

Thanks for taking look at the issue. Now looks I located the code where trigger the problem.
it is in function ProcessBackendResponse() in pool_proto_modules.c.
"if (MAJOR(backend) == PROTO_MAJOR_V3)
{
  switch (kind)
  {
      ......
      case '1': /* ParseComplete */
    status = ParseComplete(frontend, backend);
    pool_set_command_success();
    if (REPLICATION||RAW_MODE)
      pool_unset_query_in_progress();
    break;
          case '2': /* BindComplete */
        status = BindComplete(frontend, backend);
        pool_set_command_success();
        if (REPLICATION||RAW_MODE)
                pool_unset_query_in_progress();
    break;
        ......
  }
}"
for REPLICATION or RAW_MODE. the progress flag is unset. but not for MASTER_SLAVE mode. Then PGPool is still in progress(waiting for message from backend?). after I added MASTER_SLAVE in the codition judgement. YCSB can proceed. but I don't understand why code is designed like it.I'm not sure if it is a bug of some configuration wrong. but it does work after I changed the code.

zh1029

2016-07-15 14:21

reporter   ~0000916

I reproduced the problem and pasted both jdbc and pgpool log.
PGPOOL log ==>
Jul 15 13:18:32 MMN-0 pgpool[32614]: [1-1] 2016-07-15 13:18:32: pid 32614: DEBUG: initializing pool configuration
Jul 15 13:18:32 MMN-0 pgpool[32614]: [1-2] 2016-07-15 13:18:32: pid 32614: DETAIL: num_backends: 4 total_weight: 4.000000
Jul 15 13:18:32 MMN-0 pgpool[32614]: [1-3] 2016-07-15 13:18:32: pid 32614: LOCATION: pool_config.l:3394
Jul 15 13:18:32 MMN-0 pgpool[32614]: [2-1] 2016-07-15 13:18:32: pid 32614: DEBUG: initializing pool configuration
Jul 15 13:18:32 MMN-0 pgpool[32614]: [2-2] 2016-07-15 13:18:32: pid 32614: DETAIL: backend 0 weight: 536870911.750000 flag: 0000 backend_status: 1
Jul 15 13:18:32 MMN-0 pgpool[32614]: [2-3] 2016-07-15 13:18:32: pid 32614: LOCATION: pool_config.l:3413
Jul 15 13:18:32 MMN-0 pgpool[32614]: [3-1] 2016-07-15 13:18:32: pid 32614: DEBUG: initializing pool configuration
Jul 15 13:18:32 MMN-0 pgpool[32614]: [3-2] 2016-07-15 13:18:32: pid 32614: DETAIL: backend 1 weight: 536870911.750000 flag: 0000 backend_status: 1
Jul 15 13:18:32 MMN-0 pgpool[32614]: [3-3] 2016-07-15 13:18:32: pid 32614: LOCATION: pool_config.l:3413
Jul 15 13:18:32 MMN-0 pgpool[32614]: [4-1] 2016-07-15 13:18:32: pid 32614: DEBUG: initializing pool configuration
Jul 15 13:18:32 MMN-0 pgpool[32614]: [4-2] 2016-07-15 13:18:32: pid 32614: DETAIL: backend 2 weight: 536870911.750000 flag: 0000 backend_status: 1
Jul 15 13:18:32 MMN-0 pgpool[32614]: [4-3] 2016-07-15 13:18:32: pid 32614: LOCATION: pool_config.l:3413
Jul 15 13:18:32 MMN-0 pgpool[32614]: [5-1] 2016-07-15 13:18:32: pid 32614: DEBUG: initializing pool configuration
Jul 15 13:18:32 MMN-0 pgpool[32614]: [5-2] 2016-07-15 13:18:32: pid 32614: DETAIL: backend 3 weight: 536870911.750000 flag: 0000 backend_status: 1
Jul 15 13:18:32 MMN-0 pgpool[32614]: [5-3] 2016-07-15 13:18:32: pid 32614: LOCATION: pool_config.l:3413
Jul 15 13:18:32 MMN-0 pgpool[32614]: [6-1] 2016-07-15 13:18:32: pid 32614: DEBUG: shmem_exit(-1): 2 callbacks to make
Jul 15 13:18:32 MMN-0 pgpool[32614]: [6-2] 2016-07-15 13:18:32: pid 32614: LOCATION: elog.c:2563
Jul 15 13:18:32 MMN-0 pgpool[32614]: [7-1] 2016-07-15 13:18:32: pid 32614: DEBUG: proc_exit(-1): 0 callbacks to make
Jul 15 13:18:32 MMN-0 pgpool[32614]: [7-2] 2016-07-15 13:18:32: pid 32614: LOCATION: elog.c:2535
Jul 15 13:18:32 MMN-0 pgpool[32615]: [6-1] 2016-07-15 13:18:32: pid 32615: LOG: reading status file: 2 th backend is set to down status
Jul 15 13:18:32 MMN-0 pgpool[32615]: [6-2] 2016-07-15 13:18:32: pid 32615: LOCATION: pgpool_main.c:3037
Jul 15 13:18:32 MMN-0 pgpool[32615]: [7-1] 2016-07-15 13:18:32: pid 32615: LOG: reading status file: 3 th backend is set to down status
Jul 15 13:18:32 MMN-0 pgpool[32615]: [7-2] 2016-07-15 13:18:32: pid 32615: LOCATION: pgpool_main.c:3037
Jul 15 13:18:32 MMN-0 pgpool[32615]: [8-1] 2016-07-15 13:18:32: pid 32615: DEBUG: pool_coninfo_size: num_init_children (32) * max_pool (4) * MAX_NUM_BACKENDS (128) * sizeof(ConnectionInfo) (136) = 2228224 bytes requested for shared memory
Jul 15 13:18:32 MMN-0 pgpool[32615]: [8-2] 2016-07-15 13:18:32: pid 32615: LOCATION: pool_process_context.c:109
Jul 15 13:18:32 MMN-0 pgpool[32615]: [9-1] 2016-07-15 13:18:32: pid 32615: DEBUG: ProcessInfo: num_init_children (32) * sizeof(ProcessInfo) (32) = 1024 bytes requested for shared memory
Jul 15 13:18:32 MMN-0 pgpool[32615]: [9-2] 2016-07-15 13:18:32: pid 32615: LOCATION: pgpool_main.c:2822
Jul 15 13:18:32 MMN-0 pgpool[32615]: [10-1] 2016-07-15 13:18:32: pid 32615: DEBUG: Request info are: sizeof(POOL_REQUEST_INFO) 5224 bytes requested for shared memory
Jul 15 13:18:32 MMN-0 pgpool[32615]: [10-2] 2016-07-15 13:18:32: pid 32615: LOCATION: pgpool_main.c:2837
Jul 15 13:18:32 MMN-0 pgpool[32615]: [11-1] 2016-07-15 13:18:32: pid 32615: DEBUG: Recovery management area: sizeof(int) 4 bytes requested for shared memory
Jul 15 13:18:32 MMN-0 pgpool[32615]: [11-2] 2016-07-15 13:18:32: pid 32615: LOCATION: pgpool_main.c:2860
Jul 15 13:18:32 MMN-0 pgpool[32615]: [12-1] 2016-07-15 13:18:32: pid 32615: LOG: Setting up socket for 0.0.0.0:9999
Jul 15 13:18:32 MMN-0 pgpool[32615]: [12-2] 2016-07-15 13:18:32: pid 32615: LOCATION: pgpool_main.c:797
Jul 15 13:18:32 MMN-0 pgpool[32615]: [13-1] 2016-07-15 13:18:32: pid 32615: LOG: Setting up socket for :::9999
Jul 15 13:18:32 MMN-0 pgpool[32615]: [13-2] 2016-07-15 13:18:32: pid 32615: LOCATION: pgpool_main.c:797
Jul 15 13:18:32 MMN-0 pgpool[32617]: [14-1] 2016-07-15 13:18:32: pid 32617: DEBUG: I am Pgpool Child process with pid: 32617
Jul 15 13:18:32 MMN-0 pgpool[32617]: [14-2] 2016-07-15 13:18:32: pid 32617: LOCATION: child.c:134
Jul 15 13:18:32 MMN-0 pgpool[32617]: [15-1] 2016-07-15 13:18:32: pid 32617: DEBUG: initializing backend status
Jul 15 13:18:32 MMN-0 pgpool[32617]: [15-2] 2016-07-15 13:18:32: pid 32617: LOCATION: child.c:1759
Jul 15 13:18:32 MMN-0 pgpool[32618]: [14-1] 2016-07-15 13:18:32: pid 32618: DEBUG: I am Pgpool Child process with pid: 32618
Jul 15 13:18:32 MMN-0 pgpool[32618]: [14-2] 2016-07-15 13:18:32: pid 32618: LOCATION: child.c:134
Jul 15 13:18:32 MMN-0 pgpool[32618]: [15-1] 2016-07-15 13:18:32: pid 32618: DEBUG: initializing backend status
Jul 15 13:18:32 MMN-0 pgpool[32618]: [15-2] 2016-07-15 13:18:32: pid 32618: LOCATION: child.c:1759
Jul 15 13:18:32 MMN-0 pgpool[32619]: [14-1] 2016-07-15 13:18:32: pid 32619: DEBUG: I am Pgpool Child process with pid: 32619
Jul 15 13:18:32 MMN-0 pgpool[32619]: [14-2] 2016-07-15 13:18:32: pid 32619: LOCATION: child.c:134
Jul 15 13:18:32 MMN-0 pgpool[32619]: [15-1] 2016-07-15 13:18:32: pid 32619: DEBUG: initializing backend status
Jul 15 13:18:32 MMN-0 pgpool[32619]: [15-2] 2016-07-15 13:18:32: pid 32619: LOCATION: child.c:1759
Jul 15 13:18:32 MMN-0 pgpool[32620]: [14-1] 2016-07-15 13:18:32: pid 32620: DEBUG: I am Pgpool Child process with pid: 32620
Jul 15 13:18:32 MMN-0 pgpool[32620]: [14-2] 2016-07-15 13:18:32: pid 32620: LOCATION: child.c:134
Jul 15 13:18:32 MMN-0 pgpool[32620]: [15-1] 2016-07-15 13:18:32: pid 32620: DEBUG: initializing backend status
Jul 15 13:18:32 MMN-0 pgpool[32620]: [15-2] 2016-07-15 13:18:32: pid 32620: LOCATION: child.c:1759
Jul 15 13:18:32 MMN-0 pgpool[32621]: [14-1] 2016-07-15 13:18:32: pid 32621: DEBUG: I am Pgpool Child process with pid: 32621
Jul 15 13:18:32 MMN-0 pgpool[32621]: [14-2] 2016-07-15 13:18:32: pid 32621: LOCATION: child.c:134
Jul 15 13:18:32 MMN-0 pgpool[32621]: [15-1] 2016-07-15 13:18:32: pid 32621: DEBUG: initializing backend status
Jul 15 13:18:32 MMN-0 pgpool[32621]: [15-2] 2016-07-15 13:18:32: pid 32621: LOCATION: child.c:1759
Jul 15 13:18:32 MMN-0 pgpool[32622]: [14-1] 2016-07-15 13:18:32: pid 32622: DEBUG: I am Pgpool Child process with pid: 32622
Jul 15 13:18:32 MMN-0 pgpool[32622]: [14-2] 2016-07-15 13:18:32: pid 32622: LOCATION: child.c:134
Jul 15 13:18:32 MMN-0 pgpool[32622]: [15-1] 2016-07-15 13:18:32: pid 32622: DEBUG: initializing backend status
Jul 15 13:18:32 MMN-0 pgpool[32622]: [15-2] 2016-07-15 13:18:32: pid 32622: LOCATION: child.c:1759
Jul 15 13:18:32 MMN-0 pgpool[32624]: [14-1] 2016-07-15 13:18:32: pid 32624: DEBUG: I am Pgpool Child process with pid: 32624
Jul 15 13:18:32 MMN-0 pgpool[32624]: [14-2] 2016-07-15 13:18:32: pid 32624: LOCATION: child.c:134
Jul 15 13:18:32 MMN-0 pgpool[32624]: [15-1] 2016-07-15 13:18:32: pid 32624: DEBUG: initializing backend status
Jul 15 13:18:32 MMN-0 pgpool[32624]: [15-2] 2016-07-15 13:18:32: pid 32624: LOCATION: child.c:1759
Jul 15 13:18:32 MMN-0 pgpool[32625]: [14-1] 2016-07-15 13:18:32: pid 32625: DEBUG: I am Pgpool Child process with pid: 32625
Jul 15 13:18:32 MMN-0 pgpool[32625]: [14-2] 2016-07-15 13:18:32: pid 32625: LOCATION: child.c:134
Jul 15 13:18:32 MMN-0 pgpool[32625]: [15-1] 2016-07-15 13:18:32: pid 32625: DEBUG: initializing backend status
Jul 15 13:18:32 MMN-0 pgpool[32626]: [14-1] 2016-07-15 13:18:32: pid 32626: DEBUG: I am Pgpool Child process with pid: 32626
Jul 15 13:18:32 MMN-0 pgpool[32626]: [14-2] 2016-07-15 13:18:32: pid 32626: LOCATION: child.c:134
Jul 15 13:18:32 MMN-0 pgpool[32628]: [14-1] 2016-07-15 13:18:32: pid 32628: DEBUG: I am Pgpool Child process with pid: 32628
Jul 15 13:18:32 MMN-0 pgpool[32628]: [14-2] 2016-07-15 13:18:32: pid 32628: LOCATION: child.c:134
Jul 15 13:18:32 MMN-0 pgpool[32626]: [15-1] 2016-07-15 13:18:32: pid 32626: DEBUG: initializing backend status
Jul 15 13:18:32 MMN-0 pgpool[32626]: [15-2] 2016-07-15 13:18:32: pid 32626: LOCATION: child.c:1759
Jul 15 13:18:32 MMN-0 pgpool[32628]: [15-1] 2016-07-15 13:18:32: pid 32628: DEBUG: initializing backend status
Jul 15 13:18:32 MMN-0 pgpool[32628]: [15-2] 2016-07-15 13:18:32: pid 32628: LOCATION: child.c:1759
Jul 15 13:18:32 MMN-0 pgpool[32625]: [15-2] 2016-07-15 13:18:32: pid 32625: LOCATION: child.c:1759
Jul 15 13:18:32 MMN-0 pgpool[32623]: [14-1] 2016-07-15 13:18:32: pid 32623: DEBUG: I am Pgpool Child process with pid: 32623
Jul 15 13:18:32 MMN-0 pgpool[32623]: [14-2] 2016-07-15 13:18:32: pid 32623: LOCATION: child.c:134
Jul 15 13:18:32 MMN-0 pgpool[32623]: [15-1] 2016-07-15 13:18:32: pid 32623: DEBUG: initializing backend status
Jul 15 13:18:32 MMN-0 pgpool[32623]: [15-2] 2016-07-15 13:18:32: pid 32623: LOCATION: child.c:1759
Jul 15 13:18:32 MMN-0 pgpool[32631]: [14-1] 2016-07-15 13:18:32: pid 32631: DEBUG: I am Pgpool Child process with pid: 32631
Jul 15 13:18:32 MMN-0 pgpool[32631]: [14-2] 2016-07-15 13:18:32: pid 32631: LOCATION: child.c:134
Jul 15 13:18:32 MMN-0 pgpool[32627]: [14-1] 2016-07-15 13:18:32: pid 32627: DEBUG: I am Pgpool Child process with pid: 32627
Jul 15 13:18:32 MMN-0 pgpool[32627]: [14-2] 2016-07-15 13:18:32: pid 32627: LOCATION: child.c:134
Jul 15 13:18:32 MMN-0 pgpool[32631]: [15-1] 2016-07-15 13:18:32: pid 32631: DEBUG: initializing backend status
Jul 15 13:18:32 MMN-0 pgpool[32631]: [15-2] 2016-07-15 13:18:32: pid 32631: LOCATION: child.c:1759
Jul 15 13:18:32 MMN-0 pgpool[32627]: [15-1] 2016-07-15 13:18:32: pid 32627: DEBUG: initializing backend status
Jul 15 13:18:32 MMN-0 pgpool[32627]: [15-2] 2016-07-15 13:18:32: pid 32627: LOCATION: child.c:1759
Jul 15 13:18:32 MMN-0 pgpool[32634]: [14-1] 2016-07-15 13:18:32: pid 32634: DEBUG: I am Pgpool Child process with pid: 32634
Jul 15 13:18:32 MMN-0 pgpool[32634]: [14-2] 2016-07-15 13:18:32: pid 32634: LOCATION: child.c:134
Jul 15 13:18:32 MMN-0 pgpool[32629]: [14-1] 2016-07-15 13:18:32: pid 32629: DEBUG: I am Pgpool Child process with pid: 32629
Jul 15 13:18:32 MMN-0 pgpool[32629]: [14-2] 2016-07-15 13:18:32: pid 32629: LOCATION: child.c:134
Jul 15 13:18:32 MMN-0 pgpool[32634]: [15-1] 2016-07-15 13:18:32: pid 32634: DEBUG: initializing backend status
Jul 15 13:18:32 MMN-0 pgpool[32634]: [15-2] 2016-07-15 13:18:32: pid 32634: LOCATION: child.c:1759
Jul 15 13:18:32 MMN-0 pgpool[32629]: [15-1] 2016-07-15 13:18:32: pid 32629: DEBUG: initializing backend status
Jul 15 13:18:32 MMN-0 pgpool[32629]: [15-2] 2016-07-15 13:18:32: pid 32629: LOCATION: child.c:1759
Jul 15 13:18:32 MMN-0 pgpool[32637]: [14-1] 2016-07-15 13:18:32: pid 32637: DEBUG: I am Pgpool Child process with pid: 32637
Jul 15 13:18:32 MMN-0 pgpool[32637]: [14-2] 2016-07-15 13:18:32: pid 32637: LOCATION: child.c:134
Jul 15 13:18:32 MMN-0 pgpool[32630]: [14-1] 2016-07-15 13:18:32: pid 32630: DEBUG: I am Pgpool Child process with pid: 32630
Jul 15 13:18:32 MMN-0 pgpool[32630]: [14-2] 2016-07-15 13:18:32: pid 32630: LOCATION: child.c:134
Jul 15 13:18:32 MMN-0 pgpool[32637]: [15-1] 2016-07-15 13:18:32: pid 32637: DEBUG: initializing backend status
Jul 15 13:18:32 MMN-0 pgpool[32637]: [15-2] 2016-07-15 13:18:32: pid 32637: LOCATION: child.c:1759
Jul 15 13:18:32 MMN-0 pgpool[32630]: [15-1] 2016-07-15 13:18:32: pid 32630: DEBUG: initializing backend status
Jul 15 13:18:32 MMN-0 pgpool[32630]: [15-2] 2016-07-15 13:18:32: pid 32630: LOCATION: child.c:1759
Jul 15 13:18:32 MMN-0 pgpool[32640]: [14-1] 2016-07-15 13:18:32: pid 32640: DEBUG: I am Pgpool Child process with pid: 32640
Jul 15 13:18:32 MMN-0 pgpool[32640]: [14-2] 2016-07-15 13:18:32: pid 32640: LOCATION: child.c:134
Jul 15 13:18:32 MMN-0 pgpool[32640]: [15-1] 2016-07-15 13:18:32: pid 32640: DEBUG: initializing backend status
Jul 15 13:18:32 MMN-0 pgpool[32640]: [15-2] 2016-07-15 13:18:32: pid 32640: LOCATION: child.c:1759
Jul 15 13:18:32 MMN-0 pgpool[32641]: [14-1] 2016-07-15 13:18:32: pid 32641: DEBUG: I am Pgpool Child process with pid: 32641
Jul 15 13:18:32 MMN-0 pgpool[32641]: [14-2] 2016-07-15 13:18:32: pid 32641: LOCATION: child.c:134
Jul 15 13:18:32 MMN-0 pgpool[32641]: [15-1] 2016-07-15 13:18:32: pid 32641: DEBUG: initializing backend status
Jul 15 13:18:32 MMN-0 pgpool[32641]: [15-2] 2016-07-15 13:18:32: pid 32641: LOCATION: child.c:1759
Jul 15 13:18:32 MMN-0 pgpool[32643]: [14-1] 2016-07-15 13:18:32: pid 32643: DEBUG: I am Pgpool Child process with pid: 32643
Jul 15 13:18:32 MMN-0 pgpool[32643]: [14-2] 2016-07-15 13:18:32: pid 32643: LOCATION: child.c:134
Jul 15 13:18:32 MMN-0 pgpool[32643]: [15-1] 2016-07-15 13:18:32: pid 32643: DEBUG: initializing backend status
Jul 15 13:18:32 MMN-0 pgpool[32643]: [15-2] 2016-07-15 13:18:32: pid 32643: LOCATION: child.c:1759
Jul 15 13:18:32 MMN-0 pgpool[32642]: [14-1] 2016-07-15 13:18:32: pid 32642: DEBUG: I am Pgpool Child process with pid: 32642
Jul 15 13:18:32 MMN-0 pgpool[32642]: [14-2] 2016-07-15 13:18:32: pid 32642: LOCATION: child.c:134
Jul 15 13:18:32 MMN-0 pgpool[32642]: [15-1] 2016-07-15 13:18:32: pid 32642: DEBUG: initializing backend status
Jul 15 13:18:32 MMN-0 pgpool[32642]: [15-2] 2016-07-15 13:18:32: pid 32642: LOCATION: child.c:1759
Jul 15 13:18:32 MMN-0 pgpool[32646]: [14-1] 2016-07-15 13:18:32: pid 32646: DEBUG: I am Pgpool Child process with pid: 32646
Jul 15 13:18:32 MMN-0 pgpool[32646]: [14-2] 2016-07-15 13:18:32: pid 32646: LOCATION: child.c:134
Jul 15 13:18:32 MMN-0 pgpool[32644]: [14-1] 2016-07-15 13:18:32: pid 32644: DEBUG: I am Pgpool Child process with pid: 32644
Jul 15 13:18:32 MMN-0 pgpool[32644]: [14-2] 2016-07-15 13:18:32: pid 32644: LOCATION: child.c:134
Jul 15 13:18:32 MMN-0 pgpool[32646]: [15-1] 2016-07-15 13:18:32: pid 32646: DEBUG: initializing backend status
Jul 15 13:18:32 MMN-0 pgpool[32646]: [15-2] 2016-07-15 13:18:32: pid 32646: LOCATION: child.c:1759
Jul 15 13:18:32 MMN-0 pgpool[32644]: [15-1] 2016-07-15 13:18:32: pid 32644: DEBUG: initializing backend status
Jul 15 13:18:32 MMN-0 pgpool[32644]: [15-2] 2016-07-15 13:18:32: pid 32644: LOCATION: child.c:1759
Jul 15 13:18:32 MMN-0 pgpool[32639]: [14-1] 2016-07-15 13:18:32: pid 32639: DEBUG: I am Pgpool Child process with pid: 32639
Jul 15 13:18:32 MMN-0 pgpool[32639]: [14-2] 2016-07-15 13:18:32: pid 32639: LOCATION: child.c:134
Jul 15 13:18:32 MMN-0 pgpool[32639]: [15-1] 2016-07-15 13:18:32: pid 32639: DEBUG: initializing backend status
Jul 15 13:18:32 MMN-0 pgpool[32638]: [14-1] 2016-07-15 13:18:32: pid 32638: DEBUG: I am Pgpool Child process with pid: 32638
Jul 15 13:18:32 MMN-0 pgpool[32639]: [15-2] 2016-07-15 13:18:32: pid 32639: LOCATION: child.c:1759
Jul 15 13:18:32 MMN-0 pgpool[32638]: [14-2] 2016-07-15 13:18:32: pid 32638: LOCATION: child.c:134
Jul 15 13:18:32 MMN-0 pgpool[32638]: [15-1] 2016-07-15 13:18:32: pid 32638: DEBUG: initializing backend status
Jul 15 13:18:32 MMN-0 pgpool[32638]: [15-2] 2016-07-15 13:18:32: pid 32638: LOCATION: child.c:1759
Jul 15 13:18:32 MMN-0 pgpool[32615]: [14-1] 2016-07-15 13:18:32: pid 32615: LOG: pgpool-II successfully started. version 3.5.2 (ekieboshi)
Jul 15 13:18:32 MMN-0 pgpool[32615]: [14-2] 2016-07-15 13:18:32: pid 32615: LOCATION: pgpool_main.c:370
Jul 15 13:18:32 MMN-0 pgpool[32615]: [15-1] 2016-07-15 13:18:32: pid 32615: DEBUG: find_primary_node: not in streaming replication mode
Jul 15 13:18:32 MMN-0 pgpool[32615]: [15-2] 2016-07-15 13:18:32: pid 32615: LOCATION: pgpool_main.c:2683
Jul 15 13:18:32 MMN-0 pgpool[32645]: [14-1] 2016-07-15 13:18:32: pid 32645: DEBUG: I am Pgpool Child process with pid: 32645
Jul 15 13:18:32 MMN-0 pgpool[32645]: [14-2] 2016-07-15 13:18:32: pid 32645: LOCATION: child.c:134
Jul 15 13:18:32 MMN-0 pgpool[32650]: [14-1] 2016-07-15 13:18:32: pid 32650: DEBUG: I am 32650
Jul 15 13:18:32 MMN-0 pgpool[32650]: [14-2] 2016-07-15 13:18:32: pid 32650: LOCATION: pool_worker_child.c:100
Jul 15 13:18:32 MMN-0 pgpool[32645]: [15-1] 2016-07-15 13:18:32: pid 32645: DEBUG: initializing backend status
Jul 15 13:18:32 MMN-0 pgpool[32645]: [15-2] 2016-07-15 13:18:32: pid 32645: LOCATION: child.c:1759
Jul 15 13:18:32 MMN-0 pgpool[32650]: [15-1] 2016-07-15 13:18:32: pid 32650: DEBUG: initializing backend status
Jul 15 13:18:32 MMN-0 pgpool[32650]: [15-2] 2016-07-15 13:18:32: pid 32650: LOCATION: child.c:1759
Jul 15 13:18:32 MMN-0 pgpool[32636]: [14-1] 2016-07-15 13:18:32: pid 32636: DEBUG: I am Pgpool Child process with pid: 32636
Jul 15 13:18:32 MMN-0 pgpool[32636]: [14-2] 2016-07-15 13:18:32: pid 32636: LOCATION: child.c:134
Jul 15 13:18:32 MMN-0 pgpool[32636]: [15-1] 2016-07-15 13:18:32: pid 32636: DEBUG: initializing backend status
Jul 15 13:18:32 MMN-0 pgpool[32636]: [15-2] 2016-07-15 13:18:32: pid 32636: LOCATION: child.c:1759
Jul 15 13:18:32 MMN-0 pgpool[32647]: [14-1] 2016-07-15 13:18:32: pid 32647: DEBUG: I am Pgpool Child process with pid: 32647
Jul 15 13:18:32 MMN-0 pgpool[32647]: [14-2] 2016-07-15 13:18:32: pid 32647: LOCATION: child.c:134
Jul 15 13:18:32 MMN-0 pgpool[32647]: [15-1] 2016-07-15 13:18:32: pid 32647: DEBUG: initializing backend status
Jul 15 13:18:32 MMN-0 pgpool[32647]: [15-2] 2016-07-15 13:18:32: pid 32647: LOCATION: child.c:1759
Jul 15 13:18:32 MMN-0 pgpool[32635]: [14-1] 2016-07-15 13:18:32: pid 32635: DEBUG: I am Pgpool Child process with pid: 32635
Jul 15 13:18:32 MMN-0 pgpool[32635]: [14-2] 2016-07-15 13:18:32: pid 32635: LOCATION: child.c:134
Jul 15 13:18:32 MMN-0 pgpool[32635]: [15-1] 2016-07-15 13:18:32: pid 32635: DEBUG: initializing backend status
Jul 15 13:18:32 MMN-0 pgpool[32635]: [15-2] 2016-07-15 13:18:32: pid 32635: LOCATION: child.c:1759
Jul 15 13:18:32 MMN-0 pgpool[32648]: [14-1] 2016-07-15 13:18:32: pid 32648: DEBUG: I am Pgpool Child process with pid: 32648
Jul 15 13:18:32 MMN-0 pgpool[32648]: [14-2] 2016-07-15 13:18:32: pid 32648: LOCATION: child.c:134
Jul 15 13:18:32 MMN-0 pgpool[32633]: [14-1] 2016-07-15 13:18:32: pid 32633: DEBUG: I am Pgpool Child process with pid: 32633
Jul 15 13:18:32 MMN-0 pgpool[32633]: [14-2] 2016-07-15 13:18:32: pid 32633: LOCATION: child.c:134
Jul 15 13:18:32 MMN-0 pgpool[32649]: [14-1] 2016-07-15 13:18:32: pid 32649: DEBUG: I am PCP child with pid:32649
Jul 15 13:18:32 MMN-0 pgpool[32649]: [14-2] 2016-07-15 13:18:32: pid 32649: LOCATION: pcp_child.c:105
Jul 15 13:18:32 MMN-0 pgpool[32648]: [15-1] 2016-07-15 13:18:32: pid 32648: DEBUG: initializing backend status
Jul 15 13:18:32 MMN-0 pgpool[32648]: [15-2] 2016-07-15 13:18:32: pid 32648: LOCATION: child.c:1759
Jul 15 13:18:32 MMN-0 pgpool[32633]: [15-1] 2016-07-15 13:18:32: pid 32633: DEBUG: initializing backend status
Jul 15 13:18:32 MMN-0 pgpool[32633]: [15-2] 2016-07-15 13:18:32: pid 32633: LOCATION: child.c:1759
Jul 15 13:18:32 MMN-0 pgpool[32632]: [14-1] 2016-07-15 13:18:32: pid 32632: DEBUG: I am Pgpool Child process with pid: 32632
Jul 15 13:18:32 MMN-0 pgpool[32632]: [14-2] 2016-07-15 13:18:32: pid 32632: LOCATION: child.c:134
Jul 15 13:18:32 MMN-0 pgpool[32632]: [15-1] 2016-07-15 13:18:32: pid 32632: DEBUG: initializing backend status
Jul 15 13:18:32 MMN-0 pgpool[32632]: [15-2] 2016-07-15 13:18:32: pid 32632: LOCATION: child.c:1759
Jul 15 13:18:38 MMN-0 pgpool[32639]: [16-1] 2016-07-15 13:18:38: pid 32639: DEBUG: I am 32639 accept fd 8
Jul 15 13:18:38 MMN-0 pgpool[32639]: [16-2] 2016-07-15 13:18:38: pid 32639: LOCATION: child.c:2097
Jul 15 13:18:38 MMN-0 pgpool[32639]: [17-1] 2016-07-15 13:18:38: pid 32639: DEBUG: reading startup packet
Jul 15 13:18:38 MMN-0 pgpool[32639]: [17-2] 2016-07-15 13:18:38: pid 32639: DETAIL: Protocol Major: 3 Minor: 0 database: ycsb user: _nokfssystestpostgres
Jul 15 13:18:38 MMN-0 pgpool[32639]: [17-3] 2016-07-15 13:18:38: pid 32639: LOCATION: child.c:614
Jul 15 13:18:38 MMN-0 pgpool[32639]: [18-1] 2016-07-15 13:18:38: pid 32639: DEBUG: creating new connection to backend
Jul 15 13:18:38 MMN-0 pgpool[32639]: [18-2] 2016-07-15 13:18:38: pid 32639: DETAIL: connecting 0 backend
Jul 15 13:18:38 MMN-0 pgpool[32639]: [18-3] 2016-07-15 13:18:38: pid 32639: LOCATION: pool_connection_pool.c:830
Jul 15 13:18:38 MMN-0 pgpool[32639]: [19-1] 2016-07-15 13:18:38: pid 32639: DEBUG: creating new connection to backend
Jul 15 13:18:38 MMN-0 pgpool[32639]: [19-2] 2016-07-15 13:18:38: pid 32639: DETAIL: connecting 1 backend
Jul 15 13:18:38 MMN-0 pgpool[32639]: [19-3] 2016-07-15 13:18:38: pid 32639: LOCATION: pool_connection_pool.c:830
Jul 15 13:18:38 MMN-0 pgpool[32639]: [20-1] 2016-07-15 13:18:38: pid 32639: DEBUG: creating new connection to backend
Jul 15 13:18:38 MMN-0 pgpool[32639]: [20-2] 2016-07-15 13:18:38: pid 32639: DETAIL: connecting 2 backend
Jul 15 13:18:38 MMN-0 pgpool[32639]: [20-3] 2016-07-15 13:18:38: pid 32639: LOCATION: pool_connection_pool.c:830
Jul 15 13:18:38 MMN-0 pgpool[32639]: [21-1] 2016-07-15 13:18:38: pid 32639: DEBUG: creating new connection to backend
Jul 15 13:18:38 MMN-0 pgpool[32639]: [21-2] 2016-07-15 13:18:38: pid 32639: DETAIL: skipping backend slot 2 because backend_status = 3
Jul 15 13:18:38 MMN-0 pgpool[32639]: [21-3] 2016-07-15 13:18:38: pid 32639: LOCATION: pool_connection_pool.c:837
Jul 15 13:18:38 MMN-0 pgpool[32639]: [22-1] 2016-07-15 13:18:38: pid 32639: DEBUG: creating new connection to backend
Jul 15 13:18:38 MMN-0 pgpool[32639]: [22-2] 2016-07-15 13:18:38: pid 32639: DETAIL: connecting 3 backend
Jul 15 13:18:38 MMN-0 pgpool[32639]: [22-3] 2016-07-15 13:18:38: pid 32639: LOCATION: pool_connection_pool.c:830
Jul 15 13:18:38 MMN-0 pgpool[32639]: [23-1] 2016-07-15 13:18:38: pid 32639: DEBUG: creating new connection to backend
Jul 15 13:18:38 MMN-0 pgpool[32639]: [23-2] 2016-07-15 13:18:38: pid 32639: DETAIL: skipping backend slot 3 because backend_status = 3
Jul 15 13:18:38 MMN-0 pgpool[32639]: [23-3] 2016-07-15 13:18:38: pid 32639: LOCATION: pool_connection_pool.c:837
Jul 15 13:18:38 MMN-0 pgpool[32639]: [24-1] 2016-07-15 13:18:38: pid 32639: DEBUG: SSL is requested but SSL support is not available
Jul 15 13:18:38 MMN-0 pgpool[32639]: [24-2] 2016-07-15 13:18:38: pid 32639: LOCATION: pool_ssl.c:333
Jul 15 13:18:38 MMN-0 pgpool[32639]: [25-1] 2016-07-15 13:18:38: pid 32639: DEBUG: SSL is requested but SSL support is not available
Jul 15 13:18:38 MMN-0 pgpool[32639]: [25-2] 2016-07-15 13:18:38: pid 32639: LOCATION: pool_ssl.c:333
Jul 15 13:18:38 MMN-0 pgpool[32639]: [26-1] 2016-07-15 13:18:38: pid 32639: DEBUG: pool_read: read 341 bytes from backend 0
Jul 15 13:18:38 MMN-0 pgpool[32639]: [26-2] 2016-07-15 13:18:38: pid 32639: LOCATION: pool_stream.c:190
Jul 15 13:18:38 MMN-0 pgpool[32639]: [27-1] 2016-07-15 13:18:38: pid 32639: DEBUG: pool_read: read 341 bytes from backend 1
Jul 15 13:18:38 MMN-0 pgpool[32639]: [27-2] 2016-07-15 13:18:38: pid 32639: LOCATION: pool_stream.c:190
Jul 15 13:18:38 MMN-0 pgpool[32639]: [28-1] 2016-07-15 13:18:38: pid 32639: DEBUG: reading message length
Jul 15 13:18:38 MMN-0 pgpool[32639]: [28-2] 2016-07-15 13:18:38: pid 32639: DETAIL: slot: 0 length: 8
Jul 15 13:18:38 MMN-0 pgpool[32639]: [28-3] 2016-07-15 13:18:38: pid 32639: LOCATION: pool_auth.c:1107
Jul 15 13:18:38 MMN-0 pgpool[32639]: [29-1] 2016-07-15 13:18:38: pid 32639: DEBUG: reading message length
Jul 15 13:18:38 MMN-0 pgpool[32639]: [29-2] 2016-07-15 13:18:38: pid 32639: DETAIL: slot: 1 length: 8
Jul 15 13:18:38 MMN-0 pgpool[32639]: [29-3] 2016-07-15 13:18:38: pid 32639: LOCATION: pool_auth.c:1126
Jul 15 13:18:38 MMN-0 pgpool[32639]: [30-1] 2016-07-15 13:18:38: pid 32639: DEBUG: authentication backend
Jul 15 13:18:38 MMN-0 pgpool[32639]: [30-2] 2016-07-15 13:18:38: pid 32639: DETAIL: auth kind:0
Jul 15 13:18:38 MMN-0 pgpool[32639]: [30-3] 2016-07-15 13:18:38: pid 32639: LOCATION: pool_auth.c:142
Jul 15 13:18:38 MMN-0 pgpool[32639]: [31-1] 2016-07-15 13:18:38: pid 32639: DEBUG: reading message length
Jul 15 13:18:38 MMN-0 pgpool[32639]: [31-2] 2016-07-15 13:18:38: pid 32639: DETAIL: master slot: 0 length: 22
Jul 15 13:18:38 MMN-0 pgpool[32639]: [31-3] 2016-07-15 13:18:38: pid 32639: LOCATION: pool_auth.c:1161
Jul 15 13:18:38 MMN-0 pgpool[32639]: [32-1] 2016-07-15 13:18:38: pid 32639: DEBUG: reading message length
Jul 15 13:18:38 MMN-0 pgpool[32639]: [32-2] 2016-07-15 13:18:38: pid 32639: DETAIL: master slot: 1 length: 22
Jul 15 13:18:38 MMN-0 pgpool[32639]: [32-3] 2016-07-15 13:18:38: pid 32639: LOCATION: pool_auth.c:1172
Jul 15 13:18:38 MMN-0 pgpool[32639]: [33-1] 2016-07-15 13:18:38: pid 32639: DEBUG: process parameter status
Jul 15 13:18:38 MMN-0 pgpool[32639]: [33-2] 2016-07-15 13:18:38: pid 32639: DETAIL: backend:0 name:"application_name" value:""
Jul 15 13:18:38 MMN-0 pgpool[32639]: [33-3] 2016-07-15 13:18:38: pid 32639: LOCATION: pool_process_query.c:921
Jul 15 13:18:38 MMN-0 pgpool[32639]: [34-1] 2016-07-15 13:18:38: pid 32639: DEBUG: process parameter status
Jul 15 13:18:38 MMN-0 pgpool[32639]: [34-2] 2016-07-15 13:18:38: pid 32639: DETAIL: backend:1 name:"application_name" value:""
Jul 15 13:18:38 MMN-0 pgpool[32639]: [34-3] 2016-07-15 13:18:38: pid 32639: LOCATION: pool_process_query.c:921
Jul 15 13:18:38 MMN-0 pgpool[32639]: [35-1] 2016-07-15 13:18:38: pid 32639: DEBUG: reading message length
Jul 15 13:18:38 MMN-0 pgpool[32639]: [35-2] 2016-07-15 13:18:38: pid 32639: DETAIL: master slot: 0 length: 25
Jul 15 13:18:38 MMN-0 pgpool[32639]: [35-3] 2016-07-15 13:18:38: pid 32639: LOCATION: pool_auth.c:1161
Jul 15 13:18:38 MMN-0 pgpool[32639]: [36-1] 2016-07-15 13:18:38: pid 32639: DEBUG: reading message length
Jul 15 13:18:38 MMN-0 pgpool[32639]: [36-2] 2016-07-15 13:18:38: pid 32639: DETAIL: master slot: 1 length: 25
Jul 15 13:18:38 MMN-0 pgpool[32639]: [36-3] 2016-07-15 13:18:38: pid 32639: LOCATION: pool_auth.c:1172
Jul 15 13:18:38 MMN-0 pgpool[32639]: [37-1] 2016-07-15 13:18:38: pid 32639: DEBUG: process parameter status
Jul 15 13:18:38 MMN-0 pgpool[32639]: [37-2] 2016-07-15 13:18:38: pid 32639: DETAIL: backend:0 name:"client_encoding" value:"UTF8"
Jul 15 13:18:38 MMN-0 pgpool[32639]: [37-3] 2016-07-15 13:18:38: pid 32639: LOCATION: pool_process_query.c:921
Jul 15 13:18:38 MMN-0 pgpool[32639]: [38-1] 2016-07-15 13:18:38: pid 32639: DEBUG: process parameter status
Jul 15 13:18:38 MMN-0 pgpool[32639]: [38-2] 2016-07-15 13:18:38: pid 32639: DETAIL: backend:1 name:"client_encoding" value:"UTF8"
Jul 15 13:18:38 MMN-0 pgpool[32639]: [38-3] 2016-07-15 13:18:38: pid 32639: LOCATION: pool_process_query.c:921
Jul 15 13:18:38 MMN-0 pgpool[32639]: [39-1] 2016-07-15 13:18:38: pid 32639: DEBUG: reading message length
Jul 15 13:18:38 MMN-0 pgpool[32639]: [39-2] 2016-07-15 13:18:38: pid 32639: DETAIL: master slot: 0 length: 23
Jul 15 13:18:38 MMN-0 pgpool[32639]: [39-3] 2016-07-15 13:18:38: pid 32639: LOCATION: pool_auth.c:1161
Jul 15 13:18:38 MMN-0 pgpool[32639]: [40-1] 2016-07-15 13:18:38: pid 32639: DEBUG: reading message length
Jul 15 13:18:38 MMN-0 pgpool[32639]: [40-2] 2016-07-15 13:18:38: pid 32639: DETAIL: master slot: 1 length: 23
Jul 15 13:18:38 MMN-0 pgpool[32639]: [40-3] 2016-07-15 13:18:38: pid 32639: LOCATION: pool_auth.c:1172
Jul 15 13:18:38 MMN-0 pgpool[32639]: [41-1] 2016-07-15 13:18:38: pid 32639: DEBUG: process parameter status
Jul 15 13:18:38 MMN-0 pgpool[32639]: [41-2] 2016-07-15 13:18:38: pid 32639: DETAIL: backend:0 name:"DateStyle" value:"ISO, MDY"
Jul 15 13:18:38 MMN-0 pgpool[32639]: [41-3] 2016-07-15 13:18:38: pid 32639: LOCATION: pool_process_query.c:921
Jul 15 13:18:38 MMN-0 pgpool[32639]: [42-1] 2016-07-15 13:18:38: pid 32639: DEBUG: process parameter status
Jul 15 13:18:38 MMN-0 pgpool[32639]: [42-2] 2016-07-15 13:18:38: pid 32639: DETAIL: backend:1 name:"DateStyle" value:"ISO, MDY"
Jul 15 13:18:38 MMN-0 pgpool[32639]: [42-3] 2016-07-15 13:18:38: pid 32639: LOCATION: pool_process_query.c:921
Jul 15 13:18:38 MMN-0 pgpool[32639]: [43-1] 2016-07-15 13:18:38: pid 32639: DEBUG: reading message length
Jul 15 13:18:38 MMN-0 pgpool[32639]: [43-2] 2016-07-15 13:18:38: pid 32639: DETAIL: master slot: 0 length: 25
Jul 15 13:18:38 MMN-0 pgpool[32639]: [43-3] 2016-07-15 13:18:38: pid 32639: LOCATION: pool_auth.c:1161
Jul 15 13:18:38 MMN-0 pgpool[32639]: [44-1] 2016-07-15 13:18:38: pid 32639: DEBUG: reading message length
Jul 15 13:18:38 MMN-0 pgpool[32639]: [44-2] 2016-07-15 13:18:38: pid 32639: DETAIL: master slot: 1 length: 25
Jul 15 13:18:38 MMN-0 pgpool[32639]: [44-3] 2016-07-15 13:18:38: pid 32639: LOCATION: pool_auth.c:1172
Jul 15 13:18:38 MMN-0 pgpool[32639]: [45-1] 2016-07-15 13:18:38: pid 32639: DEBUG: process parameter status
Jul 15 13:18:38 MMN-0 pgpool[32639]: [45-2] 2016-07-15 13:18:38: pid 32639: DETAIL: backend:0 name:"integer_datetimes" value:"on"
Jul 15 13:18:38 MMN-0 pgpool[32639]: [45-3] 2016-07-15 13:18:38: pid 32639: LOCATION: pool_process_query.c:921
Jul 15 13:18:38 MMN-0 pgpool[32639]: [46-1] 2016-07-15 13:18:38: pid 32639: DEBUG: process parameter status
Jul 15 13:18:38 MMN-0 pgpool[32639]: [46-2] 2016-07-15 13:18:38: pid 32639: DETAIL: backend:1 name:"integer_datetimes" value:"on"
Jul 15 13:18:38 MMN-0 pgpool[32639]: [46-3] 2016-07-15 13:18:38: pid 32639: LOCATION: pool_process_query.c:921
Jul 15 13:18:38 MMN-0 pgpool[32639]: [47-1] 2016-07-15 13:18:38: pid 32639: DEBUG: reading message length
Jul 15 13:18:38 MMN-0 pgpool[32639]: [47-2] 2016-07-15 13:18:38: pid 32639: DETAIL: master slot: 0 length: 27
Jul 15 13:18:38 MMN-0 pgpool[32639]: [47-3] 2016-07-15 13:18:38: pid 32639: LOCATION: pool_auth.c:1161
Jul 15 13:18:38 MMN-0 pgpool[32639]: [48-1] 2016-07-15 13:18:38: pid 32639: DEBUG: reading message length
Jul 15 13:18:38 MMN-0 pgpool[32639]: [48-2] 2016-07-15 13:18:38: pid 32639: DETAIL: master slot: 1 length: 27
Jul 15 13:18:38 MMN-0 pgpool[32639]: [48-3] 2016-07-15 13:18:38: pid 32639: LOCATION: pool_auth.c:1172
Jul 15 13:18:38 MMN-0 pgpool[32639]: [49-1] 2016-07-15 13:18:38: pid 32639: DEBUG: process parameter status
Jul 15 13:18:38 MMN-0 pgpool[32639]: [49-2] 2016-07-15 13:18:38: pid 32639: DETAIL: backend:0 name:"IntervalStyle" value:"postgres"
Jul 15 13:18:38 MMN-0 pgpool[32639]: [49-3] 2016-07-15 13:18:38: pid 32639: LOCATION: pool_process_query.c:921
Jul 15 13:18:38 MMN-0 pgpool[32639]: [50-1] 2016-07-15 13:18:38: pid 32639: DEBUG: process parameter status
Jul 15 13:18:38 MMN-0 pgpool[32639]: [50-2] 2016-07-15 13:18:38: pid 32639: DETAIL: backend:1 name:"IntervalStyle" value:"postgres"
Jul 15 13:18:38 MMN-0 pgpool[32639]: [50-3] 2016-07-15 13:18:38: pid 32639: LOCATION: pool_process_query.c:921
Jul 15 13:18:38 MMN-0 pgpool[32639]: [51-1] 2016-07-15 13:18:38: pid 32639: DEBUG: reading message length
Jul 15 13:18:38 MMN-0 pgpool[32639]: [51-2] 2016-07-15 13:18:38: pid 32639: DETAIL: master slot: 0 length: 20
Jul 15 13:18:38 MMN-0 pgpool[32639]: [51-3] 2016-07-15 13:18:38: pid 32639: LOCATION: pool_auth.c:1161
Jul 15 13:18:38 MMN-0 pgpool[32639]: [52-1] 2016-07-15 13:18:38: pid 32639: DEBUG: reading message length
Jul 15 13:18:38 MMN-0 pgpool[32639]: [52-2] 2016-07-15 13:18:38: pid 32639: DETAIL: master slot: 1 length: 20
Jul 15 13:18:38 MMN-0 pgpool[32639]: [52-3] 2016-07-15 13:18:38: pid 32639: LOCATION: pool_auth.c:1172
Jul 15 13:18:38 MMN-0 pgpool[32639]: [53-1] 2016-07-15 13:18:38: pid 32639: DEBUG: process parameter status
Jul 15 13:18:38 MMN-0 pgpool[32639]: [53-2] 2016-07-15 13:18:38: pid 32639: DETAIL: backend:0 name:"is_superuser" value:"on"
Jul 15 13:18:38 MMN-0 pgpool[32639]: [53-3] 2016-07-15 13:18:38: pid 32639: LOCATION: pool_process_query.c:921
Jul 15 13:18:38 MMN-0 pgpool[32639]: [54-1] 2016-07-15 13:18:38: pid 32639: DEBUG: process parameter status
Jul 15 13:18:38 MMN-0 pgpool[32639]: [54-2] 2016-07-15 13:18:38: pid 32639: DETAIL: backend:1 name:"is_superuser" value:"on"
Jul 15 13:18:38 MMN-0 pgpool[32639]: [54-3] 2016-07-15 13:18:38: pid 32639: LOCATION: pool_process_query.c:921
Jul 15 13:18:38 MMN-0 pgpool[32639]: [55-1] 2016-07-15 13:18:38: pid 32639: DEBUG: reading message length
Jul 15 13:18:38 MMN-0 pgpool[32639]: [55-2] 2016-07-15 13:18:38: pid 32639: DETAIL: master slot: 0 length: 25
Jul 15 13:18:38 MMN-0 pgpool[32639]: [55-3] 2016-07-15 13:18:38: pid 32639: LOCATION: pool_auth.c:1161
Jul 15 13:18:38 MMN-0 pgpool[32639]: [56-1] 2016-07-15 13:18:38: pid 32639: DEBUG: reading message length
Jul 15 13:18:38 MMN-0 pgpool[32639]: [56-2] 2016-07-15 13:18:38: pid 32639: DETAIL: master slot: 1 length: 25
Jul 15 13:18:38 MMN-0 pgpool[32639]: [56-3] 2016-07-15 13:18:38: pid 32639: LOCATION: pool_auth.c:1172
Jul 15 13:18:38 MMN-0 pgpool[32639]: [57-1] 2016-07-15 13:18:38: pid 32639: DEBUG: process parameter status
Jul 15 13:18:38 MMN-0 pgpool[32639]: [57-2] 2016-07-15 13:18:38: pid 32639: DETAIL: backend:0 name:"server_encoding" value:"UTF8"
Jul 15 13:18:38 MMN-0 pgpool[32639]: [57-3] 2016-07-15 13:18:38: pid 32639: LOCATION: pool_process_query.c:921
Jul 15 13:18:38 MMN-0 pgpool[32639]: [58-1] 2016-07-15 13:18:38: pid 32639: DEBUG: process parameter status
Jul 15 13:18:38 MMN-0 pgpool[32639]: [58-2] 2016-07-15 13:18:38: pid 32639: DETAIL: backend:1 name:"server_encoding" value:"UTF8"
Jul 15 13:18:38 MMN-0 pgpool[32639]: [58-3] 2016-07-15 13:18:38: pid 32639: LOCATION: pool_process_query.c:921
Jul 15 13:18:38 MMN-0 pgpool[32639]: [59-1] 2016-07-15 13:18:38: pid 32639: DEBUG: reading message length
Jul 15 13:18:38 MMN-0 pgpool[32639]: [59-2] 2016-07-15 13:18:38: pid 32639: DETAIL: master slot: 0 length: 25
Jul 15 13:18:38 MMN-0 pgpool[32639]: [59-3] 2016-07-15 13:18:38: pid 32639: LOCATION: pool_auth.c:1161
Jul 15 13:18:38 MMN-0 pgpool[32639]: [60-1] 2016-07-15 13:18:38: pid 32639: DEBUG: reading message length
Jul 15 13:18:38 MMN-0 pgpool[32639]: [60-2] 2016-07-15 13:18:38: pid 32639: DETAIL: master slot: 1 length: 25
Jul 15 13:18:38 MMN-0 pgpool[32639]: [60-3] 2016-07-15 13:18:38: pid 32639: LOCATION: pool_auth.c:1172
Jul 15 13:18:38 MMN-0 pgpool[32639]: [61-1] 2016-07-15 13:18:38: pid 32639: DEBUG: process parameter status
Jul 15 13:18:38 MMN-0 pgpool[32639]: [61-2] 2016-07-15 13:18:38: pid 32639: DETAIL: backend:0 name:"server_version" value:"9.3.6"
Jul 15 13:18:38 MMN-0 pgpool[32639]: [61-3] 2016-07-15 13:18:38: pid 32639: LOCATION: pool_process_query.c:921
Jul 15 13:18:38 MMN-0 pgpool[32639]: [62-1] 2016-07-15 13:18:38: pid 32639: DEBUG: process parameter status
Jul 15 13:18:38 MMN-0 pgpool[32639]: [62-2] 2016-07-15 13:18:38: pid 32639: DETAIL: backend:1 name:"server_version" value:"9.3.6"
Jul 15 13:18:38 MMN-0 pgpool[32639]: [62-3] 2016-07-15 13:18:38: pid 32639: LOCATION: pool_process_query.c:921
Jul 15 13:18:38 MMN-0 pgpool[32639]: [63-1] 2016-07-15 13:18:38: pid 32639: DEBUG: reading message length
Jul 15 13:18:38 MMN-0 pgpool[32639]: [63-2] 2016-07-15 13:18:38: pid 32639: DETAIL: master slot: 0 length: 48
Jul 15 13:18:38 MMN-0 pgpool[32639]: [63-3] 2016-07-15 13:18:38: pid 32639: LOCATION: pool_auth.c:1161
Jul 15 13:18:38 MMN-0 pgpool[32639]: [64-1] 2016-07-15 13:18:38: pid 32639: DEBUG: reading message length
Jul 15 13:18:38 MMN-0 pgpool[32639]: [64-2] 2016-07-15 13:18:38: pid 32639: DETAIL: master slot: 1 length: 48
Jul 15 13:18:38 MMN-0 pgpool[32639]: [64-3] 2016-07-15 13:18:38: pid 32639: LOCATION: pool_auth.c:1172
Jul 15 13:18:38 MMN-0 pgpool[32639]: [65-1] 2016-07-15 13:18:38: pid 32639: DEBUG: process parameter status
Jul 15 13:18:38 MMN-0 pgpool[32639]: [65-2] 2016-07-15 13:18:38: pid 32639: DETAIL: backend:0 name:"session_authorization" value:"_nokfssystestpostgres"
Jul 15 13:18:38 MMN-0 pgpool[32639]: [65-3] 2016-07-15 13:18:38: pid 32639: LOCATION: pool_process_query.c:921
Jul 15 13:18:38 MMN-0 pgpool[32639]: [66-1] 2016-07-15 13:18:38: pid 32639: DEBUG: process parameter status
Jul 15 13:18:38 MMN-0 pgpool[32639]: [66-2] 2016-07-15 13:18:38: pid 32639: DETAIL: backend:1 name:"session_authorization" value:"_nokfssystestpostgres"
Jul 15 13:18:38 MMN-0 pgpool[32639]: [66-3] 2016-07-15 13:18:38: pid 32639: LOCATION: pool_process_query.c:921
Jul 15 13:18:38 MMN-0 pgpool[32639]: [67-1] 2016-07-15 13:18:38: pid 32639: DEBUG: reading message length
Jul 15 13:18:38 MMN-0 pgpool[32639]: [67-2] 2016-07-15 13:18:38: pid 32639: DETAIL: master slot: 0 length: 35
Jul 15 13:18:38 MMN-0 pgpool[32639]: [67-3] 2016-07-15 13:18:38: pid 32639: LOCATION: pool_auth.c:1161
Jul 15 13:18:38 MMN-0 pgpool[32639]: [68-1] 2016-07-15 13:18:38: pid 32639: DEBUG: reading message length
Jul 15 13:18:38 MMN-0 pgpool[32639]: [68-2] 2016-07-15 13:18:38: pid 32639: DETAIL: master slot: 1 length: 35
Jul 15 13:18:38 MMN-0 pgpool[32639]: [68-3] 2016-07-15 13:18:38: pid 32639: LOCATION: pool_auth.c:1172
Jul 15 13:18:38 MMN-0 pgpool[32639]: [69-1] 2016-07-15 13:18:38: pid 32639: DEBUG: process parameter status
Jul 15 13:18:38 MMN-0 pgpool[32639]: [69-2] 2016-07-15 13:18:38: pid 32639: DETAIL: backend:0 name:"standard_conforming_strings" value:"on"
Jul 15 13:18:38 MMN-0 pgpool[32639]: [69-3] 2016-07-15 13:18:38: pid 32639: LOCATION: pool_process_query.c:921
Jul 15 13:18:38 MMN-0 pgpool[32639]: [70-1] 2016-07-15 13:18:38: pid 32639: DEBUG: process parameter status
Jul 15 13:18:38 MMN-0 pgpool[32639]: [70-2] 2016-07-15 13:18:38: pid 32639: DETAIL: backend:1 name:"standard_conforming_strings" value:"on"
Jul 15 13:18:38 MMN-0 pgpool[32639]: [70-3] 2016-07-15 13:18:38: pid 32639: LOCATION: pool_process_query.c:921
Jul 15 13:18:38 MMN-0 pgpool[32639]: [71-1] 2016-07-15 13:18:38: pid 32639: DEBUG: reading message length
Jul 15 13:18:38 MMN-0 pgpool[32639]: [71-2] 2016-07-15 13:18:38: pid 32639: DETAIL: master slot: 0 length: 27
Jul 15 13:18:38 MMN-0 pgpool[32639]: [71-3] 2016-07-15 13:18:38: pid 32639: LOCATION: pool_auth.c:1161
Jul 15 13:18:38 MMN-0 pgpool[32639]: [72-1] 2016-07-15 13:18:38: pid 32639: DEBUG: reading message length
Jul 15 13:18:38 MMN-0 pgpool[32639]: [72-2] 2016-07-15 13:18:38: pid 32639: DETAIL: master slot: 1 length: 27
Jul 15 13:18:38 MMN-0 pgpool[32639]: [72-3] 2016-07-15 13:18:38: pid 32639: LOCATION: pool_auth.c:1172
Jul 15 13:18:38 MMN-0 pgpool[32639]: [73-1] 2016-07-15 13:18:38: pid 32639: DEBUG: process parameter status
Jul 15 13:18:38 MMN-0 pgpool[32639]: [73-2] 2016-07-15 13:18:38: pid 32639: DETAIL: backend:0 name:"TimeZone" value:"Asia/Shanghai"
Jul 15 13:18:38 MMN-0 pgpool[32639]: [73-3] 2016-07-15 13:18:38: pid 32639: LOCATION: pool_process_query.c:921
Jul 15 13:18:38 MMN-0 pgpool[32639]: [74-1] 2016-07-15 13:18:38: pid 32639: DEBUG: process parameter status
Jul 15 13:18:38 MMN-0 pgpool[32639]: [74-2] 2016-07-15 13:18:38: pid 32639: DETAIL: backend:1 name:"TimeZone" value:"Asia/Shanghai"
Jul 15 13:18:38 MMN-0 pgpool[32639]: [74-3] 2016-07-15 13:18:38: pid 32639: LOCATION: pool_process_query.c:921
Jul 15 13:18:38 MMN-0 pgpool[32639]: [75-1] 2016-07-15 13:18:38: pid 32639: DEBUG: reading message length
Jul 15 13:18:38 MMN-0 pgpool[32639]: [75-2] 2016-07-15 13:18:38: pid 32639: DETAIL: slot: 0 length: 12
Jul 15 13:18:38 MMN-0 pgpool[32639]: [75-3] 2016-07-15 13:18:38: pid 32639: LOCATION: pool_auth.c:1107
Jul 15 13:18:38 MMN-0 pgpool[32639]: [76-1] 2016-07-15 13:18:38: pid 32639: DEBUG: reading message length
Jul 15 13:18:38 MMN-0 pgpool[32639]: [76-2] 2016-07-15 13:18:38: pid 32639: DETAIL: slot: 1 length: 12
Jul 15 13:18:38 MMN-0 pgpool[32639]: [76-3] 2016-07-15 13:18:38: pid 32639: LOCATION: pool_auth.c:1126
Jul 15 13:18:38 MMN-0 pgpool[32639]: [77-1] 2016-07-15 13:18:38: pid 32639: DEBUG: authentication backend
Jul 15 13:18:38 MMN-0 pgpool[32639]: [77-2] 2016-07-15 13:18:38: pid 32639: DETAIL: cp->info[i]:0x7f655a18e000 pid:32690
Jul 15 13:18:38 MMN-0 pgpool[32639]: [77-3] 2016-07-15 13:18:38: pid 32639: LOCATION: pool_auth.c:391
Jul 15 13:18:38 MMN-0 pgpool[32639]: [78-1] 2016-07-15 13:18:38: pid 32639: DEBUG: authentication backend
Jul 15 13:18:38 MMN-0 pgpool[32639]: [78-2] 2016-07-15 13:18:38: pid 32639: DETAIL: cp->info[i]:0x7f655a18e088 pid:2074
Jul 15 13:18:38 MMN-0 pgpool[32639]: [78-3] 2016-07-15 13:18:38: pid 32639: LOCATION: pool_auth.c:391
Jul 15 13:18:38 MMN-0 pgpool[32639]: [79-1] 2016-07-15 13:18:38: pid 32639: DEBUG: sending backend key data
Jul 15 13:18:38 MMN-0 pgpool[32639]: [79-2] 2016-07-15 13:18:38: pid 32639: DETAIL: send pid 2074 to frontend
Jul 15 13:18:38 MMN-0 pgpool[32639]: [79-3] 2016-07-15 13:18:38: pid 32639: LOCATION: pool_auth.c:519
Jul 15 13:18:38 MMN-0 pgpool[32639]: [80-1] 2016-07-15 13:18:38: pid 32639: DEBUG: selecting load balance node
Jul 15 13:18:38 MMN-0 pgpool[32639]: [80-2] 2016-07-15 13:18:38: pid 32639: DETAIL: selected backend id is 1
Jul 15 13:18:38 MMN-0 pgpool[32639]: [80-3] 2016-07-15 13:18:38: pid 32639: LOCATION: child.c:1720
Jul 15 13:18:38 MMN-0 pgpool[32639]: [81-1] 2016-07-15 13:18:38: pid 32639: DEBUG: initializing session context
Jul 15 13:18:38 MMN-0 pgpool[32639]: [81-2] 2016-07-15 13:18:38: pid 32639: DETAIL: selected load balancing node: 1
Jul 15 13:18:38 MMN-0 pgpool[32639]: [81-3] 2016-07-15 13:18:38: pid 32639: LOCATION: pool_session_context.c:99
Jul 15 13:18:38 MMN-0 pgpool[32639]: [82-1] 2016-07-15 13:18:38: pid 32639: DEBUG: session context: unsetting query in progress. DONE
Jul 15 13:18:38 MMN-0 pgpool[32639]: [82-2] 2016-07-15 13:18:38: pid 32639: LOCATION: pool_session_context.c:219
Jul 15 13:18:38 MMN-0 pgpool[32639]: [83-1] 2016-07-15 13:18:38: pid 32639: DEBUG: session context: clearing transaction isolation. DONE
Jul 15 13:18:38 MMN-0 pgpool[32639]: [83-2] 2016-07-15 13:18:38: pid 32639: LOCATION: pool_session_context.c:731
Jul 15 13:18:38 MMN-0 pgpool[32639]: [84-1] 2016-07-15 13:18:38: pid 32639: DEBUG: session context: clearing writing transaction. DONE
Jul 15 13:18:38 MMN-0 pgpool[32639]: [84-2] 2016-07-15 13:18:38: pid 32639: LOCATION: pool_session_context.c:565
Jul 15 13:18:38 MMN-0 pgpool[32639]: [85-1] 2016-07-15 13:18:38: pid 32639: DEBUG: session context: clearing failed transaction. DONE
Jul 15 13:18:38 MMN-0 pgpool[32639]: [85-2] 2016-07-15 13:18:38: pid 32639: LOCATION: pool_session_context.c:594
Jul 15 13:18:38 MMN-0 pgpool[32639]: [86-1] 2016-07-15 13:18:38: pid 32639: DEBUG: session context: clearing failed transaction. DONE
Jul 15 13:18:38 MMN-0 pgpool[32639]: [86-2] 2016-07-15 13:18:38: pid 32639: LOCATION: pool_session_context.c:624
Jul 15 13:18:38 MMN-0 pgpool[32639]: [87-1] 2016-07-15 13:18:38: pid 32639: DEBUG: session context: clearing skip reading from backends. DONE
Jul 15 13:18:38 MMN-0 pgpool[32639]: [87-2] 2016-07-15 13:18:38: pid 32639: LOCATION: pool_session_context.c:250
Jul 15 13:18:38 MMN-0 pgpool[32639]: [88-1] 2016-07-15 13:18:38: pid 32639: DEBUG: session context: clearing ignore till sync. DONE
Jul 15 13:18:38 MMN-0 pgpool[32639]: [88-2] 2016-07-15 13:18:38: pid 32639: LOCATION: pool_session_context.c:310
Jul 15 13:18:38 MMN-0 pgpool[32639]: [89-1] 2016-07-15 13:18:38: pid 32639: DEBUG: pool_use_sync_map: we cannot use sync map because STREAM: 0 query in progress: 0 doing extended query: 0
Jul 15 13:18:38 MMN-0 pgpool[32639]: [89-2] 2016-07-15 13:18:38: pid 32639: LOCATION: pool_session_context.c:969
Jul 15 13:18:38 MMN-0 pgpool[32639]: [90-1] 2016-07-15 13:18:38: pid 32639: DEBUG: reading backend data packet kind
Jul 15 13:18:38 MMN-0 pgpool[32639]: [90-2] 2016-07-15 13:18:38: pid 32639: DETAIL: master node id: 0
Jul 15 13:18:38 MMN-0 pgpool[32639]: [90-3] 2016-07-15 13:18:38: pid 32639: LOCATION: pool_process_query.c:3238
Jul 15 13:18:38 MMN-0 pgpool[32639]: [91-1] 2016-07-15 13:18:38: pid 32639: DEBUG: reading backend data packet kind
Jul 15 13:18:38 MMN-0 pgpool[32639]: [91-2] 2016-07-15 13:18:38: pid 32639: DETAIL: backend:0 kind:'Z'
Jul 15 13:18:38 MMN-0 pgpool[32639]: [91-3] 2016-07-15 13:18:38: pid 32639: LOCATION: pool_process_query.c:3308
Jul 15 13:18:38 MMN-0 pgpool[32639]: [92-1] 2016-07-15 13:18:38: pid 32639: DEBUG: reading backend data packet kind
Jul 15 13:18:38 MMN-0 pgpool[32639]: [92-2] 2016-07-15 13:18:38: pid 32639: DETAIL: backend:0 of 4 kind = 'Z'
Jul 15 13:18:38 MMN-0 pgpool[32639]: [92-3] 2016-07-15 13:18:38: pid 32639: LOCATION: pool_process_query.c:3349
Jul 15 13:18:38 MMN-0 pgpool[32639]: [93-1] 2016-07-15 13:18:38: pid 32639: DEBUG: reading backend data packet kind
Jul 15 13:18:38 MMN-0 pgpool[32639]: [93-2] 2016-07-15 13:18:38: pid 32639: DETAIL: backend:1 kind:'Z'
Jul 15 13:18:38 MMN-0 pgpool[32639]: [93-3] 2016-07-15 13:18:38: pid 32639: LOCATION: pool_process_query.c:3308
Jul 15 13:18:38 MMN-0 pgpool[32639]: [94-1] 2016-07-15 13:18:38: pid 32639: DEBUG: reading backend data packet kind
Jul 15 13:18:38 MMN-0 pgpool[32639]: [94-2] 2016-07-15 13:18:38: pid 32639: DETAIL: backend:1 of 4 kind = 'Z'
Jul 15 13:18:38 MMN-0 pgpool[32639]: [94-3] 2016-07-15 13:18:38: pid 32639: LOCATION: pool_process_query.c:3349
Jul 15 13:18:38 MMN-0 pgpool[32639]: [95-1] 2016-07-15 13:18:38: pid 32639: DEBUG: read_kind_from_backend max_count:2.000000 num_executed_nodes:2
Jul 15 13:18:38 MMN-0 pgpool[32639]: [95-2] 2016-07-15 13:18:38: pid 32639: LOCATION: pool_process_query.c:3365
Jul 15 13:18:38 MMN-0 pgpool[32639]: [96-1] 2016-07-15 13:18:38: pid 32639: DEBUG: processing backend response
Jul 15 13:18:38 MMN-0 pgpool[32639]: [96-2] 2016-07-15 13:18:38: pid 32639: DETAIL: received kind 'Z'(5a) from backend
Jul 15 13:18:38 MMN-0 pgpool[32639]: [96-3] 2016-07-15 13:18:38: pid 32639: LOCATION: pool_proto_modules.c:2424
Jul 15 13:18:38 MMN-0 pgpool[32639]: [97-1] 2016-07-15 13:18:38: pid 32639: DEBUG: processing backend response
Jul 15 13:18:38 MMN-0 pgpool[32639]: [97-2] 2016-07-15 13:18:38: pid 32639: DETAIL: Ready For Query received
Jul 15 13:18:38 MMN-0 pgpool[32639]: [97-3] 2016-07-15 13:18:38: pid 32639: LOCATION: pool_proto_modules.c:2442
Jul 15 13:18:38 MMN-0 pgpool[32639]: [98-1] 2016-07-15 13:18:38: pid 32639: DEBUG: session context: clearing ignore till sync. DONE
Jul 15 13:18:38 MMN-0 pgpool[32639]: [98-2] 2016-07-15 13:18:38: pid 32639: LOCATION: pool_session_context.c:310
Jul 15 13:18:38 MMN-0 pgpool[32639]: [99-1] 2016-07-15 13:18:38: pid 32639: DEBUG: pool_use_sync_map: we cannot use sync map because STREAM: 0 query in progress: 0 doing extended query: 0
Jul 15 13:18:38 MMN-0 pgpool[32639]: [99-2] 2016-07-15 13:18:38: pid 32639: LOCATION: pool_session_context.c:969
Jul 15 13:18:38 MMN-0 pgpool[32639]: [100-1] 2016-07-15 13:18:38: pid 32639: DEBUG: pool_use_sync_map: we cannot use sync map because STREAM: 0 query in progress: 0 doing extended query: 0
Jul 15 13:18:38 MMN-0 pgpool[32639]: [100-2] 2016-07-15 13:18:38: pid 32639: LOCATION: pool_session_context.c:969
Jul 15 13:18:38 MMN-0 pgpool[32639]: [101-1] 2016-07-15 13:18:38: pid 32639: DEBUG: pool_use_sync_map: we cannot use sync map because STREAM: 0 query in progress: 0 doing extended query: 0
Jul 15 13:18:38 MMN-0 pgpool[32639]: [101-2] 2016-07-15 13:18:38: pid 32639: LOCATION: pool_session_context.c:969
Jul 15 13:18:38 MMN-0 pgpool[32639]: [102-1] 2016-07-15 13:18:38: pid 32639: DEBUG: reading message length
Jul 15 13:18:38 MMN-0 pgpool[32639]: [102-2] 2016-07-15 13:18:38: pid 32639: DETAIL: slot: 0 length: 5
Jul 15 13:18:38 MMN-0 pgpool[32639]: [102-3] 2016-07-15 13:18:38: pid 32639: LOCATION: pool_auth.c:1107
Jul 15 13:18:38 MMN-0 pgpool[32639]: [103-1] 2016-07-15 13:18:38: pid 32639: DEBUG: reading message length
Jul 15 13:18:38 MMN-0 pgpool[32639]: [103-2] 2016-07-15 13:18:38: pid 32639: DETAIL: slot: 1 length: 5
Jul 15 13:18:38 MMN-0 pgpool[32639]: [103-3] 2016-07-15 13:18:38: pid 32639: LOCATION: pool_auth.c:1126
Jul 15 13:18:38 MMN-0 pgpool[32639]: [104-1] 2016-07-15 13:18:38: pid 32639: DEBUG: processing ReadyForQuery
Jul 15 13:18:38 MMN-0 pgpool[32639]: [104-2] 2016-07-15 13:18:38: pid 32639: DETAIL: transaction state '
Jul 15 13:18:38 MMN-0 pgpool[32639]: [104-3] 2016-07-15 13:18:38: pid 32639: LOCATION: pool_proto_modules.c:1612
Jul 15 13:18:38 MMN-0 pgpool[32639]: [105-1] 2016-07-15 13:18:38: pid 32639: DEBUG: processing ReadyForQuery
Jul 15 13:18:38 MMN-0 pgpool[32639]: [105-2] 2016-07-15 13:18:38: pid 32639: DETAIL: transaction state 'I'(49)
Jul 15 13:18:38 MMN-0 pgpool[32639]: [105-3] 2016-07-15 13:18:38: pid 32639: LOCATION: pool_proto_modules.c:1612
Jul 15 13:18:38 MMN-0 pgpool[32639]: [106-1] 2016-07-15 13:18:38: pid 32639: DEBUG: processing frontend response
Jul 15 13:18:38 MMN-0 pgpool[32639]: [106-2] 2016-07-15 13:18:38: pid 32639: DETAIL: received kind 'P'(50) from frontend
Jul 15 13:18:38 MMN-0 pgpool[32639]: [106-3] 2016-07-15 13:18:38: pid 32639: LOCATION: pool_proto_modules.c:2188
Jul 15 13:18:38 MMN-0 pgpool[32639]: [107-1] 2016-07-15 13:18:38: pid 32639: DEBUG: session context: clearing doing extended query messaging. DONE
Jul 15 13:18:38 MMN-0 pgpool[32639]: [107-2] 2016-07-15 13:18:38: pid 32639: LOCATION: pool_session_context.c:280
Jul 15 13:18:38 MMN-0 pgpool[32639]: [108-1] 2016-07-15 13:18:38: pid 32639: DEBUG: session context: setting doing extended query messaging. DONE
Jul 15 13:18:38 MMN-0 pgpool[32639]: [108-2] 2016-07-15 13:18:38: pid 32639: LOCATION: pool_session_context.c:269
Jul 15 13:18:38 MMN-0 pgpool[32639]: [109-1] 2016-07-15 13:18:38: pid 32639: DEBUG: Parse: statement name <>
Jul 15 13:18:38 MMN-0 pgpool[32639]: [109-2] 2016-07-15 13:18:38: pid 32639: LOCATION: pool_proto_modules.c:817
Jul 15 13:18:38 MMN-0 pgpool[32639]: [110-1] 2016-07-15 13:18:38: pid 32639: DEBUG: session context: setting query in progress. DONE
Jul 15 13:18:38 MMN-0 pgpool[32639]: [110-2] 2016-07-15 13:18:38: pid 32639: LOCATION: pool_session_context.c:208
Jul 15 13:18:38 MMN-0 pgpool[32639]: [111-1] 2016-07-15 13:18:38: pid 32639: DEBUG: decide where to send the queries
Jul 15 13:18:38 MMN-0 pgpool[32639]: [111-2] 2016-07-15 13:18:38: pid 32639: DETAIL: destination = 3 for query= "SET extra_float_digits = 3"
Jul 15 13:18:38 MMN-0 pgpool[32639]: [111-3] 2016-07-15 13:18:38: pid 32639: LOCATION: pool_query_context.c:370
Jul 15 13:18:38 MMN-0 pgpool[32639]: [112-1] 2016-07-15 13:18:38: pid 32639: DEBUG: Parse: waiting for master completing the query
Jul 15 13:18:38 MMN-0 pgpool[32639]: [112-2] 2016-07-15 13:18:38: pid 32639: LOCATION: pool_proto_modules.c:1064
Jul 15 13:18:38 MMN-0 pgpool[32639]: [113-1] 2016-07-15 13:18:38: pid 32639: DEBUG: pool_send_and_wait: pool_set_sync_map: 0
Jul 15 13:18:38 MMN-0 pgpool[32639]: [113-2] 2016-07-15 13:18:38: pid 32639: LOCATION: pool_query_context.c:854
Jul 15 13:18:38 MMN-0 pgpool[32639]: [114-1] 2016-07-15 13:18:38: pid 32639: DEBUG: pool_write: to backend: kind:P
Jul 15 13:18:38 MMN-0 pgpool[32639]: [114-2] 2016-07-15 13:18:38: pid 32639: LOCATION: pool_stream.c:431
Jul 15 13:18:38 MMN-0 pgpool[32639]: [115-1] 2016-07-15 13:18:38: pid 32639: DEBUG: pool_write: to backend: kind:H
Jul 15 13:18:38 MMN-0 pgpool[32639]: [115-2] 2016-07-15 13:18:38: pid 32639: LOCATION: pool_stream.c:431
Jul 15 13:18:38 MMN-0 pgpool[32639]: [116-1] 2016-07-15 13:18:38: pid 32639: DEBUG: waiting for query response
Jul 15 13:18:38 MMN-0 pgpool[32639]: [116-2] 2016-07-15 13:18:38: pid 32639: DETAIL: waiting for backend:0 to complete the query
Jul 15 13:18:38 MMN-0 pgpool[32639]: [116-3] 2016-07-15 13:18:38: pid 32639: LOCATION: pool_process_query.c:479
Jul 15 13:18:38 MMN-0 pgpool[32639]: [117-1] 2016-07-15 13:18:38: pid 32639: DEBUG: pool_read: read 5 bytes from backend 0
Jul 15 13:18:38 MMN-0 pgpool[32639]: [117-2] 2016-07-15 13:18:38: pid 32639: LOCATION: pool_stream.c:190
Jul 15 13:18:38 MMN-0 pgpool[32639]: [118-1] 2016-07-15 13:18:38: pid 32639: DEBUG: detect error: kind: 1
Jul 15 13:18:38 MMN-0 pgpool[32639]: [118-2] 2016-07-15 13:18:38: pid 32639: LOCATION: pool_process_query.c:4166
Jul 15 13:18:38 MMN-0 pgpool[32639]: [119-1] 2016-07-15 13:18:38: pid 32639: DEBUG: pool_send_and_wait: pool_set_sync_map: 1
Jul 15 13:18:38 MMN-0 pgpool[32639]: [119-2] 2016-07-15 13:18:38: pid 32639: LOCATION: pool_query_context.c:854
Jul 15 13:18:38 MMN-0 pgpool[32639]: [120-1] 2016-07-15 13:18:38: pid 32639: DEBUG: pool_write: to backend: kind:P
Jul 15 13:18:38 MMN-0 pgpool[32639]: [120-2] 2016-07-15 13:18:38: pid 32639: LOCATION: pool_stream.c:431
Jul 15 13:18:38 MMN-0 pgpool[32639]: [121-1] 2016-07-15 13:18:38: pid 32639: DEBUG: pool_write: to backend: kind:H
Jul 15 13:18:38 MMN-0 pgpool[32639]: [121-2] 2016-07-15 13:18:38: pid 32639: LOCATION: pool_stream.c:431
Jul 15 13:18:38 MMN-0 pgpool[32639]: [122-1] 2016-07-15 13:18:38: pid 32639: DEBUG: waiting for query response
Jul 15 13:18:38 MMN-0 pgpool[32639]: [122-2] 2016-07-15 13:18:38: pid 32639: DETAIL: waiting for backend:1 to complete the query
Jul 15 13:18:38 MMN-0 pgpool[32639]: [122-3] 2016-07-15 13:18:38: pid 32639: LOCATION: pool_process_query.c:479
Jul 15 13:18:38 MMN-0 pgpool[32639]: [123-1] 2016-07-15 13:18:38: pid 32639: DEBUG: pool_read: read 5 bytes from backend 1
Jul 15 13:18:38 MMN-0 pgpool[32639]: [123-2] 2016-07-15 13:18:38: pid 32639: LOCATION: pool_stream.c:190
Jul 15 13:18:38 MMN-0 pgpool[32639]: [124-1] 2016-07-15 13:18:38: pid 32639: DEBUG: pool_use_sync_map: we cannot use sync map because STREAM: 0 query in progress: 1 doing extended query: 1

JDBC log ==>
13:18:38.395 (1) PostgreSQL 9.3 JDBC4.1 (build 1103)
13:18:38.400 (1) Trying to establish a protocol version 3 connection to MMN-0:9999
13:18:38.413 (1) Receive Buffer Size is 530136
13:18:38.413 (1) Send Buffer Size is 1313280
13:18:38.413 (1) FE=> StartupPacket(user=_nokfssystestpostgres, database=ycsb, client_encoding=UTF8, DateStyle=ISO, TimeZone=Asia/Shanghai, extra_float_digits=2)
13:18:38.420 (1) <=BE AuthenticationOk
13:18:38.431 (1) <=BE ParameterStatus(application_name = )
13:18:38.431 (1) <=BE ParameterStatus(client_encoding = UTF8)
13:18:38.431 (1) <=BE ParameterStatus(DateStyle = ISO, MDY)
13:18:38.431 (1) <=BE ParameterStatus(integer_datetimes = on)
13:18:38.432 (1) <=BE ParameterStatus(IntervalStyle = postgres)
13:18:38.432 (1) <=BE ParameterStatus(is_superuser = on)
13:18:38.432 (1) <=BE ParameterStatus(server_encoding = UTF8)
13:18:38.432 (1) <=BE ParameterStatus(server_version = 9.3.6)
13:18:38.432 (1) <=BE ParameterStatus(session_authorization = _nokfssystestpostgres)
13:18:38.432 (1) <=BE ParameterStatus(standard_conforming_strings = on)
13:18:38.432 (1) <=BE ParameterStatus(TimeZone = Asia/Shanghai)
13:18:38.432 (1) <=BE BackendKeyData(pid=2074,ckey=1344905865)
13:18:38.435 (1) <=BE NoticeResponse(DEBUG: selecting load balance node
  Detail: selected backend id is 1)
SQLWarning:
13:18:38.436 (1) <=BE NoticeResponse(DEBUG: initializing session context
  Detail: selected load balancing node: 1)
SQLWarning:
13:18:38.436 (1) <=BE NoticeResponse(DEBUG: session context: unsetting query in progress. DONE)
SQLWarning:
13:18:38.436 (1) <=BE NoticeResponse(DEBUG: session context: clearing transaction isolation. DONE)
SQLWarning:
13:18:38.437 (1) <=BE NoticeResponse(DEBUG: session context: clearing writing transaction. DONE)
SQLWarning:
13:18:38.437 (1) <=BE NoticeResponse(DEBUG: session context: clearing failed transaction. DONE)
SQLWarning:
13:18:38.437 (1) <=BE NoticeResponse(DEBUG: session context: clearing failed transaction. DONE)
SQLWarning:
13:18:38.437 (1) <=BE NoticeResponse(DEBUG: session context: clearing skip reading from backends. DONE)
SQLWarning:
13:18:38.437 (1) <=BE NoticeResponse(DEBUG: session context: clearing ignore till sync. DONE)
SQLWarning:
13:18:38.438 (1) <=BE NoticeResponse(DEBUG: pool_use_sync_map: we cannot use sync map because STREAM: 0 query in progress: 0 doing extended query: 0)
SQLWarning:
13:18:38.438 (1) <=BE NoticeResponse(DEBUG: reading backend data packet kind
  Detail: master node id: 0)
SQLWarning:
13:18:38.438 (1) <=BE NoticeResponse(DEBUG: reading backend data packet kind
  Detail: backend:0 kind:'Z')
SQLWarning:
13:18:38.438 (1) <=BE NoticeResponse(DEBUG: reading backend data packet kind
  Detail: backend:0 of 4 kind = 'Z')
SQLWarning:
13:18:38.439 (1) <=BE NoticeResponse(DEBUG: reading backend data packet kind
  Detail: backend:1 kind:'Z')
SQLWarning:
13:18:38.439 (1) <=BE NoticeResponse(DEBUG: reading backend data packet kind
  Detail: backend:1 of 4 kind = 'Z')
SQLWarning:
13:18:38.439 (1) <=BE NoticeResponse(DEBUG: read_kind_from_backend max_count:2.000000 num_executed_nodes:2)
SQLWarning:
13:18:38.439 (1) <=BE NoticeResponse(DEBUG: processing backend response
  Detail: received kind 'Z'(5a) from backend)
SQLWarning:
13:18:38.440 (1) <=BE NoticeResponse(DEBUG: processing backend response
  Detail: Ready For Query received)
SQLWarning:
13:18:38.440 (1) <=BE NoticeResponse(DEBUG: session context: clearing ignore till sync. DONE)
SQLWarning:
13:18:38.440 (1) <=BE NoticeResponse(DEBUG: pool_use_sync_map: we cannot use sync map because STREAM: 0 query in progress: 0 doing extended query: 0)
SQLWarning:
13:18:38.440 (1) <=BE NoticeResponse(DEBUG: pool_use_sync_map: we cannot use sync map because STREAM: 0 query in progress: 0 doing extended query: 0)
SQLWarning:
13:18:38.440 (1) <=BE NoticeResponse(DEBUG: pool_use_sync_map: we cannot use sync map because STREAM: 0 query in progress: 0 doing extended query: 0)
SQLWarning:
13:18:38.441 (1) <=BE NoticeResponse(DEBUG: reading message length
  Detail: slot: 0 length: 5)
SQLWarning:
13:18:38.441 (1) <=BE NoticeResponse(DEBUG: reading message length
  Detail: slot: 1 length: 5)
SQLWarning:
13:18:38.441 (1) <=BE NoticeResponse(DEBUG: processing ReadyForQuery
  Detail: transaction state ')
SQLWarning:
13:18:38.441 (1) <=BE NoticeResponse(DEBUG: processing ReadyForQuery
  Detail: transaction state 'I'(49))
SQLWarning:
13:18:38.442 (1) <=BE ReadyForQuery(I)
13:18:38.443 (1) simple execute, handler=org.postgresql.core.SetupQueryRunner$SimpleResultHandler@4ae8f8d, maxRows=0, fetchSize=0, flags=23
13:18:38.444 (1) FE=> Parse(stmt=null,query="SET extra_float_digits = 3",oids={})
13:18:38.445 (1) FE=> Bind(stmt=null,portal=null)
13:18:38.445 (1) FE=> Execute(portal=null,limit=1)
13:18:38.445 (1) FE=> Sync
13:18:38.446 (1) <=BE NoticeResponse(DEBUG: processing frontend response
  Detail: received kind 'P'(50) from frontend)
SQLWarning:
13:18:38.446 (1) <=BE NoticeResponse(DEBUG: session context: clearing doing extended query messaging. DONE)
SQLWarning:
13:18:38.446 (1) <=BE NoticeResponse(DEBUG: session context: setting doing extended query messaging. DONE)
SQLWarning:
13:18:38.447 (1) <=BE NoticeResponse(DEBUG: Parse: statement name <>)
SQLWarning:
13:18:38.447 (1) <=BE NoticeResponse(DEBUG: session context: setting query in progress. DONE)
SQLWarning:
13:18:38.447 (1) <=BE NoticeResponse(DEBUG: decide where to send the queries
  Detail: destination = 3 for query= "SET extra_float_digits = 3")
SQLWarning:
13:18:38.447 (1) <=BE NoticeResponse(DEBUG: Parse: waiting for master completing the query)
SQLWarning:
13:18:38.447 (1) <=BE NoticeResponse(DEBUG: pool_send_and_wait: pool_set_sync_map: 0)
SQLWarning:
13:18:38.447 (1) <=BE NoticeResponse(DEBUG: pool_write: to backend: kind:P)
SQLWarning:
13:18:38.447 (1) <=BE NoticeResponse(DEBUG: pool_write: to backend: kind:H)
SQLWarning:
13:18:38.447 (1) <=BE NoticeResponse(DEBUG: waiting for query response
  Detail: waiting for backend:0 to complete the query)
SQLWarning:
13:18:38.448 (1) <=BE NoticeResponse(DEBUG: pool_read: read 5 bytes from backend 0)
SQLWarning:
13:18:38.448 (1) <=BE NoticeResponse(DEBUG: detect error: kind: 1)
SQLWarning:
13:18:38.448 (1) <=BE NoticeResponse(DEBUG: pool_send_and_wait: pool_set_sync_map: 1)
SQLWarning:
13:18:38.448 (1) <=BE NoticeResponse(DEBUG: pool_write: to backend: kind:P)
SQLWarning:
13:18:38.448 (1) <=BE NoticeResponse(DEBUG: pool_write: to backend: kind:H)
SQLWarning:
13:18:38.448 (1) <=BE NoticeResponse(DEBUG: waiting for query response
  Detail: waiting for backend:1 to complete the query)
SQLWarning:
13:18:38.449 (1) <=BE NoticeResponse(DEBUG: pool_read: read 5 bytes from backend 1)
SQLWarning:
13:18:38.449 (1) <=BE NoticeResponse(DEBUG: pool_use_sync_map: we cannot use sync map because STREAM: 0 query in progress: 1 doing extended query: 1)
SQLWarning:
13:18:38.450 (1) <=BE NoticeResponse(DEBUG: reading backend data packet kind
  Detail: master node id: 0)
SQLWarning:
13:18:38.450 (1) <=BE NoticeResponse(DEBUG: reading backend data packet kind
  Detail: backend:0 kind:'1')
SQLWarning:
13:18:38.450 (1) <=BE NoticeResponse(DEBUG: reading backend data packet kind
  Detail: backend:0 of 4 kind = '1')
SQLWarning:
13:18:38.450 (1) <=BE NoticeResponse(DEBUG: reading backend data packet kind
  Detail: backend:1 kind:'1')
SQLWarning:
13:18:38.450 (1) <=BE NoticeResponse(DEBUG: reading backend data packet kind
  Detail: backend:1 of 4 kind = '1')
SQLWarning:
13:18:38.450 (1) <=BE NoticeResponse(DEBUG: read_kind_from_backend max_count:2.000000 num_executed_nodes:2)
SQLWarning:
13:18:38.451 (1) <=BE NoticeResponse(DEBUG: processing backend response
  Detail: received kind '1'(31) from backend)
SQLWarning:
13:18:38.451 (1) <=BE NoticeResponse(DEBUG: called by pool_add_sent_message: sent message: address: a94630 kind: P name: ==)
SQLWarning:
13:18:38.451 (1) <=BE NoticeResponse(DEBUG: pool_use_sync_map: we cannot use sync map because STREAM: 0 query in progress: 1 doing extended query: 1)
SQLWarning:
13:18:38.451 (1) <=BE ParseComplete [null]
13:18:38.451 (1) <=BE NoticeResponse(DEBUG: SimpleForwardToFrontend: packet:1 length:0)
SQLWarning:
13:18:38.451 (1) <=BE NoticeResponse(DEBUG: session context: setting command success. DONE)
SQLWarning:
13:18:38.451 (1) <=BE NoticeResponse(DEBUG: pool_use_sync_map: we cannot use sync map because STREAM: 0 query in progress: 1 doing extended query: 1)
SQLWarning:
13:18:38.451 (1) <=BE NoticeResponse(DEBUG: reading backend data packet kind
  Detail: master node id: 0)
SQLWarning:

t-ishii

2016-07-15 16:37

developer   ~0000918

Can you show me pgpool.conf? It seems you are using pgpool-II in master slave mode (master_slave_mode = on, master_slave_sub_mode = 'slony'). I thought you are using in streaming replication mode (master_slave_mode = on, master_slave_sub_mode = 'stream').

zh1029

2016-07-20 18:56

reporter   ~0000923

It is 'slony' configured.

2016-07-20 17:44:34: pid 2581: DEBUG: key: pid_file_name
2016-07-20 17:44:34: pid 2581: LOCATION: pool_config.l:500
2016-07-20 17:44:34: pid 2581: DEBUG: value: '/var/run/pgpool/pgpool.pid' kind: 4
2016-07-20 17:44:34: pid 2581: LOCATION: pool_config.l:507
2016-07-20 17:44:34: pid 2581: DEBUG: key: logdir
2016-07-20 17:44:34: pid 2581: LOCATION: pool_config.l:500
2016-07-20 17:44:34: pid 2581: DEBUG: value: '/tmp' kind: 4
2016-07-20 17:44:34: pid 2581: LOCATION: pool_config.l:507
2016-07-20 17:44:34: pid 2581: DEBUG: key: connection_cache
2016-07-20 17:44:34: pid 2581: LOCATION: pool_config.l:500
2016-07-20 17:44:34: pid 2581: DEBUG: value: on kind: 1
2016-07-20 17:44:34: pid 2581: LOCATION: pool_config.l:507
2016-07-20 17:44:34: pid 2581: DEBUG: key: reset_query_list
2016-07-20 17:44:34: pid 2581: LOCATION: pool_config.l:500
2016-07-20 17:44:34: pid 2581: DEBUG: value: 'ABORT; DISCARD ALL' kind: 4
2016-07-20 17:44:34: pid 2581: LOCATION: pool_config.l:507
2016-07-20 17:44:34: pid 2581: DEBUG: initializing pool configuration
2016-07-20 17:44:34: pid 2581: DETAIL: extracting string tokens [token: ABORT]
2016-07-20 17:44:34: pid 2581: LOCATION: pool_config.l:3567
2016-07-20 17:44:34: pid 2581: DEBUG: initializing pool configuration
2016-07-20 17:44:34: pid 2581: DETAIL: extracting string tokens [token: DISCARD ALL]
2016-07-20 17:44:34: pid 2581: LOCATION: pool_config.l:3567
2016-07-20 17:44:34: pid 2581: DEBUG: key: replication_mode
2016-07-20 17:44:34: pid 2581: LOCATION: pool_config.l:500
2016-07-20 17:44:34: pid 2581: DEBUG: value: off kind: 1
2016-07-20 17:44:34: pid 2581: LOCATION: pool_config.l:507
2016-07-20 17:44:34: pid 2581: DEBUG: key: replicate_select
2016-07-20 17:44:34: pid 2581: LOCATION: pool_config.l:500
2016-07-20 17:44:34: pid 2581: DEBUG: value: off kind: 1
2016-07-20 17:44:34: pid 2581: LOCATION: pool_config.l:507
2016-07-20 17:44:34: pid 2581: DEBUG: initializing pool configuration
2016-07-20 17:44:34: pid 2581: DETAIL: replicate_select: 0
2016-07-20 17:44:34: pid 2581: LOCATION: pool_config.l:1029
2016-07-20 17:44:34: pid 2581: DEBUG: key: insert_lock
2016-07-20 17:44:34: pid 2581: LOCATION: pool_config.l:500
2016-07-20 17:44:34: pid 2581: DEBUG: value: off kind: 1
2016-07-20 17:44:34: pid 2581: LOCATION: pool_config.l:507
2016-07-20 17:44:34: pid 2581: DEBUG: key: lobj_lock_table
2016-07-20 17:44:34: pid 2581: LOCATION: pool_config.l:500
2016-07-20 17:44:34: pid 2581: DEBUG: value: '' kind: 4
2016-07-20 17:44:34: pid 2581: LOCATION: pool_config.l:507
2016-07-20 17:44:34: pid 2581: DEBUG: key: replication_stop_on_mismatch
2016-07-20 17:44:34: pid 2581: LOCATION: pool_config.l:500
2016-07-20 17:44:34: pid 2581: DEBUG: value: off kind: 1
2016-07-20 17:44:34: pid 2581: LOCATION: pool_config.l:507
2016-07-20 17:44:34: pid 2581: DEBUG: initializing pool configuration
2016-07-20 17:44:34: pid 2581: DETAIL: replication_stop_on_mismatch: 0
2016-07-20 17:44:34: pid 2581: LOCATION: pool_config.l:991
2016-07-20 17:44:34: pid 2581: DEBUG: key: failover_if_affected_tuples_mismatch
2016-07-20 17:44:34: pid 2581: LOCATION: pool_config.l:500
2016-07-20 17:44:34: pid 2581: DEBUG: value: off kind: 1
2016-07-20 17:44:34: pid 2581: LOCATION: pool_config.l:507
2016-07-20 17:44:34: pid 2581: DEBUG: initializing pool configuration
2016-07-20 17:44:34: pid 2581: DETAIL: failover_if_affected_tuples_mismatch: 0
2016-07-20 17:44:34: pid 2581: LOCATION: pool_config.l:1010
2016-07-20 17:44:34: pid 2581: DEBUG: key: load_balance_mode
2016-07-20 17:44:34: pid 2581: LOCATION: pool_config.l:500
2016-07-20 17:44:34: pid 2581: DEBUG: value: on kind: 1
2016-07-20 17:44:34: pid 2581: LOCATION: pool_config.l:507
2016-07-20 17:44:34: pid 2581: DEBUG: key: ignore_leading_white_space
2016-07-20 17:44:34: pid 2581: LOCATION: pool_config.l:500
2016-07-20 17:44:34: pid 2581: DEBUG: value: on kind: 1
2016-07-20 17:44:34: pid 2581: LOCATION: pool_config.l:507
2016-07-20 17:44:34: pid 2581: DEBUG: key: white_function_list
2016-07-20 17:44:34: pid 2581: LOCATION: pool_config.l:500
2016-07-20 17:44:34: pid 2581: DEBUG: value: '' kind: 4
2016-07-20 17:44:34: pid 2581: LOCATION: pool_config.l:507
2016-07-20 17:44:34: pid 2581: DEBUG: key: black_function_list
2016-07-20 17:44:34: pid 2581: LOCATION: pool_config.l:500
2016-07-20 17:44:34: pid 2581: DEBUG: value: 'currval,lastval,nextval,setval' kind: 4
2016-07-20 17:44:34: pid 2581: LOCATION: pool_config.l:507
2016-07-20 17:44:34: pid 2581: DEBUG: initializing pool configuration
2016-07-20 17:44:34: pid 2581: DETAIL: extracting string tokens [token: currval]
2016-07-20 17:44:34: pid 2581: LOCATION: pool_config.l:3567
2016-07-20 17:44:34: pid 2581: DEBUG: initializing pool configuration
2016-07-20 17:44:34: pid 2581: DETAIL: extracting string tokens [token: lastval]
2016-07-20 17:44:34: pid 2581: LOCATION: pool_config.l:3567
2016-07-20 17:44:34: pid 2581: DEBUG: initializing pool configuration
2016-07-20 17:44:34: pid 2581: DETAIL: extracting string tokens [token: nextval]
2016-07-20 17:44:34: pid 2581: LOCATION: pool_config.l:3567
2016-07-20 17:44:34: pid 2581: DEBUG: initializing pool configuration
2016-07-20 17:44:34: pid 2581: DETAIL: extracting string tokens [token: setval]
2016-07-20 17:44:34: pid 2581: LOCATION: pool_config.l:3567
2016-07-20 17:44:34: pid 2581: DEBUG: initializing pool configuration
2016-07-20 17:44:34: pid 2581: DETAIL: adding regex pattern for "black_function_list" pattern: ^currval$
2016-07-20 17:44:34: pid 2581: LOCATION: pool_config.l:362
2016-07-20 17:44:34: pid 2581: DEBUG: initializing pool configuration
2016-07-20 17:44:34: pid 2581: DETAIL: adding regex pattern for "black_function_list" pattern: ^lastval$
2016-07-20 17:44:34: pid 2581: LOCATION: pool_config.l:362
2016-07-20 17:44:34: pid 2581: DEBUG: initializing pool configuration
2016-07-20 17:44:34: pid 2581: DETAIL: adding regex pattern for "black_function_list" pattern: ^nextval$
2016-07-20 17:44:34: pid 2581: LOCATION: pool_config.l:362
2016-07-20 17:44:34: pid 2581: DEBUG: initializing pool configuration
2016-07-20 17:44:34: pid 2581: DETAIL: adding regex pattern for "black_function_list" pattern: ^setval$
2016-07-20 17:44:34: pid 2581: LOCATION: pool_config.l:362
2016-07-20 17:44:34: pid 2581: DEBUG: key: database_redirect_preference_list
2016-07-20 17:44:34: pid 2581: LOCATION: pool_config.l:500
2016-07-20 17:44:34: pid 2581: DEBUG: value: '' kind: 4
2016-07-20 17:44:34: pid 2581: LOCATION: pool_config.l:507
2016-07-20 17:44:34: pid 2581: DEBUG: key: app_name_redirect_preference_list
2016-07-20 17:44:34: pid 2581: LOCATION: pool_config.l:500
2016-07-20 17:44:34: pid 2581: DEBUG: value: '' kind: 4
2016-07-20 17:44:34: pid 2581: LOCATION: pool_config.l:507
2016-07-20 17:44:34: pid 2581: DEBUG: key: allow_sql_comments
2016-07-20 17:44:34: pid 2581: LOCATION: pool_config.l:500
2016-07-20 17:44:34: pid 2581: DEBUG: value: off kind: 1
2016-07-20 17:44:34: pid 2581: LOCATION: pool_config.l:507
2016-07-20 17:44:34: pid 2581: DEBUG: key: master_slave_mode
2016-07-20 17:44:34: pid 2581: LOCATION: pool_config.l:500
2016-07-20 17:44:34: pid 2581: DEBUG: value: on kind: 1
2016-07-20 17:44:34: pid 2581: LOCATION: pool_config.l:507
2016-07-20 17:44:34: pid 2581: DEBUG: key: master_slave_sub_mode
2016-07-20 17:44:34: pid 2581: LOCATION: pool_config.l:500
2016-07-20 17:44:34: pid 2581: DEBUG: value: 'slony' kind: 4
2016-07-20 17:44:34: pid 2581: LOCATION: pool_config.l:507
2016-07-20 17:44:34: pid 2581: DEBUG: key: sr_check_period
2016-07-20 17:44:34: pid 2581: LOCATION: pool_config.l:500
2016-07-20 17:44:34: pid 2581: DEBUG: value: 0 kind: 2
2016-07-20 17:44:34: pid 2581: LOCATION: pool_config.l:507
2016-07-20 17:44:34: pid 2581: DEBUG: key: sr_check_user
2016-07-20 17:44:34: pid 2581: LOCATION: pool_config.l:500
2016-07-20 17:44:34: pid 2581: DEBUG: value: 'nobody' kind: 4
2016-07-20 17:44:34: pid 2581: LOCATION: pool_config.l:507
2016-07-20 17:44:34: pid 2581: DEBUG: key: sr_check_password
2016-07-20 17:44:34: pid 2581: LOCATION: pool_config.l:500
2016-07-20 17:44:34: pid 2581: DEBUG: value: '' kind: 4
2016-07-20 17:44:34: pid 2581: LOCATION: pool_config.l:507
2016-07-20 17:44:34: pid 2581: DEBUG: key: sr_check_database
2016-07-20 17:44:34: pid 2581: LOCATION: pool_config.l:500
2016-07-20 17:44:34: pid 2581: DEBUG: value: 'postgres' kind: 4
2016-07-20 17:44:34: pid 2581: LOCATION: pool_config.l:507
2016-07-20 17:44:34: pid 2581: DEBUG: key: delay_threshold
2016-07-20 17:44:34: pid 2581: LOCATION: pool_config.l:500
2016-07-20 17:44:34: pid 2581: DEBUG: value: 0 kind: 2
2016-07-20 17:44:34: pid 2581: LOCATION: pool_config.l:507
2016-07-20 17:44:34: pid 2581: DEBUG: key: follow_master_command
2016-07-20 17:44:34: pid 2581: LOCATION: pool_config.l:500
2016-07-20 17:44:34: pid 2581: DEBUG: value: '' kind: 4
2016-07-20 17:44:34: pid 2581: LOCATION: pool_config.l:507
2016-07-20 17:44:34: pid 2581: DEBUG: key: health_check_period
2016-07-20 17:44:34: pid 2581: LOCATION: pool_config.l:500
2016-07-20 17:44:34: pid 2581: DEBUG: value: 0 kind: 2
2016-07-20 17:44:34: pid 2581: LOCATION: pool_config.l:507
2016-07-20 17:44:34: pid 2581: DEBUG: key: health_check_timeout
2016-07-20 17:44:34: pid 2581: LOCATION: pool_config.l:500
2016-07-20 17:44:34: pid 2581: DEBUG: value: 20 kind: 2
2016-07-20 17:44:34: pid 2581: LOCATION: pool_config.l:507
2016-07-20 17:44:34: pid 2581: DEBUG: key: health_check_user
2016-07-20 17:44:34: pid 2581: LOCATION: pool_config.l:500
2016-07-20 17:44:34: pid 2581: DEBUG: value: 'nobody' kind: 4
2016-07-20 17:44:34: pid 2581: LOCATION: pool_config.l:507
2016-07-20 17:44:34: pid 2581: DEBUG: key: health_check_password
2016-07-20 17:44:34: pid 2581: LOCATION: pool_config.l:500
2016-07-20 17:44:34: pid 2581: DEBUG: value: '' kind: 4
2016-07-20 17:44:34: pid 2581: LOCATION: pool_config.l:507
2016-07-20 17:44:34: pid 2581: DEBUG: key: health_check_database
2016-07-20 17:44:34: pid 2581: LOCATION: pool_config.l:500
2016-07-20 17:44:34: pid 2581: DEBUG: value: '' kind: 4
2016-07-20 17:44:34: pid 2581: LOCATION: pool_config.l:507
2016-07-20 17:44:34: pid 2581: DEBUG: key: health_check_max_retries
2016-07-20 17:44:34: pid 2581: LOCATION: pool_config.l:500
2016-07-20 17:44:34: pid 2581: DEBUG: value: 0 kind: 2
2016-07-20 17:44:34: pid 2581: LOCATION: pool_config.l:507
2016-07-20 17:44:34: pid 2581: DEBUG: key: health_check_retry_delay
2016-07-20 17:44:34: pid 2581: LOCATION: pool_config.l:500
2016-07-20 17:44:34: pid 2581: DEBUG: value: 1 kind: 2
2016-07-20 17:44:34: pid 2581: LOCATION: pool_config.l:507
2016-07-20 17:44:34: pid 2581: DEBUG: key: connect_timeout
2016-07-20 17:44:34: pid 2581: LOCATION: pool_config.l:500
2016-07-20 17:44:34: pid 2581: DEBUG: value: 10000 kind: 2
2016-07-20 17:44:34: pid 2581: LOCATION: pool_config.l:507
2016-07-20 17:44:34: pid 2581: DEBUG: key: failover_command
2016-07-20 17:44:34: pid 2581: LOCATION: pool_config.l:500
2016-07-20 17:44:34: pid 2581: DEBUG: value: '' kind: 4
2016-07-20 17:44:34: pid 2581: LOCATION: pool_config.l:507
2016-07-20 17:44:34: pid 2581: DEBUG: key: failback_command
2016-07-20 17:44:34: pid 2581: LOCATION: pool_config.l:500
2016-07-20 17:44:34: pid 2581: DEBUG: value: '' kind: 4
2016-07-20 17:44:34: pid 2581: LOCATION: pool_config.l:507
2016-07-20 17:44:34: pid 2581: DEBUG: key: fail_over_on_backend_error
2016-07-20 17:44:34: pid 2581: LOCATION: pool_config.l:500
2016-07-20 17:44:34: pid 2581: DEBUG: value: on kind: 1
2016-07-20 17:44:34: pid 2581: LOCATION: pool_config.l:507
2016-07-20 17:44:34: pid 2581: DEBUG: key: search_primary_node_timeout
2016-07-20 17:44:34: pid 2581: LOCATION: pool_config.l:500
2016-07-20 17:44:34: pid 2581: DEBUG: value: 10 kind: 2
2016-07-20 17:44:34: pid 2581: LOCATION: pool_config.l:507
2016-07-20 17:44:34: pid 2581: DEBUG: key: recovery_user
2016-07-20 17:44:34: pid 2581: LOCATION: pool_config.l:500
2016-07-20 17:44:34: pid 2581: DEBUG: value: 'nobody' kind: 4
2016-07-20 17:44:34: pid 2581: LOCATION: pool_config.l:507
2016-07-20 17:44:34: pid 2581: DEBUG: key: recovery_password
2016-07-20 17:44:34: pid 2581: LOCATION: pool_config.l:500
2016-07-20 17:44:34: pid 2581: DEBUG: value: '' kind: 4
2016-07-20 17:44:34: pid 2581: LOCATION: pool_config.l:507
2016-07-20 17:44:34: pid 2581: DEBUG: key: recovery_1st_stage_command
2016-07-20 17:44:34: pid 2581: LOCATION: pool_config.l:500
2016-07-20 17:44:34: pid 2581: DEBUG: value: '' kind: 4
2016-07-20 17:44:34: pid 2581: LOCATION: pool_config.l:507
2016-07-20 17:44:34: pid 2581: DEBUG: key: recovery_2nd_stage_command
2016-07-20 17:44:34: pid 2581: LOCATION: pool_config.l:500
2016-07-20 17:44:34: pid 2581: DEBUG: value: '' kind: 4
2016-07-20 17:44:34: pid 2581: LOCATION: pool_config.l:507
2016-07-20 17:44:34: pid 2581: DEBUG: key: recovery_timeout
2016-07-20 17:44:34: pid 2581: LOCATION: pool_config.l:500
2016-07-20 17:44:34: pid 2581: DEBUG: value: 90 kind: 2
2016-07-20 17:44:34: pid 2581: LOCATION: pool_config.l:507
2016-07-20 17:44:34: pid 2581: DEBUG: key: client_idle_limit_in_recovery
2016-07-20 17:44:34: pid 2581: LOCATION: pool_config.l:500
2016-07-20 17:44:34: pid 2581: DEBUG: value: 0 kind: 2
2016-07-20 17:44:34: pid 2581: LOCATION: pool_config.l:507
2016-07-20 17:44:34: pid 2581: DEBUG: key: use_watchdog
2016-07-20 17:44:34: pid 2581: LOCATION: pool_config.l:500
2016-07-20 17:44:34: pid 2581: DEBUG: value: off kind: 1
2016-07-20 17:44:34: pid 2581: LOCATION: pool_config.l:507
2016-07-20 17:44:34: pid 2581: DEBUG: key: trusted_servers
2016-07-20 17:44:34: pid 2581: LOCATION: pool_config.l:500
2016-07-20 17:44:34: pid 2581: DEBUG: value: '' kind: 4
2016-07-20 17:44:34: pid 2581: LOCATION: pool_config.l:507
2016-07-20 17:44:34: pid 2581: DEBUG: key: ping_path
2016-07-20 17:44:34: pid 2581: LOCATION: pool_config.l:500
2016-07-20 17:44:34: pid 2581: DEBUG: value: '/bin' kind: 4
2016-07-20 17:44:34: pid 2581: LOCATION: pool_config.l:507
2016-07-20 17:44:34: pid 2581: DEBUG: key: wd_hostname
2016-07-20 17:44:34: pid 2581: LOCATION: pool_config.l:500
2016-07-20 17:44:34: pid 2581: DEBUG: value: '' kind: 4
2016-07-20 17:44:34: pid 2581: LOCATION: pool_config.l:507
2016-07-20 17:44:34: pid 2581: DEBUG: key: wd_port
2016-07-20 17:44:34: pid 2581: LOCATION: pool_config.l:500
2016-07-20 17:44:34: pid 2581: DEBUG: value: 9000 kind: 2
2016-07-20 17:44:34: pid 2581: LOCATION: pool_config.l:507
2016-07-20 17:44:34: pid 2581: DEBUG: key: wd_priority
2016-07-20 17:44:34: pid 2581: LOCATION: pool_config.l:500
2016-07-20 17:44:34: pid 2581: DEBUG: value: 1 kind: 2
2016-07-20 17:44:34: pid 2581: LOCATION: pool_config.l:507
2016-07-20 17:44:34: pid 2581: DEBUG: key: wd_authkey
2016-07-20 17:44:34: pid 2581: LOCATION: pool_config.l:500
2016-07-20 17:44:34: pid 2581: DEBUG: value: '' kind: 4
2016-07-20 17:44:34: pid 2581: LOCATION: pool_config.l:507
2016-07-20 17:44:34: pid 2581: DEBUG: key: wd_ipc_socket_dir
2016-07-20 17:44:34: pid 2581: LOCATION: pool_config.l:500
2016-07-20 17:44:34: pid 2581: DEBUG: value: '/tmp' kind: 4
2016-07-20 17:44:34: pid 2581: LOCATION: pool_config.l:507
2016-07-20 17:44:34: pid 2581: DEBUG: key: delegate_IP
2016-07-20 17:44:34: pid 2581: LOCATION: pool_config.l:500
2016-07-20 17:44:34: pid 2581: DEBUG: value: '' kind: 4
2016-07-20 17:44:34: pid 2581: LOCATION: pool_config.l:507
2016-07-20 17:44:34: pid 2581: DEBUG: key: if_cmd_path
2016-07-20 17:44:34: pid 2581: LOCATION: pool_config.l:500
2016-07-20 17:44:34: pid 2581: DEBUG: value: '/sbin' kind: 4
2016-07-20 17:44:34: pid 2581: LOCATION: pool_config.l:507
2016-07-20 17:44:34: pid 2581: DEBUG: key: if_up_cmd
2016-07-20 17:44:34: pid 2581: LOCATION: pool_config.l:500
2016-07-20 17:44:34: pid 2581: DEBUG: value: 'ip addr add $_IP_$/24 dev eth0 label eth0:0' kind: 4
2016-07-20 17:44:34: pid 2581: LOCATION: pool_config.l:507
2016-07-20 17:44:34: pid 2581: DEBUG: key: if_down_cmd
2016-07-20 17:44:34: pid 2581: LOCATION: pool_config.l:500
2016-07-20 17:44:34: pid 2581: DEBUG: value: 'ip addr del $_IP_$/24 dev eth0' kind: 4
2016-07-20 17:44:34: pid 2581: LOCATION: pool_config.l:507
2016-07-20 17:44:34: pid 2581: DEBUG: key: arping_path
2016-07-20 17:44:34: pid 2581: LOCATION: pool_config.l:500
2016-07-20 17:44:34: pid 2581: DEBUG: value: '/usr/sbin' kind: 4
2016-07-20 17:44:34: pid 2581: LOCATION: pool_config.l:507
2016-07-20 17:44:34: pid 2581: DEBUG: key: arping_cmd
2016-07-20 17:44:34: pid 2581: LOCATION: pool_config.l:500
2016-07-20 17:44:34: pid 2581: DEBUG: value: 'arping -U $_IP_$ -w 1' kind: 4
2016-07-20 17:44:34: pid 2581: LOCATION: pool_config.l:507
2016-07-20 17:44:34: pid 2581: DEBUG: key: clear_memqcache_on_escalation
2016-07-20 17:44:34: pid 2581: LOCATION: pool_config.l:500
2016-07-20 17:44:34: pid 2581: DEBUG: value: on kind: 1
2016-07-20 17:44:34: pid 2581: LOCATION: pool_config.l:507
2016-07-20 17:44:34: pid 2581: DEBUG: key: wd_escalation_command
2016-07-20 17:44:34: pid 2581: LOCATION: pool_config.l:500
2016-07-20 17:44:34: pid 2581: DEBUG: value: '' kind: 4
2016-07-20 17:44:34: pid 2581: LOCATION: pool_config.l:507
2016-07-20 17:44:34: pid 2581: DEBUG: key: wd_de_escalation_command
2016-07-20 17:44:34: pid 2581: LOCATION: pool_config.l:500
2016-07-20 17:44:34: pid 2581: DEBUG: value: '' kind: 4
2016-07-20 17:44:34: pid 2581: LOCATION: pool_config.l:507
2016-07-20 17:44:34: pid 2581: DEBUG: key: wd_monitoring_interfaces_list
2016-07-20 17:44:34: pid 2581: LOCATION: pool_config.l:500
2016-07-20 17:44:34: pid 2581: DEBUG: value: '' kind: 4
2016-07-20 17:44:34: pid 2581: LOCATION: pool_config.l:507
2016-07-20 17:44:34: pid 2581: DEBUG: key: wd_lifecheck_method
2016-07-20 17:44:34: pid 2581: LOCATION: pool_config.l:500
2016-07-20 17:44:34: pid 2581: DEBUG: value: 'heartbeat' kind: 4
2016-07-20 17:44:34: pid 2581: LOCATION: pool_config.l:507
2016-07-20 17:44:34: pid 2581: DEBUG: key: wd_interval
2016-07-20 17:44:34: pid 2581: LOCATION: pool_config.l:500
2016-07-20 17:44:34: pid 2581: DEBUG: value: 10 kind: 2
2016-07-20 17:44:34: pid 2581: LOCATION: pool_config.l:507
2016-07-20 17:44:34: pid 2581: DEBUG: key: wd_heartbeat_port
2016-07-20 17:44:34: pid 2581: LOCATION: pool_config.l:500
2016-07-20 17:44:34: pid 2581: DEBUG: value: 9694 kind: 2
2016-07-20 17:44:34: pid 2581: LOCATION: pool_config.l:507
2016-07-20 17:44:34: pid 2581: DEBUG: key: wd_heartbeat_keepalive
2016-07-20 17:44:34: pid 2581: LOCATION: pool_config.l:500
2016-07-20 17:44:34: pid 2581: DEBUG: value: 2 kind: 2
2016-07-20 17:44:34: pid 2581: LOCATION: pool_config.l:507
2016-07-20 17:44:34: pid 2581: DEBUG: key: wd_heartbeat_deadtime
2016-07-20 17:44:34: pid 2581: LOCATION: pool_config.l:500
2016-07-20 17:44:34: pid 2581: DEBUG: value: 30 kind: 2
2016-07-20 17:44:34: pid 2581: LOCATION: pool_config.l:507
2016-07-20 17:44:34: pid 2581: DEBUG: key: heartbeat_destination0
2016-07-20 17:44:34: pid 2581: LOCATION: pool_config.l:500
2016-07-20 17:44:34: pid 2581: DEBUG: value: 'host0_ip1' kind: 4
2016-07-20 17:44:34: pid 2581: LOCATION: pool_config.l:507
2016-07-20 17:44:34: pid 2581: DEBUG: key: heartbeat_destination_port0
2016-07-20 17:44:34: pid 2581: LOCATION: pool_config.l:500
2016-07-20 17:44:34: pid 2581: DEBUG: value: 9694 kind: 2
2016-07-20 17:44:34: pid 2581: LOCATION: pool_config.l:507
2016-07-20 17:44:34: pid 2581: DEBUG: key: heartbeat_device0
2016-07-20 17:44:34: pid 2581: LOCATION: pool_config.l:500
2016-07-20 17:44:34: pid 2581: DEBUG: value: '' kind: 4
2016-07-20 17:44:34: pid 2581: LOCATION: pool_config.l:507
2016-07-20 17:44:34: pid 2581: DEBUG: key: wd_life_point
2016-07-20 17:44:34: pid 2581: LOCATION: pool_config.l:500
2016-07-20 17:44:34: pid 2581: DEBUG: value: 3 kind: 2
2016-07-20 17:44:34: pid 2581: LOCATION: pool_config.l:507
2016-07-20 17:44:34: pid 2581: DEBUG: key: wd_lifecheck_query
2016-07-20 17:44:34: pid 2581: LOCATION: pool_config.l:500
2016-07-20 17:44:34: pid 2581: DEBUG: value: 'SELECT 1' kind: 4
2016-07-20 17:44:34: pid 2581: LOCATION: pool_config.l:507
2016-07-20 17:44:34: pid 2581: DEBUG: key: wd_lifecheck_dbname
2016-07-20 17:44:34: pid 2581: LOCATION: pool_config.l:500
2016-07-20 17:44:34: pid 2581: DEBUG: value: 'template1' kind: 4
2016-07-20 17:44:34: pid 2581: LOCATION: pool_config.l:507
2016-07-20 17:44:34: pid 2581: DEBUG: key: wd_lifecheck_user
2016-07-20 17:44:34: pid 2581: LOCATION: pool_config.l:500
2016-07-20 17:44:34: pid 2581: DEBUG: value: 'nobody' kind: 4
2016-07-20 17:44:34: pid 2581: LOCATION: pool_config.l:507
2016-07-20 17:44:34: pid 2581: DEBUG: key: wd_lifecheck_password
2016-07-20 17:44:34: pid 2581: LOCATION: pool_config.l:500
2016-07-20 17:44:34: pid 2581: DEBUG: value: '' kind: 4
2016-07-20 17:44:34: pid 2581: LOCATION: pool_config.l:507
2016-07-20 17:44:34: pid 2581: DEBUG: key: relcache_expire
2016-07-20 17:44:34: pid 2581: LOCATION: pool_config.l:500
2016-07-20 17:44:34: pid 2581: DEBUG: value: 0 kind: 2
2016-07-20 17:44:34: pid 2581: LOCATION: pool_config.l:507
2016-07-20 17:44:34: pid 2581: DEBUG: key: relcache_size
2016-07-20 17:44:34: pid 2581: LOCATION: pool_config.l:500
2016-07-20 17:44:34: pid 2581: DEBUG: value: 256 kind: 2
2016-07-20 17:44:34: pid 2581: LOCATION: pool_config.l:507
2016-07-20 17:44:34: pid 2581: DEBUG: key: check_temp_table
2016-07-20 17:44:34: pid 2581: LOCATION: pool_config.l:500
2016-07-20 17:44:34: pid 2581: DEBUG: value: on kind: 1
2016-07-20 17:44:34: pid 2581: LOCATION: pool_config.l:507
2016-07-20 17:44:34: pid 2581: DEBUG: key: check_unlogged_table
2016-07-20 17:44:34: pid 2581: LOCATION: pool_config.l:500
2016-07-20 17:44:34: pid 2581: DEBUG: value: on kind: 1
2016-07-20 17:44:34: pid 2581: LOCATION: pool_config.l:507
2016-07-20 17:44:34: pid 2581: DEBUG: key: memory_cache_enabled
2016-07-20 17:44:34: pid 2581: LOCATION: pool_config.l:500
2016-07-20 17:44:34: pid 2581: DEBUG: value: off kind: 1
2016-07-20 17:44:34: pid 2581: LOCATION: pool_config.l:507
2016-07-20 17:44:34: pid 2581: DEBUG: key: memqcache_method
2016-07-20 17:44:34: pid 2581: LOCATION: pool_config.l:500
2016-07-20 17:44:34: pid 2581: DEBUG: value: 'shmem' kind: 4
2016-07-20 17:44:34: pid 2581: LOCATION: pool_config.l:507
2016-07-20 17:44:34: pid 2581: DEBUG: key: memqcache_memcached_host
2016-07-20 17:44:34: pid 2581: LOCATION: pool_config.l:500
2016-07-20 17:44:34: pid 2581: DEBUG: value: 'localhost' kind: 4
2016-07-20 17:44:34: pid 2581: LOCATION: pool_config.l:507
2016-07-20 17:44:34: pid 2581: DEBUG: key: memqcache_memcached_port
2016-07-20 17:44:34: pid 2581: LOCATION: pool_config.l:500
2016-07-20 17:44:34: pid 2581: DEBUG: value: 11211 kind: 2
2016-07-20 17:44:34: pid 2581: LOCATION: pool_config.l:507
2016-07-20 17:44:34: pid 2581: DEBUG: key: memqcache_total_size
2016-07-20 17:44:34: pid 2581: LOCATION: pool_config.l:500
2016-07-20 17:44:34: pid 2581: DEBUG: value: 67108864 kind: 2
2016-07-20 17:44:34: pid 2581: LOCATION: pool_config.l:507
2016-07-20 17:44:34: pid 2581: DEBUG: key: memqcache_max_num_cache
2016-07-20 17:44:34: pid 2581: LOCATION: pool_config.l:500
2016-07-20 17:44:34: pid 2581: DEBUG: value: 1000000 kind: 2
2016-07-20 17:44:34: pid 2581: LOCATION: pool_config.l:507
2016-07-20 17:44:34: pid 2581: DEBUG: key: memqcache_expire
2016-07-20 17:44:34: pid 2581: LOCATION: pool_config.l:500
2016-07-20 17:44:34: pid 2581: DEBUG: value: 0 kind: 2
2016-07-20 17:44:34: pid 2581: LOCATION: pool_config.l:507
2016-07-20 17:44:34: pid 2581: DEBUG: key: memqcache_auto_cache_invalidation
2016-07-20 17:44:34: pid 2581: LOCATION: pool_config.l:500
2016-07-20 17:44:34: pid 2581: DEBUG: value: on kind: 1
2016-07-20 17:44:34: pid 2581: LOCATION: pool_config.l:507
2016-07-20 17:44:34: pid 2581: DEBUG: key: memqcache_maxcache
2016-07-20 17:44:34: pid 2581: LOCATION: pool_config.l:500
2016-07-20 17:44:34: pid 2581: DEBUG: value: 409600 kind: 2
2016-07-20 17:44:34: pid 2581: LOCATION: pool_config.l:507
2016-07-20 17:44:34: pid 2581: DEBUG: key: memqcache_cache_block_size
2016-07-20 17:44:34: pid 2581: LOCATION: pool_config.l:500
2016-07-20 17:44:34: pid 2581: DEBUG: value: 1048576 kind: 2
2016-07-20 17:44:34: pid 2581: LOCATION: pool_config.l:507
2016-07-20 17:44:34: pid 2581: DEBUG: key: memqcache_oiddir
2016-07-20 17:44:34: pid 2581: LOCATION: pool_config.l:500
2016-07-20 17:44:34: pid 2581: DEBUG: value: '/var/log/pgpool/oiddir' kind: 4
2016-07-20 17:44:34: pid 2581: LOCATION: pool_config.l:507
2016-07-20 17:44:34: pid 2581: DEBUG: key: white_memqcache_table_list
2016-07-20 17:44:34: pid 2581: LOCATION: pool_config.l:500
2016-07-20 17:44:34: pid 2581: DEBUG: value: '' kind: 4
2016-07-20 17:44:34: pid 2581: LOCATION: pool_config.l:507
2016-07-20 17:44:34: pid 2581: DEBUG: key: black_memqcache_table_list
2016-07-20 17:44:34: pid 2581: LOCATION: pool_config.l:500
2016-07-20 17:44:34: pid 2581: DEBUG: value: '' kind: 4
2016-07-20 17:44:34: pid 2581: LOCATION: pool_config.l:507
2016-07-20 17:44:34: pid 2581: DEBUG: initializing pool configuration
2016-07-20 17:44:34: pid 2581: DETAIL: num_backends: 4 total_weight: 4.000000
2016-07-20 17:44:34: pid 2581: LOCATION: pool_config.l:3394
2016-07-20 17:44:34: pid 2581: DEBUG: initializing pool configuration
2016-07-20 17:44:34: pid 2581: DETAIL: backend 0 weight: 536870911.750000 flag: 0000
2016-07-20 17:44:34: pid 2581: LOCATION: pool_config.l:3413
2016-07-20 17:44:34: pid 2581: DEBUG: initializing pool configuration
2016-07-20 17:44:34: pid 2581: DETAIL: backend 1 weight: 536870911.750000 flag: 0000
2016-07-20 17:44:34: pid 2581: LOCATION: pool_config.l:3413
2016-07-20 17:44:34: pid 2581: DEBUG: initializing pool configuration
2016-07-20 17:44:34: pid 2581: DETAIL: backend 2 weight: 536870911.750000 flag: 0000
2016-07-20 17:44:34: pid 2581: LOCATION: pool_config.l:3413
2016-07-20 17:44:34: pid 2581: DEBUG: initializing pool configuration
2016-07-20 17:44:34: pid 2581: DETAIL: backend 3 weight: 536870911.750000 flag: 0000
2016-07-20 17:44:34: pid 2581: LOCATION: pool_config.l:3413
2016-07-20 17:44:34: pid 2581: DEBUG: shmem_exit(-1): 2 callbacks to make
2016-07-20 17:44:34: pid 2581: LOCATION: elog.c:2563
2016-07-20 17:44:34: pid 2581: DEBUG: proc_exit(-1): 0 callbacks to make
2016-07-20 17:44:34: pid 2581: LOCATION: elog.c:2535

pgpool.conf.master-slave (34,815 bytes)

zh1029

2016-07-20 18:57

reporter  

pgpool.conf-2.master-slave (34,815 bytes)

t-ishii

2016-07-20 22:10

developer   ~0000924

Ok, your fix makes sense then. From pgpool-II 3.5, streaming replication mode is treated specially to enhance performance. "REPLICATION||RAW_MODE" was intended to match other than streaming replication mode, but forgot to think about slony. Proper fix would be replacing "REPLICATION || RAW_MODE" with "!STREAM". Please try attached diff.

t-ishii

2016-07-20 22:11

developer  

pool_proto_module.diff (2,273 bytes)
diff --git a/src/protocol/pool_proto_modules.c b/src/protocol/pool_proto_modules.c
index 6eb7716..87955b2 100644
--- a/src/protocol/pool_proto_modules.c
+++ b/src/protocol/pool_proto_modules.c
@@ -2450,21 +2450,21 @@ POOL_STATUS ProcessBackendResponse(POOL_CONNECTION *frontend,
 			case '1':	/* ParseComplete */
 				status = ParseComplete(frontend, backend);
 				pool_set_command_success();
-				if (REPLICATION||RAW_MODE)
+				if (!STREAM)
 					pool_unset_query_in_progress();
 				break;
 
 			case '2':	/* BindComplete */
 				status = BindComplete(frontend, backend);
 				pool_set_command_success();
-				if (REPLICATION||RAW_MODE)
+				if (!STREAM)
 					pool_unset_query_in_progress();
 				break;
 
 			case '3':	/* CloseComplete */
 				status = CloseComplete(frontend, backend);
 				pool_set_command_success();
-				if (REPLICATION||RAW_MODE)
+				if (!STREAM)
 					pool_unset_query_in_progress();
 				break;
 
@@ -2484,7 +2484,7 @@ POOL_STATUS ProcessBackendResponse(POOL_CONNECTION *frontend,
 			case 'C':	/* CommandComplete */				
 				status = CommandComplete(frontend, backend);
 				pool_set_command_success();
-				if ((REPLICATION || RAW_MODE) && pool_is_doing_extended_query_message())
+				if (!STREAM && pool_is_doing_extended_query_message())
 					pool_unset_query_in_progress();
 				break;
 
@@ -2506,19 +2506,19 @@ POOL_STATUS ProcessBackendResponse(POOL_CONNECTION *frontend,
 
 			case 'T':	/* RowDescription */
 				status = SimpleForwardToFrontend(kind, frontend, backend);
-				if ((REPLICATION || RAW_MODE) && pool_is_doing_extended_query_message())
+				if (!STREAM && pool_is_doing_extended_query_message())
 					pool_unset_query_in_progress();
 				break;
 
 			case 'n':	/* NoData */
 				status = SimpleForwardToFrontend(kind, frontend, backend);
-				if ((REPLICATION || RAW_MODE) && pool_is_doing_extended_query_message())
+				if (!STREAM && pool_is_doing_extended_query_message())
 					pool_unset_query_in_progress();
 				break;
 
 			case 's':	/* PortalSuspended */
 				status = SimpleForwardToFrontend(kind, frontend, backend);
-				if ((REPLICATION || RAW_MODE) && pool_is_doing_extended_query_message())
+				if (!STREAM && pool_is_doing_extended_query_message())
 					pool_unset_query_in_progress();
 				break;
 
pool_proto_module.diff (2,273 bytes)

zh1029

2016-07-23 21:50

reporter   ~0000927

what's the different functionality of master_slave_sub_mode configured as 'slony' and 'stream'? According to my testing.
case 'n' will stuck at receving slave backend response with this change.
not sure for case 'T' and case 's' as testing doesn't cover both cases.


BTW, would it be better below function return false instead of return true?

/*
 * Returns true if the DB node is needed to send query.
 * Intended to be called from VALID_BACKEND
 */
bool pool_is_node_to_be_sent_in_current_query(int node_id)
{
    POOL_SESSION_CONTEXT *sc;

    if (RAW_MODE)
        return node_id == REAL_MASTER_NODE_ID;

    sc = pool_get_session_context(true);
    if (!sc)
        return true;

    if (pool_is_query_in_progress() && sc->query_context)
    {
        return pool_is_node_to_be_sent(sc->query_context, node_id);
    }

    return true;
}

t-ishii

2016-08-10 18:11

developer   ~0000978

With 'slony', it is assumed that Slony is used. With 'stream', it is assumed that PostgreSQL's streaming replication is assumed.

Can you please show me pgpool log or JDBC log after patching?

t-ishii

2016-09-28 10:32

developer   ~0001099

No feedback over 2 months from the reporter. Issue closed.

Issue History

Date Modified Username Field Change
2016-06-28 18:34 zh1029 New Issue
2016-07-04 11:00 t-ishii Note Added: 0000880
2016-07-04 11:00 t-ishii Assigned To => t-ishii
2016-07-04 11:00 t-ishii Status new => assigned
2016-07-04 11:00 t-ishii Status assigned => feedback
2016-07-15 14:04 zh1029 Note Added: 0000914
2016-07-15 14:04 zh1029 Status feedback => assigned
2016-07-15 14:21 zh1029 Note Added: 0000916
2016-07-15 16:37 t-ishii Note Added: 0000918
2016-07-15 21:01 t-ishii Status assigned => feedback
2016-07-20 18:56 zh1029 File Added: pgpool.conf.master-slave
2016-07-20 18:56 zh1029 Note Added: 0000923
2016-07-20 18:56 zh1029 Status feedback => assigned
2016-07-20 18:57 zh1029 File Added: pgpool.conf-2.master-slave
2016-07-20 22:10 t-ishii Note Added: 0000924
2016-07-20 22:11 t-ishii File Added: pool_proto_module.diff
2016-07-23 21:50 zh1029 Note Added: 0000927
2016-08-10 17:17 t-ishii Product Version => 3.5.2
2016-08-10 18:11 t-ishii Note Added: 0000978
2016-08-10 18:12 t-ishii Status assigned => feedback
2016-09-28 10:32 t-ishii Note Added: 0001099
2016-09-28 10:33 t-ishii Status feedback => closed