[Pgpool-general] hanging pgpool processes during massive UPDATEs

Wed Oct 10 15:12:53 UTC 2007

Hi,

we are experiencing some strange problems with pgpool-II-1.2.1 on CentOS 4.5
running version 2.6.9 of the Linux kernel. During massive UPDATEs, which are
interrupted by user interaction, some pgpool processes start consuming all
CPU time. System load goes up to N, where N denotes the count of hanging
pgpool processes. Strace shows no output if attached to one of these
processes. `ps ax` still shows these pgpool processes with their client
connection info and current action (UPDATE) as process title. But there
aren't any active PostgreSQL processes on the backend servers. We don't see
any errors in the debug log. So I assume that pgpool goes into some kind of
an endless loop.
Below I have included the last few lines from a grep for "pid <PID>" through
the debug logfile (with SQL statements scrambled):

2007-10-10 15:18:56 DEBUG: pid 445: pool_read_message_length: slot: 2
length: 5
2007-10-10 15:18:56 DEBUG: pid 445: ReadyForQuery: message length: 5
2007-10-10 15:18:56 DEBUG: pid 445: ReadyForQuery: transaction state: I
2007-10-10 15:18:56 DEBUG: pid 445: end_load_balance: end load balance mode
2007-10-10 15:18:56 DEBUG: pid 445: pool_process_query: num_fds: 11
2007-10-10 15:18:56 DEBUG: pid 445: read kind from frontend Q(51)
2007-10-10 15:18:56 DEBUG: pid 445: statement2: SELECT * FROM ... LIMIT 1
OFFSET 0
2007-10-10 15:18:56 DEBUG: pid 445: waiting for backend 2 completing the
query
2007-10-10 15:18:56 DEBUG: pid 445: read_kind_from_backend: read kind from 2
th backend T NUM_BACKENDS: 3
2007-10-10 15:18:56 DEBUG: pid 445: pool_process_query: kind from backend: T
2007-10-10 15:18:56 DEBUG: pid 445: read_kind_from_backend: read kind from 2
th backend D NUM_BACKENDS: 3
2007-10-10 15:18:56 DEBUG: pid 445: pool_process_query: kind from backend: D
2007-10-10 15:18:56 DEBUG: pid 445: read_kind_from_backend: read kind from 2
th backend C NUM_BACKENDS: 3
2007-10-10 15:18:56 DEBUG: pid 445: pool_process_query: kind from backend: C
2007-10-10 15:18:56 DEBUG: pid 445: read_kind_from_backend: read kind from 2
th backend Z NUM_BACKENDS: 3
2007-10-10 15:18:56 DEBUG: pid 445: pool_process_query: kind from backend: Z
2007-10-10 15:18:56 DEBUG: pid 445: pool_read_message_length: slot: 2
length: 5
2007-10-10 15:18:56 DEBUG: pid 445: ReadyForQuery: message length: 5
2007-10-10 15:18:56 DEBUG: pid 445: ReadyForQuery: transaction state: I
2007-10-10 15:18:56 DEBUG: pid 445: end_load_balance: end load balance mode
2007-10-10 15:18:56 DEBUG: pid 445: pool_process_query: num_fds: 11
2007-10-10 15:18:56 DEBUG: pid 445: read kind from frontend Q(51)
2007-10-10 15:18:56 DEBUG: pid 445: statement2: UPDATE ...

This one looks very strange as "statement2" is empty:

2007-10-10 15:20:54 DEBUG: pid 559: waiting for backend 0 completing the
query
2007-10-10 15:20:54 DEBUG: pid 559: read_kind_from_backend: read kind from 0
th backend T NUM_BACKENDS: 1
2007-10-10 15:20:54 DEBUG: pid 559: pool_process_query: kind from backend: T
2007-10-10 15:20:54 DEBUG: pid 559: read_kind_from_backend: read kind from 0
th backend C NUM_BACKENDS: 1
2007-10-10 15:20:54 DEBUG: pid 559: pool_process_query: kind from backend: C
2007-10-10 15:20:54 DEBUG: pid 559: read_kind_from_backend: read kind from 0
th backend Z NUM_BACKENDS: 1
2007-10-10 15:20:54 DEBUG: pid 559: pool_process_query: kind from backend: Z
2007-10-10 15:20:54 DEBUG: pid 559: pool_read_message_length: slot: 0
length: 5
2007-10-10 15:20:54 DEBUG: pid 559: ReadyForQuery: message length: 5
2007-10-10 15:20:54 DEBUG: pid 559: ReadyForQuery: transaction state: I
2007-10-10 15:20:54 DEBUG: pid 559: end_load_balance: end load balance mode
2007-10-10 15:20:54 DEBUG: pid 559: pool_process_query: num_fds: 11
2007-10-10 15:20:54 DEBUG: pid 559: read kind from frontend Q(51)
2007-10-10 15:20:54 DEBUG: pid 559: statement2:
2007-10-10 15:20:54 DEBUG: pid 559: waiting for backend 0 completing the
query
2007-10-10 15:20:54 DEBUG: pid 559: read_kind_from_backend: read kind from 0
th backend T NUM_BACKENDS: 1
2007-10-10 15:20:54 DEBUG: pid 559: pool_process_query: kind from backend: T
2007-10-10 15:20:54 DEBUG: pid 559: read_kind_from_backend: read kind from 0
th backend D NUM_BACKENDS: 1
2007-10-10 15:20:54 DEBUG: pid 559: pool_process_query: kind from backend: D
2007-10-10 15:20:54 DEBUG: pid 559: read_kind_from_backend: read kind from 0
th backend C NUM_BACKENDS: 1
2007-10-10 15:20:54 DEBUG: pid 559: pool_process_query: kind from backend: C
2007-10-10 15:20:54 DEBUG: pid 559: read_kind_from_backend: read kind from 0
th backend Z NUM_BACKENDS: 1
2007-10-10 15:20:54 DEBUG: pid 559: pool_process_query: kind from backend: Z
2007-10-10 15:20:54 DEBUG: pid 559: pool_read_message_length: slot: 0
length: 5
2007-10-10 15:20:54 DEBUG: pid 559: ReadyForQuery: message length: 5
2007-10-10 15:20:54 DEBUG: pid 559: ReadyForQuery: transaction state: I
2007-10-10 15:20:54 DEBUG: pid 559: end_load_balance: end load balance mode
2007-10-10 15:20:54 DEBUG: pid 559: pool_process_query: num_fds: 11
2007-10-10 15:20:54 DEBUG: pid 559: read kind from frontend Q(51)
2007-10-10 15:20:54 DEBUG: pid 559: statement2:

Any ideas?

TIA
Felix