[pgpool-general: 2446] Re: Segfault in pgpool triggered by a background query
Gray, David W
David.W.Gray at nielsen.com
Sat Jan 18 00:34:49 JST 2014
What error message do you see on the backend (postgresql) server?
I am having a similar issue, whereby the select has_function_privilege is failing, causing the connection to the postgres server to drop (the error kills the connection.) So, what's in the postgres log? (You may want to turn the logging level up in postgresql.conf).
From: pgpool-general-bounces at pgpool.net [mailto:pgpool-general-bounces at pgpool.net] On Behalf Of Kristjan Siimson
Sent: Friday, January 17, 2014 8:20 AM
To: pgpool-general at pgpool.net
Subject: [pgpool-general: 2445] Segfault in pgpool triggered by a background query
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/1847fc11/attachment-0001.html>
More information about the pgpool-general
mailing list