[pgpool-general: 2445] Segfault in pgpool triggered by a background query

Kristjan Siimson kristjan.siimson at cashongo.co.uk
Fri Jan 17 22:19:53 JST 2014


Sorry, my previous e-mail was sort of useless, I really did have an invalid
query, so my description was misleading.

I did some more digging and found this:

2014-01-17 13:34:04 DEBUG: pid 3668: ProcessFrontendResponse: kind from
frontend Q(51)
2014-01-17 13:34:04 DEBUG: pid 3668:
pool_unset_doing_extended_query_message: done
2014-01-17 13:34:04 DEBUG: pid 3668: statement2: insert into account (id,
bid, balance, filler) values (1, 1, 0.0, "FRESH ACCOUNT");
2014-01-17 13:34:04 DEBUG: pid 3668: pool_set_query_in_progress: done
2014-01-17 13:34:04 DEBUG: pid 3668: do_query: extended:0 query:SELECT
count(*) from (SELECT has_function_privilege('kristjan',
'pgpool_regclass(cstring)', 'execute') WHERE EXISTS(SELECT * FROM
pg_catalog.pg_proc AS p WHERE p.proname = 'pgpool_regclass')) AS s
2014-01-17 13:34:04 ERROR: pid 3668: pool_read: EOF encountered with
backend
2014-01-17 13:34:04 ERROR: pid 3668: do_query: error while reading message
kind
2014-01-17 13:34:04 ERROR: pid 3668: pool_search_relcache: do_query failed
2014-01-17 13:34:04 DEBUG: pid 3668: do_query: extended:0 query:SELECT
attname, d.adsrc, coalesce((d.adsrc LIKE '%now()%' OR d.adsrc LIKE
'%''now''::text%') AND (a.atttypid = 'timestamp'::regtype::oid OR
a.atttypid = 'timestamp with time zone'::regtype::oid OR a.atttypid =
'date'::regtype::oid OR a.atttypid = 'time'::regtype::oid OR a.atttypid =
'time with time zone'::regtype::oid) , false) FROM pg_catalog.pg_class c,
pg_catalog.pg_attribute a  LEFT JOIN pg_catalog.pg_attrdef d ON (a.attrelid
= d.adrelid AND a.attnum = d.adnum) WHERE c.oid = a.attrelid AND a.attnum
>= 1 AND a.attisdropped = 'f' AND c.relname = 'account' ORDER BY a.attnum
2014-01-17 13:34:04 ERROR: pid 3668: pool_read: EOF encountered with
backend
2014-01-17 13:34:04 ERROR: pid 3668: do_query: error while reading message
kind
2014-01-17 13:34:04 ERROR: pid 3668: pool_search_relcache: do_query failed
2014-01-17 13:34:04 DEBUG: pid 3668: wait_for_query_response: waiting for
backend 1 completing the query
2014-01-17 13:34:04 ERROR: pid 3668: pool_read: EOF encountered with
backend
2014-01-17 13:34:04 ERROR: pid 3668: pool_read: EOF encountered with
backend
2014-01-17 13:34:04 ERROR: pid 3668: pool_read: EOF encountered with
backend
2014-01-17 13:34:04 ERROR: pid 3668: pool_read: EOF encountered with
backend
2014-01-17 13:34:04 ERROR: pid 3668: pool_read: EOF encountered with
backend
2014-01-17 13:34:04 ERROR: pid 3668: pool_read: EOF encountered with
backend
2014-01-17 13:34:04 ERROR: pid 3668: read_kind_from_backend: failed to read
kind from 1 th backend
2014-01-17 13:34:04 LOG:   pid 3668: do_child: exits with status 1 due to
error
2014-01-17 13:34:04 ERROR: pid 3668: pool_flush_it: write failed to backend
(1). reason: Broken pipe offset: 0 wlen: 5
2014-01-17 13:34:04 DEBUG: pid 3671: I am 3671 accept fd 6
2014-01-17 13:34:04 DEBUG: pid 3671: read_startup_packet: application_name:
psql
2014-01-17 13:34:04 DEBUG: pid 3671: Protocol Major: 3 Minor: 0 database:
bench_parallel user: kristjan
2014-01-17 13:34:04 DEBUG: pid 3671: new_connection: connecting 0 backend
2014-01-17 13:34:04 DEBUG: pid 3671: new_connection: skipping slot 0
because backend_status = 3
2014-01-17 13:34:04 DEBUG: pid 3671: new_connection: connecting 1 backend
2014-01-17 13:34:04 DEBUG: pid 3671: pool_ssl: SSL requested but SSL
support is not available
2014-01-17 13:34:04 DEBUG: pid 3639: reap_handler called
2014-01-17 13:34:04 DEBUG: pid 3639: reap_handler: call wait3
2014-01-17 13:34:04 DEBUG: pid 3639: child 3668 exits with status 256
2014-01-17 13:34:04 DEBUG: pid 3639: fork a new child pid 3675
2014-01-17 13:34:04 DEBUG: pid 3639: reap_handler: normally exited
2014-01-17 13:34:04 DEBUG: pid 3675: I am 3675
2014-01-17 13:34:04 DEBUG: pid 3675:
pool_initialize_private_backend_status: initialize backend status
2014-01-17 13:34:04 DEBUG: pid 3671: pool_read_message_length: slot: 1
length: 8
2014-01-17 13:34:04 DEBUG: pid 3671: pool_do_auth: auth kind:0
2014-01-17 13:34:04 DEBUG: pid 3671: pool_read_message_length2: master
slot: 1 length: 26
2014-01-17 13:34:04 DEBUG: pid 3671: 1 th backend: name: application_name
value: psql
2014-01-17 13:34:04 DEBUG: pid 3671: pool_read_message_length2: master
slot: 1 length: 25
2014-01-17 13:34:04 DEBUG: pid 3671: 1 th backend: name: client_encoding
value: UTF8
2014-01-17 13:34:04 DEBUG: pid 3671: pool_read_message_length2: master
slot: 1 length: 23
2014-01-17 13:34:04 DEBUG: pid 3671: 1 th backend: name: DateStyle value:
ISO, MDY
2014-01-17 13:34:04 DEBUG: pid 3671: pool_read_message_length2: master
slot: 1 length: 25
2014-01-17 13:34:04 DEBUG: pid 3671: 1 th backend: name: integer_datetimes
value: on
2014-01-17 13:34:04 DEBUG: pid 3671: pool_read_message_length2: master
slot: 1 length: 27
2014-01-17 13:34:04 DEBUG: pid 3671: 1 th backend: name: IntervalStyle
value: postgres
2014-01-17 13:34:04 DEBUG: pid 3671: pool_read_message_length2: master
slot: 1 length: 20
2014-01-17 13:34:04 DEBUG: pid 3671: 1 th backend: name: is_superuser
value: on
2014-01-17 13:34:04 DEBUG: pid 3671: pool_read_message_length2: master
slot: 1 length: 25

