[pgpool-general: 8892] Re: pgpool sub-processes get terminated by segment fault
Zhaoxun Yan
yan.zhaoxun at gmail.com
Wed Jul 12 17:24:44 JST 2023
The log for 2023-07-07 is empty.
I have created user checker:
create user checker with password 'check123';
grant all on database "template1" to checker;
I have already granted trust to them, so this time it does not ask me
password on postgresql:
# psql -h 172.17.0.2 -p 5432 -U checker template1
but the inquiry to pgpool failed again like before:
# psql -h 172.17.0.2 -p 9999 -U checker template1
psql: error: server closed the connection unexpectedly
This probably means the server terminated abnormally
before or while processing the request.
Log of postgres:
2023-07-12 16:09:59.586 CST [8680] LOG: received fast shutdown request
2023-07-12 16:09:59.587 CST [8680] LOG: aborting any active transactions
2023-07-12 16:09:59.592 CST [8680] LOG: background worker "logical
replication launcher" (PID 8689) exited with exit code 1
2023-07-12 16:09:59.593 CST [8683] LOG: shutting down
2023-07-12 16:09:59.633 CST [8680] LOG: database system is shut down
2023-07-12 16:15:30.173 CST [48844] LOG: starting PostgreSQL 13.10 on
x86_64-redhat-linux-gnu, compiled by gcc (GCC) 11.3.1 20221121 (Red Hat
11.3.1-4), 64-bit
2023-07-12 16:15:30.173 CST [48844] LOG: listening on IPv4 address
"0.0.0.0", port 5432
2023-07-12 16:15:30.173 CST [48844] LOG: listening on IPv6 address "::",
port 5432
2023-07-12 16:15:30.175 CST [48844] LOG: listening on Unix socket
"/var/run/postgresql/.s.PGSQL.5432"
2023-07-12 16:15:30.177 CST [48844] LOG: listening on Unix socket
"/tmp/.s.PGSQL.5432"
2023-07-12 16:15:30.182 CST [48846] LOG: database system was shut down at
2023-07-12 16:09:59 CST
2023-07-12 16:15:30.188 CST [48844] LOG: database system is ready to
accept connections
Log of pgpool:
2023-07-12 16:15:42.369: main pid 48855: LOG:
health_check_stats_shared_memory_size: requested size: 12288
2023-07-12 16:15:42.369: main pid 48855: LOG: memory cache initialized
2023-07-12 16:15:42.369: main pid 48855: DETAIL: memcache blocks :64
2023-07-12 16:15:42.369: main pid 48855: LOG: allocating (136981824) bytes
of shared memory segment
2023-07-12 16:15:42.369: main pid 48855: LOG: allocating shared memory
segment of size: 136981824
2023-07-12 16:15:42.453: main pid 48855: LOG:
health_check_stats_shared_memory_size: requested size: 12288
2023-07-12 16:15:42.453: main pid 48855: LOG:
health_check_stats_shared_memory_size: requested size: 12288
2023-07-12 16:15:42.453: main pid 48855: LOG: memory cache initialized
2023-07-12 16:15:42.453: main pid 48855: DETAIL: memcache blocks :64
2023-07-12 16:15:42.458: main pid 48855: LOG: pool_discard_oid_maps:
discarded memqcache oid maps
2023-07-12 16:15:42.472: main pid 48855: LOG: unix_socket_directories[0]:
/run/.s.PGSQL.9999
2023-07-12 16:15:42.472: main pid 48855: LOG: listen address[0]: *
2023-07-12 16:15:42.472: main pid 48855: LOG: Setting up socket for
0.0.0.0:9999
2023-07-12 16:15:42.472: main pid 48855: LOG: Setting up socket for :::9999
2023-07-12 16:15:42.486: main pid 48855: LOG: listen address[0]: localhost
2023-07-12 16:15:42.487: main pid 48855: LOG: Setting up socket for
::1:9898
2023-07-12 16:15:42.487: main pid 48855: LOG: Setting up socket for
127.0.0.1:9898
2023-07-12 16:15:42.488: sr_check_worker pid 48893: LOG: process started
2023-07-12 16:15:42.488: pcp_main pid 48892: LOG: PCP process: 48892
started
2023-07-12 16:15:42.489: main pid 48855: LOG: pgpool-II successfully
started. version 4.4.3 (nurikoboshi)
2023-07-12 16:16:58.780: child pid 48874: FATAL: pgpool is not accepting
any new connections
2023-07-12 16:16:58.780: child pid 48874: DETAIL: all backend nodes are
down, pgpool requires at least one valid node
2023-07-12 16:16:58.780: child pid 48874: HINT: repair the backend nodes
and restart pgpool
2023-07-12 16:16:58.782: main pid 48855: LOG: reaper handler
2023-07-12 16:16:58.782: main pid 48855: LOG: reaper handler: exiting
normally
On Tue, Jul 11, 2023 at 4:41 PM Bo Peng <pengbo at sraoss.co.jp> wrote:
> Hi,
>
> > > > 2023-07-07 14:59:12.379: child pid 20684: DEBUG: forwarding error
> message to frontend
>
> Could you check the PostgreSQL log for "2023-07-07 14:59:12.379"?
>
> If it is possible, could you try to set "host all all 0.0.0.0/0
> trust" in pg_hba.conf
> and restart pgpool and postgresql?
>
> Could you show the command and result when you connect to pgpool?
>
> On Tue, 11 Jul 2023 14:26:58 +0800
> Zhaoxun Yan <yan.zhaoxun at gmail.com> wrote:
>
> > This is pg_hba.conf:
> > # TYPE DATABASE USER ADDRESS METHOD
> >
> > # "local" is for Unix domain socket connections only
> > local all all peer
> > # IPv4 local connections:
> > #host all all 127.0.0.1/32 ident
> > # IPv6 local connections:
> > #host all all ::1/128 ident
> > # Allow replication connections from localhost, by a user with the
> > # replication privilege.
> > local replication all peer
> > #host replication all 127.0.0.1/32 ident
> > #host replication all ::1/128 ident
> > host replication all 172.17.0.0/16 trust
> > #host template1 checker 0.0.0.0/0 trust
> > host all all 0.0.0.0/0 md5
> >
> > And attached is the postgresql log for 2023-7-15
> >
> > On Mon, Jul 10, 2023 at 5:44 PM Bo Peng <pengbo at sraoss.co.jp> wrote:
> >
> > > Hi,
> > >
> > > > I changed the configuration to process_management_mode =static,
> > > > and everything related to it as commented, but the mal-function
> persists.
> > > > Here is the log in debug mode:
> > >
> > > > 2023-07-07 14:59:12.379: child pid 20684: DEBUG: forwarding error
> > > message
> > > > to frontend
> > >
> > > It seems PostgreSQL returns an error.
> > >
> > > I think it may be caused by authentication failure.
> > > Could you check the PostgreSQL log if any error occurs?
> > >
> > > On Fri, 7 Jul 2023 15:03:46 +0800
> > > Zhaoxun Yan <yan.zhaoxun at gmail.com> wrote:
> > >
> > > > Hi Bo!
> > > >
> > > > I changed the configuration to process_management_mode =static,
> > > > and everything related to it as commented, but the mal-function
> persists.
> > > > Here is the log in debug mode:
> > > > 2023-07-07 14:58:48.964: main pid 20671: DEBUG: BackendDesc: 113672
> > > bytes
> > > > requested for shared memo
> > > > ry
> > > > 2023-07-07 14:58:48.964: main pid 20671: DEBUG: pool_coninfo_size:
> > > > num_init_children (32) * max_poo
> > > > l (4) * MAX_NUM_BACKENDS (128) * sizeof(ConnectionInfo) (160) =
> 2621440
> > > > bytes requested for shared m
> > > > emory
> > > > 2023-07-07 14:58:48.964: main pid 20671: DEBUG: ProcessInfo:
> > > > num_init_children (32) * sizeof(Proces
> > > > sInfo) (48) = 1536 bytes requested for shared memory
> > > > 2023-07-07 14:58:48.964: main pid 20671: DEBUG: UserSignalSlot: 24
> bytes
> > > > requested for shared memor
> > > > y
> > > > 2023-07-07 14:58:48.964: main pid 20671: DEBUG: POOL_REQUEST_INFO:
> 5272
> > > > bytes requested for shared
> > > > memory
> > > > 2023-07-07 14:58:48.964: main pid 20671: DEBUG:
> stat_shared_memory_size:
> > > > 9216 bytes requested for s
> > > > hared memory
> > > > 2023-07-07 14:58:48.964: main pid 20671: LOG:
> > > > health_check_stats_shared_memory_size: requested size
> > > > : 12288
> > > > 2023-07-07 14:58:48.964: main pid 20671: DEBUG: SI_ManageInfo: 24
> bytes
> > > > requested for shared memory
> > > > 2023-07-07 14:58:48.964: main pid 20671: LOG: memory cache
> initialized
> > > > 2023-07-07 14:58:48.964: main pid 20671: DETAIL: memcache blocks :64
> > > > 2023-07-07 14:58:48.964: main pid 20671: DEBUG:
> > > shared_memory_cache_size:
> > > > 67108864
> > > > 2023-07-07 14:58:48.964: main pid 20671: DEBUG:
> > > shared_memory_fsmm_size: 64
> > > > 2023-07-07 14:58:48.964: main pid 20671: DEBUG: pool_hash_size:
> 67108880
> > > > 2023-07-07 14:58:48.964: main pid 20671: DEBUG:
> POOL_QUERY_CACHE_STATS:
> > > 24
> > > > bytes requested for shared memory
> > > > 2023-07-07 14:58:48.964: main pid 20671: LOG: allocating (136981824)
> > > bytes
> > > > of shared memory segment
> > > > 2023-07-07 14:58:48.964: main pid 20671: LOG: allocating shared
> memory
> > > > segment of size: 136981824
> > > > 2023-07-07 14:58:49.041: main pid 20671: DEBUG: pool_coninfo_size:
> > > > num_init_children (32) * max_pool (4) * MAX_NUM_BACKENDS (128) *
> > > > sizeof(ConnectionInfo) (160) = 2621440 bytes requested for shared
> memory
> > > > 2023-07-07 14:58:49.041: main pid 20671: LOG:
> > > > health_check_stats_shared_memory_size: requested size: 12288
> > > > 2023-07-07 14:58:49.041: main pid 20671: LOG:
> > > > health_check_stats_shared_memory_size: requested size: 12288
> > > > 2023-07-07 14:58:49.041: main pid 20671: LOG: memory cache
> initialized
> > > > 2023-07-07 14:58:49.041: main pid 20671: DETAIL: memcache blocks :64
> > > > 2023-07-07 14:58:49.041: main pid 20671: DEBUG:
> > > shared_memory_cache_size:
> > > > 67108864
> > > > 2023-07-07 14:58:49.041: main pid 20671: DEBUG: memory cache request
> > > size
> > > > : 67108864
> > > > 2023-07-07 14:58:49.041: main pid 20671: DEBUG:
> > > shared_memory_fsmm_size: 64
> > > > 2023-07-07 14:58:49.044: main pid 20671: LOG: pool_discard_oid_maps:
> > > > discarded memqcache oid maps
> > > > 2023-07-07 14:58:49.058: main pid 20671: LOG:
> > > unix_socket_directories[0]:
> > > > /run/.s.PGSQL.9999
> > > > 2023-07-07 14:58:49.059: main pid 20671: LOG: listen address[0]: *
> > > > 2023-07-07 14:58:49.059: main pid 20671: LOG: Setting up socket for
> > > > 0.0.0.0:9999
> > > > 2023-07-07 14:58:49.059: main pid 20671: LOG: Setting up socket for
> > > :::9999
> > > > 2023-07-07 14:58:49.061: child pid 20680: DEBUG: initializing
> backend
> > > > status
> > > > 2023-07-07 14:58:49.061: child pid 20679: DEBUG: initializing
> backend
> > > > status
> > > > 2023-07-07 14:58:49.061: child pid 20678: DEBUG: initializing
> backend
> > > > status
> > > > 2023-07-07 14:58:49.061: child pid 20681: DEBUG: initializing
> backend
> > > > status
> > > > 2023-07-07 14:58:49.062: child pid 20677: DEBUG: initializing
> backend
> > > > status
> > > > 2023-07-07 14:58:49.062: child pid 20682: DEBUG: initializing
> backend
> > > > status
> > > > 2023-07-07 14:58:49.062: child pid 20683: DEBUG: initializing
> backend
> > > > status
> > > > 2023-07-07 14:58:49.062: child pid 20676: DEBUG: initializing
> backend
> > > > status
> > > > 2023-07-07 14:58:49.064: child pid 20684: DEBUG: initializing
> backend
> > > > status
> > > > 2023-07-07 14:58:49.064: child pid 20685: DEBUG: initializing
> backend
> > > > status
> > > > 2023-07-07 14:58:49.064: child pid 20686: DEBUG: initializing
> backend
> > > > status
> > > > 2023-07-07 14:58:49.064: child pid 20675: DEBUG: initializing
> backend
> > > > status
> > > > 2023-07-07 14:58:49.067: child pid 20697: DEBUG: initializing
> backend
> > > > status
> > > > 2023-07-07 14:58:49.067: child pid 20698: DEBUG: initializing
> backend
> > > > status
> > > > 2023-07-07 14:58:49.067: child pid 20699: DEBUG: initializing
> backend
> > > > status
> > > > 2023-07-07 14:58:49.067: child pid 20700: DEBUG: initializing
> backend
> > > > status
> > > > 2023-07-07 14:58:49.068: child pid 20674: DEBUG: initializing
> backend
> > > > status
> > > > 2023-07-07 14:58:49.069: main pid 20671: DEBUG:
> > > > find_primary_node_repeatedly: not in streaming replication mode
> > > > 2023-07-07 14:58:49.069: main pid 20671: LOG: listen address[0]:
> > > localhost
> > > > 2023-07-07 14:58:49.069: main pid 20671: LOG: Setting up socket for
> > > > ::1:9898
> > > > 2023-07-07 14:58:49.069: main pid 20671: LOG: Setting up socket for
> > > > 127.0.0.1:9898
> > > > 2023-07-07 14:58:49.069: child pid 20701: DEBUG: initializing
> backend
> > > > status
> > > > 2023-07-07 14:58:49.070: child pid 20705: DEBUG: initializing
> backend
> > > > status
> > > > 2023-07-07 14:58:49.070: child pid 20704: DEBUG: initializing
> backend
> > > > status
> > > > 2023-07-07 14:58:49.070: sr_check_worker pid 20707: LOG: process
> started
> > > > 2023-07-07 14:58:49.070: pcp_main pid 20706: DEBUG: I am PCP child
> with
> > > > pid:20706
> > > > 2023-07-07 14:58:49.070: sr_check_worker pid 20707: DEBUG: I am
> 20707
> > > > 2023-07-07 14:58:49.070: main pid 20671: LOG: pgpool-II successfully
> > > > started. version 4.4.3 (nurikoboshi)
> > > > 2023-07-07 14:58:49.070: child pid 20703: DEBUG: initializing
> backend
> > > > status
> > > > 2023-07-07 14:58:49.070: pcp_main pid 20706: LOG: PCP process: 20706
> > > > started
> > > > 2023-07-07 14:58:49.071: child pid 20702: DEBUG: initializing
> backend
> > > > status
> > > > 2023-07-07 14:59:12.379: child pid 20684: DEBUG: reading startup
> packet
> > > > 2023-07-07 14:59:12.379: child pid 20684: DETAIL: Protocol Major:
> 1234
> > > > Minor: 5679 database: user:
> > > > 2023-07-07 14:59:12.379: child pid 20684: DEBUG: forwarding error
> > > message
> > > > to frontend
> > > > 2023-07-07 14:59:12.379: child pid 20684: FATAL: pgpool is not
> accepting
> > > > any new connections
> > > > 2023-07-07 14:59:12.379: child pid 20684: DETAIL: all backend nodes
> are
> > > > down, pgpool requires at least one valid node
> > > > 2023-07-07 14:59:12.379: child pid 20684: HINT: repair the backend
> nodes
> > > > and restart pgpool
> > > > 2023-07-07 14:59:12.380: main pid 20671: LOG: reaper handler
> > > > 2023-07-07 14:59:12.380: main pid 20671: DEBUG: child process with
> pid:
> > > > 20684 exits with status 256
> > > > 2023-07-07 14:59:12.380: main pid 20671: DEBUG: fork a new child
> process
> > > > with pid: 20711
> > > > 2023-07-07 14:59:12.380: main pid 20671: LOG: reaper handler:
> exiting
> > > > normally
> > > > 2023-07-07 14:59:12.380: child pid 20711: DEBUG: initializing
> backend
> > > > status
> > > >
> > > > And attached is the new configuration.
> > > >
> > > > On Wed, Jul 5, 2023 at 3:58 PM Bo Peng <pengbo at sraoss.co.jp> wrote:
> > > >
> > > > > Hi,
> > > > >
> > > > > Thank you for sharing the configuration file.
> > > > >
> > > > > You are using "dynamic process management mode".
> > > > > It seems if max_spare_children is greater than num_init_children,
> > > > > segment fault occurs.
> > > > >
> > > > > I think it is a bug of pgpool.
> > > > > I will share your report with the developer who is in charge of
> dynamic
> > > > > process management mode.
> > > > >
> > > > > On Wed, 5 Jul 2023 13:39:51 +0800
> > > > > Zhaoxun Yan <yan.zhaoxun at gmail.com> wrote:
> > > > >
> > > > > > On Wed, Jul 5, 2023 at 1:00 PM Bo Peng <pengbo at sraoss.co.jp>
> wrote:
> > > > > >
> > > > > > > Hi,
> > > > > > >
> > > > > > > I tested 4.4.3 and it should not happen normally.
> > > > > > > Could you share your pgpool.conf?
> > > > > > >
> > > > > > > On Wed, 5 Jul 2023 12:03:29 +0800
> > > > > > > Zhaoxun Yan <yan.zhaoxun at gmail.com> wrote:
> > > > > > >
> > > > > > > > Hi guys!
> > > > > > > >
> > > > > > > > Is it a bug? I started local postgres as backend_hostname0 =
> > > > > > > '172.17.0.2'
> > > > > > > > And it is visitable:
> > > > > > > > # psql -h 172.17.0.2 -p 5432 -U checker template1
> > > > > > > > Password for user checker:
> > > > > > > > psql (13.10)
> > > > > > > > Type "help" for help.
> > > > > > > >
> > > > > > > > template1=> \q
> > > > > > > >
> > > > > > > > Although pgpool is listening on 9999:
> > > > > > > > # ss -tlnp
> > > > > > > > State Recv-Q Send-Q Local
> Address:Port
> > > > > > > > Peer Address:Port Process
> > > > > > > > LISTEN 0 244
> 0.0.0.0:5432
> > > > > > > > 0.0.0.0:* users:(("postgres",pid=8680,fd=6))
> > > > > > > > LISTEN 0 64
> 127.0.0.1:9898
> > > > > > > > 0.0.0.0:*
> > > > > > > >
> > > > > > >
> > > > >
> > >
> users:(("pgpool",pid=8780,fd=11),("pgpool",pid=8773,fd=11),("pgpool",pid=8720,fd=11))
> > > > > > > > LISTEN 0 64
> 0.0.0.0:9999
> > > > > > > > 0.0.0.0:*
> > > > > > > >
> > > > > > >
> > > > >
> > >
> users:(("pgpool",pid=8780,fd=5),("pgpool",pid=8773,fd=5),("pgpool",pid=8754,fd=5),("pgpool",pid=8753,fd=5),("pgpool",pid=8752,fd=5),("pgpool",pid=8751,fd=5),("pgpool",pid=8750,fd=5),("pgpool",pid=8749,fd=5),("pgpool",pid=8748,fd=5),("pgpool",pid=8747,fd=5),("pgpool",pid=8746,fd=5),("pgpool",pid=8745,fd=5),("pgpool",pid=8744,fd=5),("pgpool",pid=8742,fd=5),("pgpool",pid=8741,fd=5),("pgpool",pid=8740,fd=5),("pgpool",pid=8739,fd=5),("pgpool",pid=8738,fd=5),("pgpool",pid=8737,fd=5),("pgpool",pid=8736,fd=5),("pgpool",pid=8735,fd=5),("pgpool",pid=8734,fd=5),("pgpool",pid=8733,fd=5),("pgpool",pid=8732,fd=5),("pgpool",pid=8731,fd=5),("pgpool",pid=8730,fd=5),("pgpool",pid=8729,fd=5),("pgpool",pid=8728,fd=5),("pgpool",pid=8727,fd=5),("pgpool",pid=8726,fd=5),("pgpool",pid=8724,fd=5),("pgpool",pid=8723,fd=5),("pgpool",pid=8720,fd=5))
> > > > > > > > LISTEN 0 128
> 0.0.0.0:22
> > > > > > > > 0.0.0.0:* users:(("sshd",pid=1395,fd=3))
> > > > > > > > LISTEN 0 244
> [::]:5432
> > > > > > > > [::]:* users:(("postgres",pid=8680,fd=7))
> > > > > > > > LISTEN 0 64
> [::1]:9898
> > > > > > > > [::]:*
> > > > > > > >
> > > > > > >
> > > > >
> > >
> users:(("pgpool",pid=8780,fd=10),("pgpool",pid=8773,fd=10),("pgpool",pid=8720,fd=10))
> > > > > > > > LISTEN 0 64
> [::]:9999
> > > > > > > > [::]:*
> > > > > > > >
> > > > > > >
> > > > >
> > >
> users:(("pgpool",pid=8780,fd=6),("pgpool",pid=8773,fd=6),("pgpool",pid=8754,fd=6),("pgpool",pid=8753,fd=6),("pgpool",pid=8752,fd=6),("pgpool",pid=8751,fd=6),("pgpool",pid=8750,fd=6),("pgpool",pid=8749,fd=6),("pgpool",pid=8748,fd=6),("pgpool",pid=8747,fd=6),("pgpool",pid=8746,fd=6),("pgpool",pid=8745,fd=6),("pgpool",pid=8744,fd=6),("pgpool",pid=8742,fd=6),("pgpool",pid=8741,fd=6),("pgpool",pid=8740,fd=6),("pgpool",pid=8739,fd=6),("pgpool",pid=8738,fd=6),("pgpool",pid=8737,fd=6),("pgpool",pid=8736,fd=6),("pgpool",pid=8735,fd=6),("pgpool",pid=8734,fd=6),("pgpool",pid=8733,fd=6),("pgpool",pid=8732,fd=6),("pgpool",pid=8731,fd=6),("pgpool",pid=8730,fd=6),("pgpool",pid=8729,fd=6),("pgpool",pid=8728,fd=6),("pgpool",pid=8727,fd=6),("pgpool",pid=8726,fd=6),("pgpool",pid=8724,fd=6),("pgpool",pid=8723,fd=6),("pgpool",pid=8720,fd=6))
> > > > > > > > LISTEN 0 128 [::]:22
> > > > > > > > [::]:* users:(("sshd",pid=1395,fd=4))
> > > > > > > >
> > > > > > > > It is not visitable:
> > > > > > > > # psql -h 127.0.0.1 -p 9999 -U checker template1
> > > > > > > > psql: error: server closed the connection unexpectedly
> > > > > > > > This probably means the server terminated abnormally
> > > > > > > > before or while processing the request.
> > > > > > > > Checking out the log, any pgpool subprocess is killed by
> segment
> > > > > fault.
> > > > > > > > And I run it again using debug mode, the same thing happens.
> > > > > > > > Attached is the pgpool log. Thanks in advance.
> > > > > > >
> > > > > > >
> > > > > > > --
> > > > > > > Bo Peng <pengbo at sraoss.co.jp>
> > > > > > > SRA OSS LLC
> > > > > > > TEL: 03-5979-2701 FAX: 03-5979-2702
> > > > > > > URL: https://www.sraoss.co.jp/
> > > > > > >
> > > > >
> > > > >
> > > > > --
> > > > > Bo Peng <pengbo at sraoss.co.jp>
> > > > > SRA OSS LLC
> > > > > TEL: 03-5979-2701 FAX: 03-5979-2702
> > > > > URL: https://www.sraoss.co.jp/
> > > > >
> > >
> > >
> > > --
> > > Bo Peng <pengbo at sraoss.co.jp>
> > > SRA OSS LLC
> > > TEL: 03-5979-2701 FAX: 03-5979-2702
> > > URL: https://www.sraoss.co.jp/
> > >
>
>
> --
> Bo Peng <pengbo at sraoss.co.jp>
> SRA OSS LLC
> TEL: 03-5979-2701 FAX: 03-5979-2702
> URL: https://www.sraoss.co.jp/
>
-------------- next part --------------
An HTML attachment was scrubbed...
URL: <http://www.pgpool.net/pipermail/pgpool-general/attachments/20230712/2998c6c9/attachment.htm>
More information about the pgpool-general
mailing list