[pgpool-general: 8756] segmentation fault with "enable_shared_relcache = on"

zam bak zam6ak at gmail.com
Thu May 11 00:59:36 JST 2023


Hi

I have noticed that in our PgPool-II v4.4,  child workers would often segfault.
A restart would seem to fix the problem but only for a day or two,
then the issue would start occuring again...

We have two PG v15 servers in streaming replication mode (async) with
single PgPool-II servers.
After enabling debug mode I noticed that child would crash just before
several messages mentioning "relcache"

So I tried setting "enable_shared_relcache = off"
Since that change, there have been no more segfaults.

Following is a config dump and also a portion of the debug log showing
messages from a single child that crashed (the entire log is filled
with exact same messages but for different child workers)

PgPool-II config (before setting enable_shared_relcache = off)
---------------------
diff --unchanged-line-format= --old-line-format=
--new-line-format='%L' pgpool.conf.sample pgpool.conf

listen_addresses = '*'
serialize_accept = on
backend_hostname0 = '10.2.32.15'
backend_port0 = 5432
backend_weight0 = 1
backend_data_directory0 = '/data/pgdata/15'
backend_flag0 = 'ALWAYS_PRIMARY'
backend_application_name0 = 'primary'
backend_hostname1 = '10.2.96.15'
backend_port1 = 5432
backend_weight1 = 1
backend_data_directory1 = '/data/pgdata/15'
backend_flag1 = 'DISALLOW_TO_FAILOVER'
backend_application_name1 = 'replica_1'
num_init_children = 246
max_pool = 2
child_life_time = 0
log_line_prefix = '%m [%p]: [%l-1] user=%u,db=%d,app=%a '
log_connections = on
log_disconnections = on
log_per_node_statement = on
log_standby_delay = 'always'
logging_collector = on
log_directory = '/var/log/pgpool-II'
log_filename = 'pgpool-01-%a.log'
log_truncate_on_rotation = on
log_rotation_age = 1d
log_rotation_size = 100MB
write_function_list =
'currval,lastval,nextval,setval,public.upgrade_.*,upgrade_.*,public.update_.*,update_.*'
statement_level_load_balance = on
sr_check_period = 5
sr_check_user = 'pgpool_monitor'
delay_threshold_by_time = 1
health_check_period = 10
health_check_timeout = 30
health_check_user = 'pgpool_monitor'
health_check_max_retries = 10
failover_on_backend_error = off
check_temp_table = trace