And with more digging I found that pgpool really does not "like" the
following query regardless of whether the backend was another instance of
pgpool or a Postgre server:

Query:

bench_parallel=# SELECT count(*) from (SELECT
has_function_privilege('kristjan', 'pgpool_regclass(cstring)', 'execute')
WHERE EXISTS(SELECT * FROM pg_catalog.pg_proc AS p WHERE p.proname =
'pgpool_regclass')) AS s;
The connection to the server was lost. Attempting reset: Succeeded.

Output from pgpool daemon in debug mode, note the segfault:

2014-01-17 15:01:52 DEBUG: pid 3569: ProcessFrontendResponse: kind from
frontend Q(51)
2014-01-17 15:01:52 DEBUG: pid 3569:
pool_unset_doing_extended_query_message: done
2014-01-17 15:01:52 DEBUG: pid 3569: statement2: SELECT count(*) from
(SELECT has_function_privilege('kristjan', 'pgpool_regclass(cstring)',
'execute') WHERE EXISTS(SELECT * FROM pg_catalog.pg_proc AS p WHERE
p.proname = 'pgpool_regclass')) AS s;
2014-01-17 15:01:52 DEBUG: pid 3569: pool_set_query_in_progress: done
2014-01-17 15:01:52 DEBUG: pid 3569: initSelectStmt: ANALYZE now(0)
2014-01-17 15:01:52 DEBUG: pid 3569: initSelectStmt: ANALYZE now(1)
2014-01-17 15:01:52 DEBUG: pid 3569: inside build_range_info num= 1
current_select=1
2014-01-17 15:01:52 DEBUG: pid 3569: inside build_range_info const or func
1
2014-01-17 15:01:52 DEBUG: pid 3569: initSelectStmt: ANALYZE now(2)
2014-01-17 15:01:52 DEBUG: pid 3569: inside build_range_info num= 1
current_select=2
2014-01-17 15:01:52 DEBUG: pid 3569: inside build_range_info const or func
2
2014-01-17 15:01:52 DEBUG: pid 3569: inside build_virtual_info no dist
state=E p
2014-01-17 15:01:52 DEBUG: pid 3556: I am 3556 accept fd 10
2014-01-17 15:01:52 DEBUG: pid 3556: read_startup_packet: application_name:
psql
2014-01-17 15:01:52 DEBUG: pid 3556: Protocol Major: 3 Minor: 0 database:
bench_parallel user: kristjan
2014-01-17 15:01:52 DEBUG: pid 3556: new_connection: connecting 0 backend
2014-01-17 15:01:52 DEBUG: pid 3556: new_connection: connecting 1 backend
2014-01-17 15:01:52 DEBUG: pid 3556: pool_ssl: SSL requested but SSL
support is not available
2014-01-17 15:01:52 DEBUG: pid 3556: pool_ssl: SSL requested but SSL
support is not available
2014-01-17 15:01:52 DEBUG: pid 3516: reap_handler called
2014-01-17 15:01:52 DEBUG: pid 3516: reap_handler: call wait3
2014-01-17 15:01:52 ERROR: pid 3516: Child process 3569 was terminated by
segmentation fault
2014-01-17 15:01:52 DEBUG: pid 3516: child 3569 exits with status 11 by
signal 11
2014-01-17 15:01:52 DEBUG: pid 3516: fork a new child pid 3570
2014-01-17 15:01:52 DEBUG: pid 3516: reap_handler: normally exited
2014-01-17 15:01:52 DEBUG: pid 3570: I am 3570
2014-01-17 15:01:52 DEBUG: pid 3570:
pool_initialize_private_backend_status: initialize backend status
2014-01-17 15:01:52 DEBUG: pid 3556: pool_read_message_length: slot: 0
length: 8
2014-01-17 15:01:52 DEBUG: pid 3556: pool_read_message_length: slot: 1
length: 8
2014-01-17 15:01:52 DEBUG: pid 3556: pool_do_auth: auth kind:0
2014-01-17 15:01:52 DEBUG: pid 3556: pool_read_message_length2: master
slot: 0 length: 26
2014-01-17 15:01:52 DEBUG: pid 3556: pool_read_message_length2: master
slot: 1 length: 26
2014-01-17 15:01:52 DEBUG: pid 3556: 0 th backend: name: application_name
value: psql
2014-01-17 15:01:52 DEBUG: pid 3556: 1 th backend: name: application_name
value: psql
2014-01-17 15:01:52 DEBUG: pid 3556: pool_read_message_length2: master
slot: 0 length: 25
2014-01-17 15:01:52 DEBUG: pid 3556: pool_read_message_length2: master
slot: 1 length: 25
2014-01-17 15:01:52 DEBUG: pid 3556: 0 th backend: name: client_encoding
value: UTF8
2014-01-17 15:01:52 DEBUG: pid 3556: 1 th backend: name: client_encoding
value: UTF8
2014-01-17 15:01:52 DEBUG: pid 3556: pool_read_message_length2: master
slot: 0 length: 23
2014-01-17 15:01:52 DEBUG: pid 3556: pool_read_message_length2: master
slot: 1 length: 23
2014-01-17 15:01:52 DEBUG: pid 3556: 0 th backend: name: DateStyle value:
ISO, MDY
2014-01-17 15:01:52 DEBUG: pid 3556: 1 th backend: name: DateStyle value:
ISO, MDY
2014-01-17 15:01:52 DEBUG: pid 3556: pool_read_message_length2: master
slot: 0 length: 25
2014-01-17 15:01:52 DEBUG: pid 3556: pool_read_message_length2: master
slot: 1 length: 25
2014-01-17 15:01:52 DEBUG: pid 3556: 0 th backend: name: integer_datetimes
value: on
2014-01-17 15:01:52 DEBUG: pid 3556: 1 th backend: name: integer_datetimes
value: on
2014-01-17 15:01:52 DEBUG: pid 3556: pool_read_message_length2: master
slot: 0 length: 27
2014-01-17 15:01:52 DEBUG: pid 3556: pool_read_message_length2: master
slot: 1 length: 27
2014-01-17 15:01:52 DEBUG: pid 3556: 0 th backend: name: IntervalStyle
value: postgres
2014-01-17 15:01:52 DEBUG: pid 3556: 1 th backend: name: IntervalStyle
value: postgres
2014-01-17 15:01:52 DEBUG: pid 3556: pool_read_message_length2: master
slot: 0 length: 20
2014-01-17 15:01:52 DEBUG: pid 3556: pool_read_message_length2: master
slot: 1 length: 20
2014-01-17 15:01:52 DEBUG: pid 3556: 0 th backend: name: is_superuser
value: on
2014-01-17 15:01:52 DEBUG: pid 3556: 1 th backend: name: is_superuser
value: on
2014-01-17 15:01:52 DEBUG: pid 3556: pool_read_message_length2: master
slot: 0 length: 25
2014-01-17 15:01:52 DEBUG: pid 3556: pool_read_message_length2: master
slot: 1 length: 25
2014-01-17 15:01:52 DEBUG: pid 3556: 0 th backend: name: server_encoding
value: UTF8
2014-01-17 15:01:52 DEBUG: pid 3556: 1 th backend: name: server_encoding
value: UTF8
2014-01-17 15:01:52 DEBUG: pid 3556: pool_read_message_length2: master
slot: 0 length: 25
2014-01-17 15:01:52 DEBUG: pid 3556: pool_read_message_length2: master
slot: 1 length: 25
2014-01-17 15:01:52 DEBUG: pid 3556: 0 th backend: name: server_version
value: 9.3.2
2014-01-17 15:01:52 DEBUG: pid 3556: 1 th backend: name: server_version
value: 9.3.2
2014-01-17 15:01:52 DEBUG: pid 3556: pool_read_message_length2: master
slot: 0 length: 35
2014-01-17 15:01:52 DEBUG: pid 3556: pool_read_message_length2: master
slot: 1 length: 35
2014-01-17 15:01:52 DEBUG: pid 3556: 0 th backend: name:
session_authorization value: kristjan
2014-01-17 15:01:52 DEBUG: pid 3556: 1 th backend: name:
session_authorization value: kristjan
2014-01-17 15:01:52 DEBUG: pid 3556: pool_read_message_length2: master
slot: 0 length: 35
2014-01-17 15:01:52 DEBUG: pid 3556: pool_read_message_length2: master
slot: 1 length: 35
2014-01-17 15:01:52 DEBUG: pid 3556: 0 th backend: name:
standard_conforming_strings value: on
2014-01-17 15:01:52 DEBUG: pid 3556: 1 th backend: name:
standard_conforming_strings value: on
2014-01-17 15:01:52 DEBUG: pid 3556: pool_read_message_length2: master
slot: 0 length: 28
2014-01-17 15:01:52 DEBUG: pid 3556: pool_read_message_length2: master
slot: 1 length: 28
2014-01-17 15:01:52 DEBUG: pid 3556: 0 th backend: name: TimeZone value:
Europe/Tallinn
2014-01-17 15:01:52 DEBUG: pid 3556: 1 th backend: name: TimeZone value:
Europe/Tallinn
2014-01-17 15:01:52 DEBUG: pid 3556: pool_read_message_length: slot: 0
length: 12
2014-01-17 15:01:52 DEBUG: pid 3556: pool_read_message_length: slot: 1
length: 12
2014-01-17 15:01:52 DEBUG: pid 3556: pool_do_auth:
cp->info[i]:0x7f5eca6b7000 pid:10951
2014-01-17 15:01:52 DEBUG: pid 3556: pool_do_auth:
cp->info[i]:0x7f5eca6b7088 pid:10298
2014-01-17 15:01:52 DEBUG: pid 3556: pool_send_auth_ok: send pid 10298 to
frontend
2014-01-17 15:01:52 DEBUG: pid 3556: select_load_balancing_node: selected
backend id is 1
2014-01-17 15:01:52 DEBUG: pid 3556: selected load balancing node: 1
2014-01-17 15:01:52 DEBUG: pid 3556: pool_unset_query_in_progress: done
2014-01-17 15:01:52 DEBUG: pid 3556: pool_unset_command_success: done
2014-01-17 15:01:52 DEBUG: pid 3556: pool_unset_writing_transaction: done
2014-01-17 15:01:52 DEBUG: pid 3556: pool_unset_failed_transaction: done
2014-01-17 15:01:52 DEBUG: pid 3556: pool_unset_transaction_isolation: done
2014-01-17 15:01:52 DEBUG: pid 3556: pool_unset_skip_reading_from_backends:
done
2014-01-17 15:01:52 DEBUG: pid 3556: pool_unset_ignore_till_sync: done
2014-01-17 15:01:52 DEBUG: pid 3556: read_kind_from_backend: kind: Z from 0
th backend
2014-01-17 15:01:52 DEBUG: pid 3556: read_kind_from_backend: read kind from
0 th backend Z NUM_BACKENDS: 2
2014-01-17 15:01:52 DEBUG: pid 3556: read_kind_from_backend: kind: Z from 1
th backend
2014-01-17 15:01:52 DEBUG: pid 3556: read_kind_from_backend: read kind from
1 th backend Z NUM_BACKENDS: 2
2014-01-17 15:01:52 DEBUG: pid 3556: ProcessBackendResponse: kind from
backend: Z
2014-01-17 15:01:52 DEBUG: pid 3556: pool_read_message_length: slot: 0
length: 5
2014-01-17 15:01:52 DEBUG: pid 3556: pool_read_message_length: slot: 1
length: 5
2014-01-17 15:01:52 DEBUG: pid 3556: ReadyForQuery: transaction state:
2014-01-17 15:01:52 DEBUG: pid 3556: ReadyForQuery: transaction state:I
2014-01-17 15:01:52 DEBUG: pid 3556: ProcessBackendResponse: Ready For
Query
2014-01-17 15:01:52 DEBUG: pid 3570: pool_ssl: SSL requested but SSL
support is not available
2014-01-17 15:01:52 DEBUG: pid 3570: s_do_auth: auth kind: 0
2014-01-17 15:01:52 DEBUG: pid 3570: s_do_auth: backend key data received
2014-01-17 15:01:52 DEBUG: pid 3570: s_do_auth: transaction state: I

The nodes output the following. The error happened also before installation
of pgpool_regclass plus I was able to run 'CREATE EXTENSION'
pgpool_regclass through pgpool.

bench_parallel=# SELECT count(*) from (SELECT
has_function_privilege('kristjan', 'pgpool_regclass(cstring)', 'execute')
WHERE EXISTS(SELECT * FROM pg_catalog.pg_proc AS p WHERE p.proname =
'pgpool_regclass')) AS s;
 count
-------
     1
(1 row)
-------------- next part --------------
An HTML attachment was scrubbed...
URL: <http://www.sraoss.jp/pipermail/pgpool-general/attachments/20140117/efb1c40f/attachment-0001.html>


More information about the pgpool-general mailing list