View Issue Details
| ID | Project | Category | View Status | Date Submitted | Last Update |
|---|---|---|---|---|---|
| 0000211 | Pgpool-II | Bug | public | 2016-06-28 18:34 | 2016-09-28 10:33 |
| Reporter | zh1029 | Assigned To | t-ishii | ||
| Priority | high | Severity | major | Reproducibility | always |
| Status | closed | Resolution | open | ||
| Product Version | 3.5.2 | ||||
| Summary | 0000211: YCSB can't connect to PGPool-II in master-slave mode. | ||||
| Description | I 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 | ||||
| Tags | No tags attached. | ||||
|
|
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? |
|
|
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. |
|
|
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: |
|
|
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'). |
|
|
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 |
|
|
|
|
|
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. |
|
|
|
|
|
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; } |
|
|
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? |
|
|
No feedback over 2 months from the reporter. Issue closed. |
| 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 |
