[pgpool-general: 9295] Re: pgpool Connection issue: ERROR: unable to read message kind

Mukesh Tanuku mukesh.postgres at gmail.com
Mon Dec 23 13:19:47 JST 2024 

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/6ded66ba/attachment-0001.htm>

More information about the pgpool-general mailing list