PgPool-II debug log (some information changed/redacted)
---------------------
2023-04-26 16:16:01.422 [2552510]: [1-1] user=[No Connection],db=[No
Connection],app=child DEBUG:  initializing backend status
2023-04-26 16:22:52.544 [2552510]: [2-1] user=[No Connection],db=[No
Connection],app=child DEBUG:  LOCKING select()
2023-04-26 16:22:54.588 [2552510]: [3-1] user=[No Connection],db=[No
Connection],app=child DEBUG:  UNLOCKING select()
2023-04-26 16:22:54.588 [2552510]: [4-1] user=[No Connection],db=[No
Connection],app=child DEBUG:  I am 2552510 accept fd 7
2023-04-26 16:22:54.588 [2552510]: [5-1] user=[No Connection],db=[No
Connection],app=child LOG:  new connection received
2023-04-26 16:22:54.588 [2552510]: [6-1] user=[No Connection],db=[No
Connection],app=child DETAIL:  connecting host=10.11.4.100 port=58698
2023-04-26 16:22:54.591 [2552510]: [7-1] user=[No Connection],db=[No
Connection],app=child DEBUG:  reading startup packet
2023-04-26 16:22:54.591 [2552510]: [8-1] user=[No Connection],db=[No
Connection],app=child DETAIL:  application_name: webapp1
2023-04-26 16:22:54.591 [2552510]: [9-1] user=[No Connection],db=[No
Connection],app=child DEBUG:  reading startup packet
2023-04-26 16:22:54.591 [2552510]: [10-1] user=[No Connection],db=[No
Connection],app=child DETAIL:  guc name: client_encoding value: UTF8
2023-04-26 16:22:54.591 [2552510]: [11-1] user=[No Connection],db=[No
Connection],app=child DEBUG:  reading startup packet
2023-04-26 16:22:54.591 [2552510]: [12-1] user=[No Connection],db=[No
Connection],app=child DETAIL:  Protocol Major: 3 Minor: 0 database:
testdb user: postgres
2023-04-26 16:22:54.591 [2552510]: [13-1] user=[No Connection],db=[No
Connection],app=child DEBUG:  creating new connection to backend
2023-04-26 16:22:54.591 [2552510]: [14-1] user=[No Connection],db=[No
Connection],app=child DETAIL:  connecting 0 backend
2023-04-26 16:22:54.591 [2552510]: [15-1] user=[No Connection],db=[No
Connection],app=child DEBUG:  creating new connection to backend
2023-04-26 16:22:54.591 [2552510]: [16-1] user=[No Connection],db=[No
Connection],app=child DETAIL:  connecting 1 backend
2023-04-26 16:22:54.593 [2552510]: [17-1] user=[No Connection],db=[No
Connection],app=child DEBUG:  authentication backend
2023-04-26 16:22:54.593 [2552510]: [18-1] user=[No Connection],db=[No
Connection],app=child DETAIL:  auth kind:10
2023-04-26 16:22:54.595 [2552510]: [19-1] user=[No Connection],db=[No
Connection],app=child DEBUG:  authentication backend 0
2023-04-26 16:22:54.595 [2552510]: [20-1] user=[No Connection],db=[No
Connection],app=child DETAIL:  trying SCRAM authentication
2023-04-26 16:22:54.653 [2552510]: [21-1] user=[No Connection],db=[No
Connection],app=child DEBUG:  SCRAM authentication successful for
backend 0
2023-04-26 16:22:54.653 [2552510]: [22-1] user=[No Connection],db=[No
Connection],app=child DEBUG:  authentication backend 1
2023-04-26 16:22:54.653 [2552510]: [23-1] user=[No Connection],db=[No
Connection],app=child DETAIL:  trying SCRAM authentication
2023-04-26 16:22:54.660 [2552510]: [24-1] user=[No Connection],db=[No
Connection],app=child DEBUG:  SCRAM authentication successful for
backend 1
2023-04-26 16:22:54.660 [2552510]: [25-1] user=[No Connection],db=[No
Connection],app=child DEBUG:  process parameter status
2023-04-26 16:22:54.660 [2552510]: [26-1] user=[No Connection],db=[No
Connection],app=child DETAIL:  backend:0 name:"application_name"
value:"webapp1"
2023-04-26 16:22:54.660 [2552510]: [27-1] user=[No Connection],db=[No
Connection],app=webapp1 DEBUG:  process parameter status
2023-04-26 16:22:54.660 [2552510]: [28-1] user=[No Connection],db=[No
Connection],app=webapp1 DETAIL:  backend:1 name:"application_name"
value:"webapp1"
2023-04-26 16:22:54.660 [2552510]: [29-1] user=[No Connection],db=[No
Connection],app=webapp1 DEBUG:  process parameter status
2023-04-26 16:22:54.660 [2552510]: [30-1] user=[No Connection],db=[No
Connection],app=webapp1 DETAIL:  backend:0 name:"client_encoding"
value:"UTF8"
2023-04-26 16:22:54.660 [2552510]: [31-1] user=[No Connection],db=[No
Connection],app=webapp1 DEBUG:  process parameter status
2023-04-26 16:22:54.660 [2552510]: [32-1] user=[No Connection],db=[No
Connection],app=webapp1 DETAIL:  backend:1 name:"client_encoding"
value:"UTF8"
2023-04-26 16:22:54.660 [2552510]: [33-1] user=[No Connection],db=[No
Connection],app=webapp1 DEBUG:  process parameter status
2023-04-26 16:22:54.660 [2552510]: [34-1] user=[No Connection],db=[No
Connection],app=webapp1 DETAIL:  backend:0 name:"DateStyle"
value:"ISO, MDY"
2023-04-26 16:22:54.660 [2552510]: [35-1] user=[No Connection],db=[No
Connection],app=webapp1 DEBUG:  process parameter status
2023-04-26 16:22:54.660 [2552510]: [36-1] user=[No Connection],db=[No
Connection],app=webapp1 DETAIL:  backend:1 name:"DateStyle"
value:"ISO, MDY"
2023-04-26 16:22:54.660 [2552510]: [37-1] user=[No Connection],db=[No
Connection],app=webapp1 DEBUG:  process parameter status
2023-04-26 16:22:54.660 [2552510]: [38-1] user=[No Connection],db=[No
Connection],app=webapp1 DETAIL:  backend:0
name:"default_transaction_read_only" value:"off"
2023-04-26 16:22:54.660 [2552510]: [39-1] user=[No Connection],db=[No
Connection],app=webapp1 DEBUG:  process parameter status
2023-04-26 16:22:54.660 [2552510]: [40-1] user=[No Connection],db=[No
Connection],app=webapp1 DETAIL:  backend:1
name:"default_transaction_read_only" value:"off"
2023-04-26 16:22:54.660 [2552510]: [41-1] user=[No Connection],db=[No
Connection],app=webapp1 DEBUG:  reading message length
2023-04-26 16:22:54.660 [2552510]: [42-1] user=[No Connection],db=[No
Connection],app=webapp1 DETAIL:  message length (22) in slot 1 does
not match with slot 0(23)
2023-04-26 16:22:54.660 [2552510]: [43-1] user=[No Connection],db=[No
Connection],app=webapp1 DEBUG:  process parameter status
2023-04-26 16:22:54.660 [2552510]: [44-1] user=[No Connection],db=[No
Connection],app=webapp1 DETAIL:  backend:0 name:"in_hot_standby"
value:"off"
2023-04-26 16:22:54.660 [2552510]: [45-1] user=[No Connection],db=[No
Connection],app=webapp1 DEBUG:  process parameter status
2023-04-26 16:22:54.660 [2552510]: [46-1] user=[No Connection],db=[No
Connection],app=webapp1 DETAIL:  backend:1 name:"in_hot_standby"
value:"on"
2023-04-26 16:22:54.660 [2552510]: [47-1] user=[No Connection],db=[No
Connection],app=webapp1 DEBUG:  process parameter status
2023-04-26 16:22:54.660 [2552510]: [48-1] user=[No Connection],db=[No
Connection],app=webapp1 DETAIL:  backend:0 name:"integer_datetimes"
value:"on"
2023-04-26 16:22:54.660 [2552510]: [49-1] user=[No Connection],db=[No
Connection],app=webapp1 DEBUG:  process parameter status
2023-04-26 16:22:54.660 [2552510]: [50-1] user=[No Connection],db=[No
Connection],app=webapp1 DETAIL:  backend:1 name:"integer_datetimes"
value:"on"
2023-04-26 16:22:54.660 [2552510]: [51-1] user=[No Connection],db=[No
Connection],app=webapp1 DEBUG:  process parameter status
2023-04-26 16:22:54.660 [2552510]: [52-1] user=[No Connection],db=[No
Connection],app=webapp1 DETAIL:  backend:0 name:"IntervalStyle"
value:"postgres"
2023-04-26 16:22:54.660 [2552510]: [53-1] user=[No Connection],db=[No
Connection],app=webapp1 DEBUG:  process parameter status
2023-04-26 16:22:54.660 [2552510]: [54-1] user=[No Connection],db=[No
Connection],app=webapp1 DETAIL:  backend:1 name:"IntervalStyle"
value:"postgres"
2023-04-26 16:22:54.660 [2552510]: [55-1] user=[No Connection],db=[No
Connection],app=webapp1 DEBUG:  process parameter status
2023-04-26 16:22:54.660 [2552510]: [56-1] user=[No Connection],db=[No
Connection],app=webapp1 DETAIL:  backend:0 name:"is_superuser"
value:"on"
2023-04-26 16:22:54.660 [2552510]: [57-1] user=[No Connection],db=[No
Connection],app=webapp1 DEBUG:  process parameter status
2023-04-26 16:22:54.660 [2552510]: [58-1] user=[No Connection],db=[No
Connection],app=webapp1 DETAIL:  backend:1 name:"is_superuser"
value:"on"
2023-04-26 16:22:54.660 [2552510]: [59-1] user=[No Connection],db=[No
Connection],app=webapp1 DEBUG:  process parameter status
2023-04-26 16:22:54.660 [2552510]: [60-1] user=[No Connection],db=[No
Connection],app=webapp1 DETAIL:  backend:0 name:"server_encoding"
value:"UTF8"
2023-04-26 16:22:54.660 [2552510]: [61-1] user=[No Connection],db=[No
Connection],app=webapp1 DEBUG:  process parameter status
2023-04-26 16:22:54.660 [2552510]: [62-1] user=[No Connection],db=[No
Connection],app=webapp1 DETAIL:  backend:1 name:"server_encoding"
value:"UTF8"
2023-04-26 16:22:54.660 [2552510]: [63-1] user=[No Connection],db=[No
Connection],app=webapp1 DEBUG:  process parameter status
2023-04-26 16:22:54.660 [2552510]: [64-1] user=[No Connection],db=[No
Connection],app=webapp1 DETAIL:  backend:0 name:"server_version"
value:"15.2"
2023-04-26 16:22:54.660 [2552510]: [65-1] user=[No Connection],db=[No
Connection],app=webapp1 DEBUG:  process parameter status
2023-04-26 16:22:54.660 [2552510]: [66-1] user=[No Connection],db=[No
Connection],app=webapp1 DETAIL:  backend:1 name:"server_version"
value:"15.2"
2023-04-26 16:22:54.660 [2552510]: [67-1] user=[No Connection],db=[No
Connection],app=webapp1 DEBUG:  process parameter status
2023-04-26 16:22:54.660 [2552510]: [68-1] user=[No Connection],db=[No
Connection],app=webapp1 DETAIL:  backend:0
name:"session_authorization" value:"postgres"
2023-04-26 16:22:54.660 [2552510]: [69-1] user=[No Connection],db=[No
Connection],app=webapp1 DEBUG:  process parameter status
2023-04-26 16:22:54.660 [2552510]: [70-1] user=[No Connection],db=[No
Connection],app=webapp1 DETAIL:  backend:1
name:"session_authorization" value:"postgres"
2023-04-26 16:22:54.660 [2552510]: [71-1] user=[No Connection],db=[No
Connection],app=webapp1 DEBUG:  process parameter status
2023-04-26 16:22:54.660 [2552510]: [72-1] user=[No Connection],db=[No
Connection],app=webapp1 DETAIL:  backend:0
name:"standard_conforming_strings" value:"on"
2023-04-26 16:22:54.660 [2552510]: [73-1] user=[No Connection],db=[No
Connection],app=webapp1 DEBUG:  process parameter status
2023-04-26 16:22:54.660 [2552510]: [74-1] user=[No Connection],db=[No
Connection],app=webapp1 DETAIL:  backend:1
name:"standard_conforming_strings" value:"on"
2023-04-26 16:22:54.660 [2552510]: [75-1] user=[No Connection],db=[No
Connection],app=webapp1 DEBUG:  process parameter status
2023-04-26 16:22:54.660 [2552510]: [76-1] user=[No Connection],db=[No
Connection],app=webapp1 DETAIL:  backend:0 name:"TimeZone" value:"UTC"
2023-04-26 16:22:54.660 [2552510]: [77-1] user=[No Connection],db=[No
Connection],app=webapp1 DEBUG:  process parameter status
2023-04-26 16:22:54.660 [2552510]: [78-1] user=[No Connection],db=[No
Connection],app=webapp1 DETAIL:  backend:1 name:"TimeZone" value:"UTC"
2023-04-26 16:22:54.660 [2552510]: [79-1] user=[No Connection],db=[No
Connection],app=webapp1 DEBUG:  authentication backend
2023-04-26 16:22:54.660 [2552510]: [80-1] user=[No Connection],db=[No
Connection],app=webapp1 DETAIL:  cp->info[i]:0x7f7cb0a20c08
pid:1737049
2023-04-26 16:22:54.660 [2552510]: [81-1] user=[No Connection],db=[No
Connection],app=webapp1 DEBUG:  authentication backend
2023-04-26 16:22:54.660 [2552510]: [82-1] user=[No Connection],db=[No
Connection],app=webapp1 DETAIL:  cp->info[i]:0x7f7cb0a20ca8
pid:1593395
2023-04-26 16:22:54.660 [2552510]: [83-1] user=[No Connection],db=[No
Connection],app=webapp1 DEBUG:  sending backend key data
2023-04-26 16:22:54.660 [2552510]: [84-1] user=[No Connection],db=[No
Connection],app=webapp1 DETAIL:  send pid 1593395 to frontend
2023-04-26 16:22:54.660 [2552510]: [85-1]
user=postgres,db=testdb,app=webapp1 DEBUG:  selecting load balance
node
2023-04-26 16:22:54.660 [2552510]: [86-1]
user=postgres,db=testdb,app=webapp1 DETAIL:  selected backend id is 1
2023-04-26 16:22:54.697 [2552510]: [87-1]
user=postgres,db=testdb,app=webapp1 LOG:  DB node id: 0 backend pid:
1737049 statement: SELECT version()
2023-04-26 16:22:54.697 [2552510]: [88-1]
user=postgres,db=testdb,app=webapp1 DEBUG:  memcache encode key
2023-04-26 16:22:54.697 [2552510]: [89-1]
user=postgres,db=testdb,app=webapp1 DETAIL:  username: "postgres"
database_name: "testdb"
2023-04-26 16:22:54.697 [2552510]: [90-1]
user=postgres,db=testdb,app=webapp1 CONTEXT:  while searching system
catalog, When relcache is missed
2023-04-26 16:22:54.697 [2552510]: [91-1]
user=postgres,db=testdb,app=webapp1 DEBUG:  memcache encode key
2023-04-26 16:22:54.697 [2552510]: [92-1]
user=postgres,db=testdb,app=webapp1 DETAIL:  query: "SELECT version()"
2023-04-26 16:22:54.697 [2552510]: [93-1]
user=postgres,db=testdb,app=webapp1 CONTEXT:  while searching system
catalog, When relcache is missed
2023-04-26 16:22:54.697 [2552510]: [94-1]
user=postgres,db=testdb,app=webapp1 DEBUG:  memcache encode key
2023-04-26 16:22:54.697 [2552510]: [95-1]
user=postgres,db=testdb,app=webapp1 DETAIL:  `postgresSELECT
version()testdb' -> `8f50e5ca51b70ccd04f453b264412af2'
2023-04-26 16:22:54.697 [2552510]: [96-1]
user=postgres,db=testdb,app=webapp1 CONTEXT:  while searching system
catalog, When relcache is missed
2023-04-26 16:22:54.697 [2552510]: [97-1]
user=postgres,db=testdb,app=webapp1 DEBUG:  fetching from cache
storage
2023-04-26 16:22:54.697 [2552510]: [98-1]
user=postgres,db=testdb,app=webapp1 DETAIL:  search key
"8f50e5ca51b70ccd04f453b264412af2"
2023-04-26 16:22:54.697 [2552510]: [99-1]
user=postgres,db=testdb,app=webapp1 CONTEXT:  while searching system
catalog, When relcache is missed
2023-04-26 16:22:54.697 [2552510]: [100-1]
user=postgres,db=testdb,app=webapp1 DEBUG:  fetching from cache
storage
2023-04-26 16:22:54.697 [2552510]: [101-1]
user=postgres,db=testdb,app=webapp1 DETAIL:  query="SELECT version()"
len:116
2023-04-26 16:22:54.697 [2552510]: [102-1]
user=postgres,db=testdb,app=webapp1 CONTEXT:  while searching system
catalog, When relcache is missed
2023-04-26 16:22:54.697 [2552510]: [103-1]
user=postgres,db=testdb,app=webapp1 DEBUG:  hit query cache
2023-04-26 16:22:54.697 [2552510]: [104-1]
user=postgres,db=testdb,app=webapp1 DETAIL:  query:SELECT version()
2023-04-26 16:22:54.697 [2552510]: [105-1]
user=postgres,db=testdb,app=webapp1 CONTEXT:  while searching system
catalog, When relcache is missed
2023-04-26 16:22:54.697 [2552510]: [106-1]
user=postgres,db=testdb,app=webapp1 DEBUG:  checking if query has
INSERT INTO, FOR SHARE or FOR UPDATE
2023-04-26 16:22:54.697 [2552510]: [107-1]
user=postgres,db=testdb,app=webapp1 DETAIL:  result = 0
2023-04-26 16:22:54.697 [2552510]: [108-1]
user=postgres,db=testdb,app=webapp1 DEBUG:  decide where to send the
query
2023-04-26 16:22:54.697 [2552510]: [109-1]
user=postgres,db=testdb,app=webapp1 DETAIL:  destination = 2 for
query= "
2023-04-26 16:22:54.697 [2552510]: [110-1]
user=postgres,db=testdb,app=webapp1 DEBUG:  do_query: extended:0
query:"SELECT current_setting('transaction_isolation')"
2023-04-26 16:22:54.697 [2552510]: [111-1]
user=postgres,db=testdb,app=webapp1 CONTEXT:  while getting
transaction isolation
2023-04-26 16:22:54.697 [2552510]: [112-1]
user=postgres,db=testdb,app=webapp1 DEBUG:  checking load balance
preconditions. TSTATE:I writing_transaction:0 failed_transaction:0
isolation:2
2023-04-26 16:22:54.697 [2552510]: [113-1]
user=postgres,db=testdb,app=webapp1 DETAIL:  destination = 2 for
query= "
2023-04-26 16:22:54.697 [2552510]: [114-1]
user=postgres,db=testdb,app=webapp1 DEBUG:  system catalog walker,
checking relation "customers"
2023-04-26 16:22:54.697 [2552510]: [115-1]
user=postgres,db=testdb,app=webapp1 LOG:  DB node id: 0 backend pid:
1737049 statement: SELECT count(*) FROM pg_class AS c, pg_namespace AS
n WHERE c.oid = pg_catalog.to_regclass('"customers"') AND
c.relnamespace = n.oid AND n.nspname = 'pg_catalog'
2023-04-26 16:22:54.697 [2552510]: [116-1]
user=postgres,db=testdb,app=webapp1 DEBUG:  memcache encode key
2023-04-26 16:22:54.697 [2552510]: [117-1]
user=postgres,db=testdb,app=webapp1 DETAIL:  username: "postgres"
database_name: "testdb"
2023-04-26 16:22:54.697 [2552510]: [118-1]
user=postgres,db=testdb,app=webapp1 CONTEXT:  while searching system
catalog, When relcache is missed
2023-04-26 16:22:54.697 [2552510]: [119-1]
user=postgres,db=testdb,app=webapp1 DEBUG:  memcache encode key
2023-04-26 16:22:54.697 [2552510]: [120-1]
user=postgres,db=testdb,app=webapp1 DETAIL:  query: "SELECT count(*)
FROM pg_class AS c, pg_namespace AS n WHERE c.oid =
pg_catalog.to_regclass('"customers"') AND c.relnamespace = n.oid AND
n.nspname = 'pg_catalog'"
2023-04-26 16:22:54.697 [2552510]: [121-1]
user=postgres,db=testdb,app=webapp1 CONTEXT:  while searching system
catalog, When relcache is missed
2023-04-26 16:22:54.698 [2552510]: [122-1]
user=postgres,db=testdb,app=webapp1 DEBUG:  memcache encode key
2023-04-26 16:22:54.698 [2552510]: [123-1]
user=postgres,db=testdb,app=webapp1 DETAIL:  `postgresSELECT count(*)
FROM pg_class AS c, pg_namespace AS n WHERE c.oid =
pg_catalog.to_regclass('"customers"') AND c.relnamespace = n.oid AND
n.nspname = 'pg_catalog'testdb' -> `825a6a367f8931914064ece25e13e0b3'
2023-04-26 16:22:54.698 [2552510]: [124-1]
user=postgres,db=testdb,app=webapp1 CONTEXT:  while searching system
catalog, When relcache is missed
2023-04-26 16:22:54.698 [2552510]: [125-1]
user=postgres,db=testdb,app=webapp1 DEBUG:  fetching from cache
storage
2023-04-26 16:22:54.698 [2552510]: [126-1]
user=postgres,db=testdb,app=webapp1 DETAIL:  search key
"825a6a367f8931914064ece25e13e0b3"
2023-04-26 16:22:54.698 [2552510]: [127-1]
user=postgres,db=testdb,app=webapp1 CONTEXT:  while searching system
catalog, When relcache is missed
2023-04-26 16:22:54.698 [2552510]: [128-1]
user=postgres,db=testdb,app=webapp1 DEBUG:  fetching from cache
storage
2023-04-26 16:22:54.698 [2552510]: [129-1]
user=postgres,db=testdb,app=webapp1 DETAIL:  cache not found on shared
memory
2023-04-26 16:22:54.698 [2552510]: [130-1]
user=postgres,db=testdb,app=webapp1 CONTEXT:  while searching system
catalog, When relcache is missed
2023-04-26 16:22:54.698 [2552510]: [131-1]
user=postgres,db=testdb,app=webapp1 DEBUG:  not hit local relation
cache and query cache
2023-04-26 16:22:54.698 [2552510]: [132-1]
user=postgres,db=testdb,app=webapp1 DETAIL:  query:SELECT count(*)
FROM pg_class AS c, pg_namespace AS n WHERE c.oid =
pg_catalog.to_regclass('"customers"') AND c.relnamespace = n.oid AND
n.nspname = 'pg_catalog'
2023-04-26 16:22:54.698 [2552510]: [133-1]
user=postgres,db=testdb,app=webapp1 CONTEXT:  while searching system
catalog, When relcache is missed
2023-04-26 16:22:54.698 [2552510]: [134-1]
user=postgres,db=testdb,app=webapp1 DEBUG:  do_query: extended:0
query:"SELECT count(*) FROM pg_class AS c, pg_namespace AS n WHERE
c.oid = pg_catalog.to_regclass('"customers"') AND c.relnamespace =
n.oid AND n.nspname = 'pg_catalog'"
2023-04-26 16:22:54.698 [2552510]: [135-1]
user=postgres,db=testdb,app=webapp1 CONTEXT:  while searching system
catalog, When relcache is missed
2023-04-26 16:22:54.699 [2552510]: [136-1]
user=postgres,db=testdb,app=webapp1 DEBUG:  committing relation cache
to cache storage
2023-04-26 16:22:54.699 [2552510]: [137-1]
user=postgres,db=testdb,app=webapp1 DETAIL:  Query="SELECT count(*)
FROM pg_class AS c, pg_namespace AS n WHERE c.oid =
pg_catalog.to_regclass('"customers"') AND c.relnamespace = n.oid AND
n.nspname = 'pg_catalog'"
2023-04-26 16:22:54.699 [2552510]: [138-1]
user=postgres,db=testdb,app=webapp1 CONTEXT:  while searching system
catalog, When relcache is missed
2023-04-26 16:22:54.699 [2552510]: [139-1]
user=postgres,db=testdb,app=webapp1 DEBUG:  memcache encode key
2023-04-26 16:22:54.699 [2552510]: [140-1]
user=postgres,db=testdb,app=webapp1 DETAIL:  username: "postgres"
database_name: "testdb"
2023-04-26 16:22:54.699 [2552510]: [141-1]
user=postgres,db=testdb,app=webapp1 CONTEXT:  while searching system
catalog, When relcache is missed
2023-04-26 16:22:54.699 [2552510]: [142-1]
user=postgres,db=testdb,app=webapp1 DEBUG:  memcache encode key
2023-04-26 16:22:54.699 [2552510]: [143-1]
user=postgres,db=testdb,app=webapp1 DETAIL:  query: "SELECT count(*)
FROM pg_class AS c, pg_namespace AS n WHERE c.oid =
pg_catalog.to_regclass('"customers"') AND c.relnamespace = n.oid AND
n.nspname = 'pg_catalog'"
2023-04-26 16:22:54.699 [2552510]: [144-1]
user=postgres,db=testdb,app=webapp1 CONTEXT:  while searching system
catalog, When relcache is missed
2023-04-26 16:22:54.699 [2552510]: [145-1]
user=postgres,db=testdb,app=webapp1 DEBUG:  memcache encode key
2023-04-26 16:22:54.699 [2552510]: [146-1]
user=postgres,db=testdb,app=webapp1 DETAIL:  `postgresSELECT count(*)
FROM pg_class AS c, pg_namespace AS n WHERE c.oid =
pg_catalog.to_regclass('"customers"') AND c.relnamespace = n.oid AND
n.nspname = 'pg_catalog'testdb' -> `825a6a367f8931914064ece25e13e0b3'
2023-04-26 16:22:54.699 [2552510]: [147-1]
user=postgres,db=testdb,app=webapp1 CONTEXT:  while searching system
catalog, When relcache is missed
2023-04-26 16:22:54.699 [2552510]: [148-1]
user=postgres,db=testdb,app=webapp1 DEBUG:  committing relation cache
to cache storage
2023-04-26 16:22:54.699 [2552510]: [149-1]
user=postgres,db=testdb,app=webapp1 DETAIL:  memqcache_expire = 0
2023-04-26 16:22:54.699 [2552510]: [150-1]
user=postgres,db=testdb,app=webapp1 CONTEXT:  while searching system
catalog, When relcache is missed
2023-04-26 16:22:54.748 [2552368]: [428-1] user=[No Connection],db=[No
Connection],app=main WARNING:  child process with pid: 2552510 was
terminated by segmentation fault


More information about the pgpool-general mailing list