[pgpool-general: 9296] Re: pgpool Connection issue: ERROR: unable to read message kind
Mukesh Tanuku
mukesh.postgres at gmail.com
Mon Dec 23 14:13:13 JST 2024
here is the pgpool.conf
listen_addresses = '*'
port = 9999
pcp_listen_addresses = '*'
backend_hostname0 = '**.**.**.**'
backend_port0 = 5432
backend_weight0 = 1
backend_hostname1 = '**.**.**.**'
backend_port1 = 5432
backend_weight1 = 1
load_balance_mode = 'on'
master_slave_mode = 'on'
master_slave_sub_mode = 'stream'
sr_check_period = 10
sr_check_user = 'monitor'
sr_check_password = 'Monitor at 321'
sr_check_database = 'monitor'
delay_threshold = 10240
allow_clear_text_frontend_auth = 'on'
pid_file_name = '/u01/app/admin/Postgresql/pgpool/pgpool.pid'
# pgpool pid location
logging_collector = on
log_directory = '/u01/app/admin/Data//PG_LOGS' #pgpool log
location
log_filename = 'pgpool.log'
num_init_children = 30
enable_pool_hba = on
pool_passwd = '/usr/local/etc/pool_passwd'
health_check_period = 30
health_check_timeout = 20
health_check_user = 'pgbigboss'
health_check_password = ''
health_check_database = 'postgres'
health_check_max_retries = 3
health_check_retry_delay = 1
connect_timeout = 10000
statement_level_load_balance = on
use_watchdog = on
delegate_ip = '**.**.**.**'
if_up_cmd = '/usr/bin/sudo /sbin/ip addr add $_IP_$/21 dev eth0 label
eth0:1'
if_down_cmd = '/usr/bin/sudo /sbin/ip addr del $_IP_$/21 dev eth0'
arping_cmd = '/usr/bin/sudo /usr/sbin/arping -U $_IP_$ -w 1 -I eth0'
hostname0 = '**.**.**.**'
wd_port0 = 9000
pgpool_port0 = 9999
hostname1 = '**.**.**.**'
wd_port1 = 9000
pgpool_port1 = 9999
heartbeat_hostname0 = '**.**.**.**'
heartbeat_port0 = 9694
heartbeat_device0 = ''
heartbeat_hostname1 = '**.**.**.**'
heartbeat_port1 = 9694
heartbeat_device1 = ''
wd_heartbeat_keepalive = 2
wd_heartbeat_deadtime = 30
#trusted_servers = ''
trusted_server_command = 'ping -q -c3 3 %h'
backend_clustering_mode = 'streaming_replication'
enable_consensus_with_half_votes = on
failover_require_consensus = on
failover_when_quorum_exists = on
log_min_messages = 'DEBUG1'
On Mon, Dec 23, 2024 at 9:49 AM Mukesh Tanuku <mukesh.postgres at gmail.com>
wrote:
> Thanks Tatsuo for giving a response to my ask.
>
> *doubt:* Is this because we set a Asynchronous streaming replication on
> postgresql nodes?
>
>
>
> *here is the log from pgpool.log*
>
> 2024-12-23 04:16:47.896: heart_beat_sender pid 1227256: DEBUG: watchdog
> heartbeat: send heartbeat signal to 10.35.8.21:9694
> 2024-12-23 04:16:48.087: watchdog pid 1227250: DEBUG: STATE MACHINE
> INVOKED WITH EVENT = TIMEOUT Current State = LEADER
> 2024-12-23 04:16:49.896: heart_beat_sender pid 1227256: DEBUG: watchdog
> heartbeat: send heartbeat signal to 10.35.8.21:9694
> 2024-12-23 04:16:51.897: heart_beat_sender pid 1227256: DEBUG: watchdog
> heartbeat: send heartbeat signal to 10.35.8.21:9694
> 2024-12-23 04:16:53.093: watchdog pid 1227250: DEBUG: STATE MACHINE
> INVOKED WITH EVENT = COMMAND FINISHED Current State = LEADER
> 2024-12-23 04:16:53.093: watchdog pid 1227250: DEBUG: I am the cluster
> leader node command finished with status:[COMMAND TIMED OUT] which is
> success
> 2024-12-23 04:16:53.093: watchdog pid 1227250: DETAIL: The command was
> sent to 0 nodes and 0 nodes replied to it
> 2024-12-23 04:16:53.897: heart_beat_sender pid 1227256: DEBUG: watchdog
> heartbeat: send heartbeat signal to 10.35.8.21:9694
> 2024-12-23 04:16:55.898: heart_beat_sender pid 1227256: DEBUG: watchdog
> heartbeat: send heartbeat signal to 10.35.8.21:9694
> 2024-12-23 04:16:57.108: watchdog pid 1227250: DEBUG: new IPC connection
> received
> 2024-12-23 04:16:57.108: watchdog pid 1227250: DEBUG: sending watchdog
> packet to socket:7, type:[7], command ID:0, data Length:34
> 2024-12-23 04:16:57.108: sr_check_worker pid 1227293: DEBUG: watchdog
> status: 4
> 2024-12-23 04:16:57.108: sr_check_worker pid 1227293: DEBUG:
> pool_acquire_follow_primary_lock: lock was not held by anyone
> 2024-12-23 04:16:57.108: sr_check_worker pid 1227293: DEBUG:
> pool_acquire_follow_primary_lock: succeeded in acquiring lock
> 2024-12-23 04:16:57.109: sr_check_worker pid 1227293: DEBUG: SSL is
> requested but SSL support is not available
> 2024-12-23 04:16:57.112: sr_check_worker pid 1227293: DEBUG: authenticate
> kind = 0
> 2024-12-23 04:16:57.113: sr_check_worker pid 1227293: DEBUG: authenticate
> backend: key data received
> 2024-12-23 04:16:57.113: sr_check_worker pid 1227293: DEBUG: authenticate
> backend: transaction state: I
> 2024-12-23 04:16:57.114: sr_check_worker pid 1227293: DEBUG: SSL is
> requested but SSL support is not available
> 2024-12-23 04:16:57.120: sr_check_worker pid 1227293: DEBUG: authenticate
> kind = 0
> 2024-12-23 04:16:57.120: sr_check_worker pid 1227293: DEBUG: authenticate
> backend: key data received
> 2024-12-23 04:16:57.120: sr_check_worker pid 1227293: DEBUG: authenticate
> backend: transaction state: I
> 2024-12-23 04:16:57.120: sr_check_worker pid 1227293: DEBUG: do_query:
> extended:0 query:"SELECT pg_catalog.pg_current_wal_lsn()"
> 2024-12-23 04:16:57.120: sr_check_worker pid 1227293: CONTEXT: while
> checking replication time lag
> 2024-12-23 04:16:57.121: sr_check_worker pid 1227293: DEBUG: do_query:
> extended:0 query:"SELECT pg_catalog.pg_last_wal_replay_lsn()"
> 2024-12-23 04:16:57.121: sr_check_worker pid 1227293: CONTEXT: while
> checking replication time lag
> 2024-12-23 04:16:57.124: sr_check_worker pid 1227293: DEBUG: do_query:
> extended:0 query:"SELECT application_name, state, sync_state,(EXTRACT(EPOCH
> FROM replay_lag)*1000000)::BIGINT
> FROM pg_catalog.pg_stat_replication"
> 2024-12-23 04:16:57.124: sr_check_worker pid 1227293: CONTEXT: while
> checking replication time lag
> 2024-12-23 04:16:57.127: sr_check_worker pid 1227293: DEBUG: do_query:
> extended:0 query:"SELECT pg_catalog.pg_is_in_recovery()"
> 2024-12-23 04:16:57.127: sr_check_worker pid 1227293: DEBUG: do_query:
> extended:0 query:"SELECT pg_catalog.pg_is_in_recovery()"
> 2024-12-23 04:16:57.128: sr_check_worker pid 1227293: DEBUG:
> verify_backend_node_status: multiple standbys: 1
> 2024-12-23 04:16:57.128: sr_check_worker pid 1227293: DEBUG:
> verify_backend_node_status: detach_false_primary is off and no additional
> checking is performed
> 2024-12-23 04:16:57.128: sr_check_worker pid 1227293: DEBUG: node
> status[0]: 1
> 2024-12-23 04:16:57.128: sr_check_worker pid 1227293: DEBUG: node
> status[1]: 2
> 2024-12-23 04:16:57.129: sr_check_worker pid 1227293: DEBUG:
> pool_release_follow_primary_lock called
> 2024-12-23 04:16:57.898: heart_beat_sender pid 1227256: DEBUG: watchdog
> heartbeat: send heartbeat signal to 10.35.8.21:9694
> 2024-12-23 04:16:58.109: watchdog pid 1227250: DEBUG: STATE MACHINE
> INVOKED WITH EVENT = TIMEOUT Current State = LEADER
> 2024-12-23 04:16:58.586: child pid 1227259: DEBUG: I am 1227259 accept fd
> 7
> 2024-12-23 04:16:59.899: heart_beat_sender pid 1227256: DEBUG: watchdog
> heartbeat: send heartbeat signal to 10.35.8.21:9694
> 2024-12-23 04:17:00.310: [unknown] pid 1227285: DEBUG: I am 1227285
> accept fd 7
> 2024-12-23 04:17:00.310: [unknown] pid 1227285: DEBUG: reading startup
> packet
> 2024-12-23 04:17:00.310: [unknown] pid 1227285: DETAIL: Protocol Major:
> 1234 Minor: 5679 database: user:
> 2024-12-23 04:17:00.310: [unknown] pid 1227285: DEBUG: selecting backend
> connection
> 2024-12-23 04:17:00.310: [unknown] pid 1227285: DETAIL: SSLRequest from
> client
> 2024-12-23 04:17:00.310: [unknown] pid 1227285: DEBUG: SSL is requested
> but SSL support is not available
> 2024-12-23 04:17:00.312: [unknown] pid 1227285: DEBUG: reading startup
> packet
> 2024-12-23 04:17:00.312: [unknown] pid 1227285: DETAIL: Protocol Major: 3
> Minor: 0 database: postgres user: pgbigboss
> 2024-12-23 04:17:00.312: [unknown] pid 1227285: DEBUG: creating new
> connection to backend
> 2024-12-23 04:17:00.312: [unknown] pid 1227285: DETAIL: connecting 0
> backend
> 2024-12-23 04:17:00.312: [unknown] pid 1227285: DEBUG: creating new
> connection to backend
> 2024-12-23 04:17:00.312: [unknown] pid 1227285: DETAIL: connecting 1
> backend
> 2024-12-23 04:17:00.315: [unknown] pid 1227285: DEBUG: SSL is requested
> but SSL support is not available
> 2024-12-23 04:17:00.315: [unknown] pid 1227285: DEBUG: SSL is requested
> but SSL support is not available
> 2024-12-23 04:17:00.321: [unknown] pid 1227285: DEBUG: authentication
> backend
> 2024-12-23 04:17:00.321: [unknown] pid 1227285: DETAIL: auth kind:0
> 2024-12-23 04:17:00.321: [unknown] pid 1227285: DEBUG: process parameter
> status
> 2024-12-23 04:17:00.321: [unknown] pid 1227285: DETAIL: backend:0
> name:"application_name" value:""
> 2024-12-23 04:17:00.321: [unknown] pid 1227285: DEBUG: process parameter
> status
> 2024-12-23 04:17:00.321: [unknown] pid 1227285: DETAIL: backend:1
> name:"application_name" value:""
> 2024-12-23 04:17:00.321: [unknown] pid 1227285: DEBUG: process parameter
> status
> 2024-12-23 04:17:00.321: [unknown] pid 1227285: DETAIL: backend:0
> name:"client_encoding" value:"UTF8"
> 2024-12-23 04:17:00.321: [unknown] pid 1227285: DEBUG: process parameter
> status
> 2024-12-23 04:17:00.321: [unknown] pid 1227285: DETAIL: backend:1
> name:"client_encoding" value:"UTF8"
> 2024-12-23 04:17:00.322: [unknown] pid 1227285: DEBUG: process parameter
> status
> 2024-12-23 04:17:00.322: [unknown] pid 1227285: DETAIL: backend:0
> name:"DateStyle" value:"ISO, MDY"
> 2024-12-23 04:17:00.322: [unknown] pid 1227285: DEBUG: process parameter
> status
> 2024-12-23 04:17:00.322: [unknown] pid 1227285: DETAIL: backend:1
> name:"DateStyle" value:"ISO, MDY"
> 2024-12-23 04:17:00.322: [unknown] pid 1227285: DEBUG: process parameter
> status
> 2024-12-23 04:17:00.322: [unknown] pid 1227285: DETAIL: backend:0
> name:"default_transaction_read_only" value:"off"
> 2024-12-23 04:17:00.322: [unknown] pid 1227285: DEBUG: process parameter
> status
> 2024-12-23 04:17:00.322: [unknown] pid 1227285: DETAIL: backend:1
> name:"default_transaction_read_only" value:"off"
> 2024-12-23 04:17:00.322: [unknown] pid 1227285: DEBUG: reading message
> length
> 2024-12-23 04:17:00.322: [unknown] pid 1227285: DETAIL: message length
> (22) in slot 1 does not match with slot 0(23)
> 2024-12-23 04:17:00.322: [unknown] pid 1227285: DEBUG: process parameter
> status
> 2024-12-23 04:17:00.322: [unknown] pid 1227285: DETAIL: backend:0
> name:"in_hot_standby" value:"off"
> 2024-12-23 04:17:00.322: [unknown] pid 1227285: DEBUG: process parameter
> status
> 2024-12-23 04:17:00.322: [unknown] pid 1227285: DETAIL: backend:1
> name:"in_hot_standby" value:"on"
> 2024-12-23 04:17:00.322: [unknown] pid 1227285: DEBUG: process parameter
> status
> 2024-12-23 04:17:00.322: [unknown] pid 1227285: DETAIL: backend:0
> name:"integer_datetimes" value:"on"
> 2024-12-23 04:17:00.322: [unknown] pid 1227285: DEBUG: process parameter
> status
> 2024-12-23 04:17:00.322: [unknown] pid 1227285: DETAIL: backend:1
> name:"integer_datetimes" value:"on"
> 2024-12-23 04:17:00.322: [unknown] pid 1227285: DEBUG: process parameter
> status
> 2024-12-23 04:17:00.322: [unknown] pid 1227285: DETAIL: backend:0
> name:"IntervalStyle" value:"postgres"
> 2024-12-23 04:17:00.322: [unknown] pid 1227285: DEBUG: process parameter
> status
> 2024-12-23 04:17:00.322: [unknown] pid 1227285: DETAIL: backend:1
> name:"IntervalStyle" value:"postgres"
> 2024-12-23 04:17:00.322: [unknown] pid 1227285: DEBUG: process parameter
> status
> 2024-12-23 04:17:00.322: [unknown] pid 1227285: DETAIL: backend:0
> name:"is_superuser" value:"on"
> 2024-12-23 04:17:00.322: [unknown] pid 1227285: DEBUG: process parameter
> status
> 2024-12-23 04:17:00.322: [unknown] pid 1227285: DETAIL: backend:1
> name:"is_superuser" value:"on"
> 2024-12-23 04:17:00.322: [unknown] pid 1227285: DEBUG: process parameter
> status
> 2024-12-23 04:17:00.322: [unknown] pid 1227285: DETAIL: backend:0
> name:"server_encoding" value:"UTF8"
> 2024-12-23 04:17:00.322: [unknown] pid 1227285: DEBUG: process parameter
> status
> 2024-12-23 04:17:00.322: [unknown] pid 1227285: DETAIL: backend:1
> name:"server_encoding" value:"UTF8"
> 2024-12-23 04:17:00.322: [unknown] pid 1227285: DEBUG: process parameter
> status
> 2024-12-23 04:17:00.322: [unknown] pid 1227285: DETAIL: backend:0
> name:"server_version" value:"15.6"
> 2024-12-23 04:17:00.322: [unknown] pid 1227285: DEBUG: process parameter
> status
> 2024-12-23 04:17:00.322: [unknown] pid 1227285: DETAIL: backend:1
> name:"server_version" value:"15.6"
> 2024-12-23 04:17:00.322: [unknown] pid 1227285: DEBUG: process parameter
> status
> 2024-12-23 04:17:00.322: [unknown] pid 1227285: DETAIL: backend:0
> name:"session_authorization" value:"pgbigboss"
> 2024-12-23 04:17:00.322: [unknown] pid 1227285: DEBUG: process parameter
> status
> 2024-12-23 04:17:00.322: [unknown] pid 1227285: DETAIL: backend:1
> name:"session_authorization" value:"pgbigboss"
> 2024-12-23 04:17:00.322: [unknown] pid 1227285: DEBUG: process parameter
> status
> 2024-12-23 04:17:00.322: [unknown] pid 1227285: DETAIL: backend:0
> name:"standard_conforming_strings" value:"on"
> 2024-12-23 04:17:00.322: [unknown] pid 1227285: DEBUG: process parameter
> status
> 2024-12-23 04:17:00.322: [unknown] pid 1227285: DETAIL: backend:1
> name:"standard_conforming_strings" value:"on"
> 2024-12-23 04:17:00.322: [unknown] pid 1227285: DEBUG: process parameter
> status
> 2024-12-23 04:17:00.322: [unknown] pid 1227285: DETAIL: backend:0
> name:"TimeZone" value:"Etc/UTC"
> 2024-12-23 04:17:00.322: [unknown] pid 1227285: DEBUG: process parameter
> status
> 2024-12-23 04:17:00.322: [unknown] pid 1227285: DETAIL: backend:1
> name:"TimeZone" value:"Etc/UTC"
> 2024-12-23 04:17:00.322: [unknown] pid 1227285: DEBUG: authentication
> backend
> 2024-12-23 04:17:00.322: [unknown] pid 1227285: DETAIL:
> cp->info[i]:0x7f54139bcc08 pid:1227327
> 2024-12-23 04:17:00.322: [unknown] pid 1227285: DEBUG: authentication
> backend
> 2024-12-23 04:17:00.322: [unknown] pid 1227285: DETAIL:
> cp->info[i]:0x7f54139bcca8 pid:1211355
> 2024-12-23 04:17:00.322: [unknown] pid 1227285: DEBUG: sending backend
> key data
> 2024-12-23 04:17:00.322: [unknown] pid 1227285: DETAIL: send pid 1211355
> to frontend
> 2024-12-23 04:17:00.322: [unknown] pid 1227285: DEBUG: selecting load
> balance node
> 2024-12-23 04:17:00.322: [unknown] pid 1227285: DETAIL: selected backend
> id is 1
> 2024-12-23 04:17:00.325: [unknown] pid 1227285: DEBUG: decide where to
> send the query
> 2024-12-23 04:17:00.325: [unknown] pid 1227285: DETAIL: destination = 3
> for query= "set client_encoding to 'UTF8'"
> 2024-12-23 04:17:00.325: [unknown] pid 1227285: DEBUG: waiting for query
> response
> 2024-12-23 04:17:00.325: [unknown] pid 1227285: DETAIL: waiting for
> backend:0 to complete the query
> 2024-12-23 04:17:00.326: [unknown] pid 1227285: DEBUG: waiting for query
> response
> 2024-12-23 04:17:00.326: [unknown] pid 1227285: DETAIL: waiting for
> backend:1 to complete the query
> 2024-12-23 04:17:00.330: [unknown] pid 1227285: DEBUG: decide where to
> send the query
> 2024-12-23 04:17:00.330: [unknown] pid 1227285: DETAIL: destination = 3
> for query= "set CLIENT_MIN_MESSAGES TO 'ERROR'"
> 2024-12-23 04:17:00.330: [unknown] pid 1227285: DEBUG: waiting for query
> response
> 2024-12-23 04:17:00.330: [unknown] pid 1227285: DETAIL: waiting for
> backend:0 to complete the query
> 2024-12-23 04:17:00.330: [unknown] pid 1227285: DEBUG: waiting for query
> response
> 2024-12-23 04:17:00.330: [unknown] pid 1227285: DETAIL: waiting for
> backend:1 to complete the query
> 2024-12-23 04:17:00.355: [unknown] pid 1227285: DEBUG: checking if query
> has INSERT INTO, FOR SHARE or FOR UPDATE
> 2024-12-23 04:17:00.355: [unknown] pid 1227285: DETAIL: result = 0
> 2024-12-23 04:17:00.355: [unknown] pid 1227285: DEBUG: decide where to
> send the query
> 2024-12-23 04:17:00.355: [unknown] pid 1227285: DETAIL: destination = 2
> for query= "SELECT 1 FROM pg_roles WHERE rolname = 'tpcc'"
> 2024-12-23 04:17:00.355: [unknown] pid 1227285: DEBUG: do_query:
> extended:0 query:"SELECT current_setting('transaction_isolation')"
> 2024-12-23 04:17:00.355: [unknown] pid 1227285: CONTEXT: while getting
> transaction isolation
> 2024-12-23 04:17:00.355: [unknown] pid 1227285: DEBUG: checking load
> balance preconditions. TSTATE:I writing_transaction:0 failed_transaction:0
> isolation:2
> 2024-12-23 04:17:00.356: [unknown] pid 1227285: DETAIL: destination = 2
> for query= "SELECT 1 FROM pg_roles WHERE rolname = 'tpcc'"
> 2024-12-23 04:17:00.356: [unknown] pid 1227285: DEBUG: system catalog
> walker, checking relation "pg_roles"
> 2024-12-23 04:17:00.356: [unknown] pid 1227285: DEBUG: hit local relation
> cache
> 2024-12-23 04:17:00.356: [unknown] pid 1227285: DETAIL: query:SELECT
> count(*) FROM pg_catalog.pg_class AS c, pg_catalog.pg_namespace AS n WHERE
> c.oid = pg_catalog.to_regclass('"%s"
> ') AND c.relnamespace = n.oid AND n.nspname = 'pg_catalog'
> 2024-12-23 04:17:00.356: [unknown] pid 1227285: DEBUG: could not load
> balance because systems catalogs are used
> 2024-12-23 04:17:00.356: [unknown] pid 1227285: DETAIL: destination = 2
> for query= "SELECT 1 FROM pg_roles WHERE rolname = 'tpcc'"
> 2024-12-23 04:17:00.356: [unknown] pid 1227285: DEBUG: waiting for query
> response
> 2024-12-23 04:17:00.356: [unknown] pid 1227285: DETAIL: waiting for
> backend:0 to complete the query
> 2024-12-23 04:17:00.360: [unknown] pid 1227285: DEBUG: checking if query
> has INSERT INTO, FOR SHARE or FOR UPDATE
> 2024-12-23 04:17:00.360: [unknown] pid 1227285: DETAIL: result = 0
> 2024-12-23 04:17:00.360: [unknown] pid 1227285: DEBUG: decide where to
> send the query
> 2024-12-23 04:17:00.360: [unknown] pid 1227285: DETAIL: destination = 2
> for query= "SELECT 1 FROM pg_database WHERE datname = 'tpcc'"
> 2024-12-23 04:17:00.360: [unknown] pid 1227285: DEBUG: checking load
> balance preconditions. TSTATE:I writing_transaction:0 failed_transaction:0
> isolation:2
> 2024-12-23 04:17:00.360: [unknown] pid 1227285: DETAIL: destination = 2
> for query= "SELECT 1 FROM pg_database WHERE datname = 'tpcc'"
> 2024-12-23 04:17:00.360: [unknown] pid 1227285: DEBUG: system catalog
> walker, checking relation "pg_database"
> 2024-12-23 04:17:00.360: [unknown] pid 1227285: DEBUG: hit local relation
> cache
> 2024-12-23 04:17:00.360: [unknown] pid 1227285: DETAIL: query:SELECT
> count(*) FROM pg_catalog.pg_class AS c, pg_catalog.pg_namespace AS n WHERE
> c.oid = pg_catalog.to_regclass('"%s"
> ') AND c.relnamespace = n.oid AND n.nspname = 'pg_catalog'
> 2024-12-23 04:17:00.360: [unknown] pid 1227285: DEBUG: could not load
> balance because systems catalogs are used
> 2024-12-23 04:17:00.360: [unknown] pid 1227285: DETAIL: destination = 2
> for query= "SELECT 1 FROM pg_database WHERE datname = 'tpcc'"
> 2024-12-23 04:17:00.360: [unknown] pid 1227285: DEBUG: waiting for query
> response
> 2024-12-23 04:17:00.360: [unknown] pid 1227285: DETAIL: waiting for
> backend:0 to complete the query
> 2024-12-23 04:17:00.363: [unknown] pid 1227285: DEBUG: decide where to
> send the query
> 2024-12-23 04:17:00.363: [unknown] pid 1227285: DETAIL: destination = 0
> for query= "CREATE USER "tpcc" PASSWORD 'tpcc'"
> 2024-12-23 04:17:00.363: [unknown] pid 1227285: DEBUG: waiting for query
> response
> 2024-12-23 04:17:00.363: [unknown] pid 1227285: DETAIL: waiting for
> backend:0 to complete the query
> 2024-12-23 04:17:00.382: [unknown] pid 1227285: DEBUG: decide where to
> send the query
> 2024-12-23 04:17:00.382: [unknown] pid 1227285: DETAIL: destination = 0
> for query= "GRANT "tpcc" to "pgbigboss""
> 2024-12-23 04:17:00.382: [unknown] pid 1227285: DEBUG: waiting for query
> response
> 2024-12-23 04:17:00.382: [unknown] pid 1227285: DETAIL: waiting for
> backend:0 to complete the query
> 2024-12-23 04:17:00.392: [unknown] pid 1227285: DEBUG: decide where to
> send the query
> 2024-12-23 04:17:00.392: [unknown] pid 1227285: DETAIL: destination = 0
> for query= "CREATE DATABASE "tpcc" OWNER "tpcc""
> 2024-12-23 04:17:00.392: [unknown] pid 1227285: DEBUG: waiting for query
> response
> 2024-12-23 04:17:00.392: [unknown] pid 1227285: DETAIL: waiting for
> backend:0 to complete the query
> 2024-12-23 04:17:00.648: [unknown] pid 1227285: DEBUG: decide where to
> send the query
> 2024-12-23 04:17:00.648: [unknown] pid 1227285: DETAIL: destination = 3
> for query= "commit"
> 2024-12-23 04:17:00.648: [unknown] pid 1227285: DEBUG: waiting for query
> response
> 2024-12-23 04:17:00.648: [unknown] pid 1227285: DETAIL: waiting for
> backend:0 to complete the query
> 2024-12-23 04:17:00.650: [unknown] pid 1227285: DEBUG: decide where to
> send the query
> 2024-12-23 04:17:00.650: [unknown] pid 1227285: DETAIL: destination = 3
> for query= "DISCARD ALL"
> 2024-12-23 04:17:00.650: [unknown] pid 1227285: DEBUG: waiting for query
> response
> 2024-12-23 04:17:00.650: [unknown] pid 1227285: DETAIL: waiting for
> backend:0 to complete the query
> 2024-12-23 04:17:00.651: [unknown] pid 1227285: DEBUG: waiting for query
> response
> 2024-12-23 04:17:00.651: [unknown] pid 1227285: DETAIL: waiting for
> backend:1 to complete the query
> 2024-12-23 04:17:00.652: [unknown] pid 1227285: DEBUG: setting backend
> connection close timer
> 2024-12-23 04:17:00.652: [unknown] pid 1227285: DETAIL: close time
> 1734927420
> 2024-12-23 04:17:00.653: [unknown] pid 1227285: DEBUG: I am 1227285
> accept fd 7
> 2024-12-23 04:17:00.653: [unknown] pid 1227285: DEBUG: reading startup
> packet
> 2024-12-23 04:17:00.653: [unknown] pid 1227285: DETAIL: Protocol Major:
> 1234 Minor: 5679 database: user:
> 2024-12-23 04:17:00.653: [unknown] pid 1227285: DEBUG: selecting backend
> connection
> 2024-12-23 04:17:00.653: [unknown] pid 1227285: DETAIL: SSLRequest from
> client
> 2024-12-23 04:17:00.653: [unknown] pid 1227285: DEBUG: SSL is requested
> but SSL support is not available
> 2024-12-23 04:17:00.656: [unknown] pid 1227285: DEBUG: reading startup
> packet
> 2024-12-23 04:17:00.656: [unknown] pid 1227285: DETAIL: Protocol Major: 3
> Minor: 0 database: tpcc user: tpcc
> 2024-12-23 04:17:00.656: [unknown] pid 1227285: DEBUG: creating new
> connection to backend
> 2024-12-23 04:17:00.656: [unknown] pid 1227285: DETAIL: connecting 0
> backend
> 2024-12-23 04:17:00.656: [unknown] pid 1227285: DEBUG: creating new
> connection to backend
> 2024-12-23 04:17:00.656: [unknown] pid 1227285: DETAIL: connecting 1
> backend
> 2024-12-23 04:17:00.657: [unknown] pid 1227285: DEBUG: SSL is requested
> but SSL support is not available
> 2024-12-23 04:17:00.657: [unknown] pid 1227285: DEBUG: SSL is requested
> but SSL support is not available
> 2024-12-23 04:17:00.665: [unknown] pid 1227285: DEBUG: authentication
> backend
> 2024-12-23 04:17:00.665: [unknown] pid 1227285: DETAIL: auth kind:0
> 2024-12-23 04:17:00.665: [unknown] pid 1227285: LOG: pool_read_kind:
> error message from 1 th backend:database "tpcc" does not exist
> 2024-12-23 04:17:00.665: [unknown] pid 1227285: ERROR: unable to read
> message kind
> 2024-12-23 04:17:00.665: [unknown] pid 1227285: DETAIL: kind does not
> match between main(53) slot[1] (45)
> 2024-12-23 04:17:01.899: heart_beat_sender pid 1227256: DEBUG: watchdog
> heartbeat: send heartbeat signal to 10.35.8.21:9694
> 2024-12-23 04:17:03.113: watchdog pid 1227250: DEBUG: STATE MACHINE
> INVOKED WITH EVENT = COMMAND FINISHED Current State = LEADER
> 2024-12-23 04:17:03.113: watchdog pid 1227250: DEBUG: I am the cluster
> leader node command finished with status:[COMMAND TIMED OUT] which is
> success
> 2024-12-23 04:17:03.113: watchdog pid 1227250: DETAIL: The command was
> sent to 0 nodes and 0 nodes replied to it
> 2024-12-23 04:17:03.900: heart_beat_sender pid 1227256: DEBUG: watchdog
> heartbeat: send heartbeat signal to 10.35.8.21:9694
>
>
> Regards
> Mukesh Tanuku
>
> On Mon, Dec 23, 2024 at 9:41 AM Mukesh Tanuku <mukesh.postgres at gmail.com>
> wrote:
>
>> Thanks Tatsuo for giving a response to my ask.
>>
>> We will share the log soon, we have to capture the log in our next test
>> iteration.
>> Is this because we set a Asynchronous streaming replication on postgresql
>> nodes?
>>
>> Regards
>> Mukesh Tanuku
>>
>> On Mon, Dec 23, 2024 at 7:44 AM Tatsuo Ishii <ishii at postgresql.org>
>> wrote:
>>
>>> > Hello Everyone,
>>> >
>>> > We have a Postgres setup in Azure (IAAS) with 2 DB nodes in the
>>> cluster and
>>> > pgpool is running on each DB node. We have enabled the watchdog.
>>> >
>>> > What we are doing: We are testing the connectivity to DB cluster via
>>> > HammerDB to apply the load.
>>> > HammerDB is connecting to Delegate IP via 9999 port.
>>> >
>>> > Issue: when we initiate the connection it gives error, but when we
>>> > re-initiate the connection again then it is successful. What could be
>>> the
>>> > issue
>>> >
>>> > Error message we are seeing when we initiate the connection for the
>>> first
>>> > time.
>>> >
>>> > Error in Virtual User 1: Error: Connection to database failed
>>> > connection to server at "10.35.8.4", port 9999 failed: ERROR: unable
>>> to
>>> > read message kind
>>> > DETAIL: kind does not match between main(53) slot[1] (45)
>>> >
>>> > If you want to see any configuration settings that i made, i can share.
>>> >
>>> > Please help me in this regard.
>>>
>>> The error message can be interpreted that primary PostgreSQL sent 0x53
>>> = 'S'(parameter status message) while standby sent 0x45 = 'E' (error
>>> response). Perhaps the parameter status cannot be processed on standby
>>> for some reasons. In order to study the cause of error, I need a
>>> pgpool log with debug level 1 (log_min_messages = debug1). Can you
>>> provide it?
>>>
>>> BTW, cross posting pgpool-general and pgsql-general is not
>>> recommended. Please post to pgpool-general only next time.
>>>
>>> Best reagards,
>>> --
>>> Tatsuo Ishii
>>> SRA OSS K.K.
>>> English: http://www.sraoss.co.jp/index_en/
>>> Japanese:http://www.sraoss.co.jp
>>>
>>
-------------- next part --------------
An HTML attachment was scrubbed...
URL: <http://www.pgpool.net/pipermail/pgpool-general/attachments/20241223/e0a43515/attachment-0001.htm>
More information about the pgpool-general
mailing list