[pgpool-general: 3781] Re: Unable to get connections by tomcat common dbcp or c3p0 connection pooling from pgpool host/port

Muhammad Usama m.usama at gmail.com
Thu Jun 4 04:31:16 JST 2015 

Hi

What version of pgpool-II are you using? Log suggests that a segmentation
fault is causing the child process to crash.

Can you please share the core dump of crashing child process.

Thanks
Best regards
Muhammad Usama


On Wed, Jun 3, 2015 at 10:09 PM, Suresh Tavvala <Suresh.Tavvala at mozido.com>
wrote:

>  Hi,
>
>  We are observing weird pattern that tomcat connection pooling framework
> not able to get connections from pgpool and it is failing with below
> exceptions. But we are successfully able to connect thru PSQL on same
> pgpool host/port and execute all SQL commands.
>
>  Just to let you all know options tried and still end up with same
> exception
>
>  1.  Switched from common dbcp to c3p0 pooling framework.
>  2. Confirmed pgpool port is listening with domain “*” and able to telnet
> from other servers.
>  3. Turn off pgpool connection cache attribute
>  4. Checked encoding on tomcat server which is UTF-8.
>
>  ANY HELP GREATLY APPRECIATED…..
>
>
>
>  *A**pplication server Exception log:*
>
>  threw exception; Error retrieving data from switch_currenty_key table:
> Could not get JDBC Connection; nested exception is java.sql.SQLException:
> Connections could not be acquired from the underlying database!
>
> at
> org.springframework.beans.factory.support.BeanDefinitionValueResolver.resolveInnerBean(BeanDefinitionValueResolver.java:282)
> ~[spring-beans-3.2.3.RELEASE.jar:3.2.3.RELEASE]
>
> at
> org.springframework.beans.factory.support.BeanDefinitionValueResolver.resolveValueIfNecessary(BeanDefinitionValueResolver.java:121)
> ~[spring-beans-3.2.3.RELEASE.jar:3.2.3.RELEASE]
>
>
>  *Pgpool logs:*
>
>
>  2015-06-02 21:57:19 DEBUG: pid 17752: 0 th backend: name: TimeZone
> value: US/Central
>
> 2015-06-02 21:57:19 DEBUG: pid 17752: 1 th backend: name: TimeZone value:
> US/Central
>
> 2015-06-02 21:57:19 DEBUG: pid 17752: pool_read_message_length: slot: 0
> length: 12
>
> 2015-06-02 21:57:19 DEBUG: pid 17752: pool_read_message_length: slot: 1
> length: 12
>
> 2015-06-02 21:57:19 DEBUG: pid 17752: pool_do_auth:
> cp->info[i]:0x7f8637ec9000 pid:17756
>
> 2015-06-02 21:57:19 DEBUG: pid 17752: pool_do_auth:
> cp->info[i]:0x7f8637ec9088 pid:12502
>
> 2015-06-02 21:57:19 DEBUG: pid 17752: pool_send_auth_ok: send pid 12502 to
> frontend
>
> 2015-06-02 21:57:19 DEBUG: pid 17752: select_load_balancing_node: selected
> backend id is 0
>
> 2015-06-02 21:57:19 DEBUG: pid 17752: selected load balancing node: 0
>
> 2015-06-02 21:57:19 DEBUG: pid 17752: pool_unset_query_in_progress: done
>
> 2015-06-02 21:57:19 DEBUG: pid 17752: pool_unset_command_success: done
>
> 2015-06-02 21:57:19 DEBUG: pid 17752: pool_unset_writing_transaction: done
>
> 2015-06-02 21:57:19 DEBUG: pid 17752: pool_unset_failed_transaction: done
>
> 2015-06-02 21:57:19 DEBUG: pid 17752: pool_unset_transaction_isolation:
> done
>
> 2015-06-02 21:57:19 DEBUG: pid 17752:
> pool_unset_skip_reading_from_backends: done
>
> 2015-06-02 21:57:19 DEBUG: pid 17752: pool_unset_ignore_till_sync: done
>
> 2015-06-02 21:57:19 DEBUG: pid 17752: read_kind_from_backend: kind: Z from
> 0 th backend
>
> 2015-06-02 21:57:19 DEBUG: pid 17752: read_kind_from_backend: read kind
> from 0 th backend Z NUM_BACKENDS: 2
>
> 2015-06-02 21:57:19 DEBUG: pid 17752: read_kind_from_backend: kind: Z from
> 1 th backend
>
> 2015-06-02 21:57:19 DEBUG: pid 17752: read_kind_from_backend: read kind
> from 1 th backend Z NUM_BACKENDS: 2
>
> 2015-06-02 21:57:19 DEBUG: pid 17752: ProcessBackendResponse: kind from
> backend: Z
>
> 2015-06-02 21:57:19 DEBUG: pid 17752: pool_read_message_length: slot: 0
> length: 5
>
> 2015-06-02 21:57:19 DEBUG: pid 17752: pool_read_message_length: slot: 1
> length: 5
>
> 2015-06-02 21:57:19 DEBUG: pid 17752: ReadyForQuery: transaction state:
>
> 2015-06-02 21:57:19 DEBUG: pid 17752: ReadyForQuery: transaction state:I
>
> 2015-06-02 21:57:19 DEBUG: pid 17752: ProcessBackendResponse: Ready For
> Query
>
> 2015-06-02 21:57:19 DEBUG: pid 17752: ProcessFrontendResponse: kind from
> frontend P(50)
>
> 2015-06-02 21:57:19 DEBUG: pid 17752:
> pool_unset_doing_extended_query_message: done
>
> 2015-06-02 21:57:19 DEBUG: pid 17752:
> pool_set_doing_extended_query_message: done
>
> 2015-06-02 21:57:19 DEBUG: pid 17752: pool_set_query_in_progress: done
>
> 2015-06-02 21:57:19 DEBUG: pid 17752: Parse: statement name <>
>
> 2015-06-02 21:57:19 DEBUG: pid 17752: pool_set_query_in_progress: done
>
> 2015-06-02 21:57:19 DEBUG: pid 17752: pool_read_message_length: slot: 0
> length: 5
>
> 2015-06-02 21:57:19 DEBUG: pid 17752: pool_read_message_length: slot: 1
> length: 5
>
> 2015-06-02 21:57:19 DEBUG: pid 17752: ReadyForQuery: transaction state:I
>
> 2015-06-02 21:57:19 DEBUG: pid 17752: ReadyForQuery: transaction state:I
>
> 2015-06-02 21:57:19 DEBUG: pid 17752: can_query_context_destroy: query
> context 0x769e10 is still used. query:SET extra_float_digits = 3
>
> 2015-06-02 21:57:19 DEBUG: pid 17752: pool_unset_query_in_progress: done
>
> 2015-06-02 21:57:19 DEBUG: pid 17752: pool_set_query_in_progress: done
>
> 2015-06-02 21:57:19 DEBUG: pid 17752: pool_unset_query_in_progress: done
>
> 2015-06-02 21:57:19 DEBUG: pid 17752: pool_set_query_in_progress: done
>
> 2015-06-02 21:57:19 DEBUG: pid 17752: Parse: waiting for master completing
> the query
>
> 2015-06-02 21:57:19 LOG:   pid 17752: DB node id: 0 backend pid: 17756
> statement: Parse: ���;�
>
> 2015-06-02 21:57:19 DEBUG: pid 17752: wait_for_query_response: waiting for
> backend 0 completing the query
>
> 2015-06-02 21:57:19 DEBUG: pid 17752: detect_error: kind: 1
>
> 2015-06-02 21:57:19 DEBUG: pid 11464: reap_handler called
>
> 2015-06-02 21:57:19 DEBUG: pid 11464: reap_handler: call wait3
>
> 2015-06-02 21:57:19 ERROR: pid 11464: Child process 17752 was terminated
> by segmentation fault
>
> 2015-06-02 21:57:19 DEBUG: pid 11464: child 17752 exits with status 11 by
> signal 11
>
> 2015-06-02 21:57:19 DEBUG: pid 11464: fork a new child pid 17757
>
> 2015-06-02 21:57:19 DEBUG: pid 11464: reap_handler: normally exited
>
> 2015-06-02 21:57:19 DEBUG: pid 17757: I am 17757
>
> 2015-06-02 21:57:19 DEBUG: pid 17757:
> pool_initialize_private_backend_status: initialize backend status
>
> 2015-06-02 21:57:27 DEBUG: pid 17729: I am 17729 accept fd 6
>
> 2015-06-02 21:57:27 LOG:   pid 17729: connection received: host=<<XXXXX
> hostname>> port=37844
>
> 2015-06-02 21:57:27 DEBUG: pid 17729: Protocol Major: 3 Minor: 0 database:
> <<databasename>> user: <<username>>
>
> 2015-06-02 21:57:27 DEBUG: pid 17729: new_connection: connecting 0 backend
>
> 2015-06-02 21:57:27 DEBUG: pid 17729: new_connection: connecting 1 backend
>
> 2015-06-02 21:57:27 DEBUG: pid 17729: pool_ssl: SSL requested but SSL
> support is not available
>
> 2015-06-02 21:57:27 DEBUG: pid 17729: pool_ssl: SSL requested but SSL
> support is not available
>
> 2015-06-02 21:57:27 DEBUG: pid 17729: pool_read_message_length: slot: 0
> length: 12
>
> 2015-06-02 21:57:27 DEBUG: pid 17729: pool_read_message_length: slot: 1
> length: 12
>
> 2015-06-02 21:57:27 DEBUG: pid 17729: pool_do_auth: auth kind:5
>
> 2015-06-02 21:57:27 DEBUG: pid 17729: trying md5 authentication
>
> 2015-06-02 21:57:27 DEBUG: pid 17729: DB node id: 0 salt: 16bcf7b8
>
> 2015-06-02 21:57:27 DEBUG: pid 17729: trying md5 authentication
>
> 2015-06-02 21:57:27 DEBUG: pid 17729: DB node id: 1 salt: ac25a3ff
>
> 2015-06-02 21:57:27 DEBUG: pid 17729: pool_read_message_length2: master
> slot: 0 length: 22
>
> 2015-06-02 21:57:27 DEBUG: pid 17729: pool_read_message_length2: master
> slot: 1 length: 22
>
> 2015-06-02 21:57:27 DEBUG: pid 17729: 0 th backend: name: application_name
> value:
>
> 2015-06-02 21:57:27 DEBUG: pid 17729: 1 th backend: name: application_name
> value:
>
> 2015-06-02 21:57:27 DEBUG: pid 17729: pool_read_message_length2: master
> slot: 0 length: 25
>
> 2015-06-02 21:57:27 DEBUG: pid 17729: pool_read_message_length2: master
> slot: 1 length: 25
>
> 2015-06-02 21:57:27 DEBUG: pid 17729: 0 th backend: name: client_encoding
> value: UTF8
>
> 2015-06-02 21:57:27 DEBUG: pid 17729: 1 th backend: name: client_encoding
> value: UTF8
>
> 2015-06-02 21:57:27 DEBUG: pid 17729: pool_read_message_length2: master
> slot: 0 length: 23
>
> 2015-06-02 21:57:27 DEBUG: pid 17729: pool_read_message_length2: master
> slot: 1 length: 23
>
> 2015-06-02 21:57:27 DEBUG: pid 17729: 0 th backend: name: DateStyle value:
> ISO, MDY
>
> 2015-06-02 21:57:27 DEBUG: pid 17729: 1 th backend: name: DateStyle value:
> ISO, MDY
>
> 2015-06-02 21:57:27 DEBUG: pid 17729: pool_read_message_length2: master
> slot: 0 length: 25
>
> 2015-06-02 21:57:27 DEBUG: pid 17729: pool_read_message_length2: master
> slot: 1 length: 25
>
> 2015-06-02 21:57:27 DEBUG: pid 17729: 0 th backend: name:
> integer_datetimes value: on
>
> 2015-06-02 21:57:27 DEBUG: pid 17729: 1 th backend: name:
> integer_datetimes value: on
>
> 2015-06-02 21:57:27 DEBUG: pid 17729: pool_read_message_length2: master
> slot: 0 length: 27
>
> 2015-06-02 21:57:27 DEBUG: pid 17729: pool_read_message_length2: master
> slot: 1 length: 27
>
> 2015-06-02 21:57:27 DEBUG: pid 17729: 0 th backend: name: IntervalStyle
> value: postgres
>
> 2015-06-02 21:57:27 DEBUG: pid 17729: 1 th backend: name: IntervalStyle
> value: postgres
>
> 2015-06-02 21:57:27 DEBUG: pid 17729: pool_read_message_length2: master
> slot: 0 length: 21
>
> 2015-06-02 21:57:27 DEBUG: pid 17729: pool_read_message_length2: master
> slot: 1 length: 21
>
> 2015-06-02 21:57:27 DEBUG: pid 17729: 0 th backend: name: is_superuser
> value: off
>
> 2015-06-02 21:57:27 DEBUG: pid 17729: 1 th backend: name: is_superuser
> value: off
>
> 2015-06-02 21:57:27 DEBUG: pid 17729: pool_read_message_length2: master
> slot: 0 length: 25
>
> 2015-06-02 21:57:27 DEBUG: pid 17729: pool_read_message_length2: master
> slot: 1 length: 25
>
> 2015-06-02 21:57:27 DEBUG: pid 17729: 0 th backend: name: server_encoding
> value: UTF8
>
> 2015-06-02 21:57:27 DEBUG: pid 17729: 1 th backend: name: server_encoding
> value: UTF8
>
> 2015-06-02 21:57:27 DEBUG: pid 17729: pool_read_message_length2: master
> slot: 0 length: 26
>
> 2015-06-02 21:57:27 DEBUG: pid 17729: pool_read_message_length2: master
> slot: 1 length: 26
>
> 2015-06-02 21:57:27 DEBUG: pid 17729: 0 th backend: name: server_version
> value: 9.2.10
>
> 2015-06-02 21:57:27 DEBUG: pid 17729: 1 th backend: name: server_version
> value: 9.2.10
>
> 2015-06-02 21:57:27 DEBUG: pid 17729: pool_read_message_length2: master
> slot: 0 length: 34
>
> 2015-06-02 21:57:27 DEBUG: pid 17729: pool_read_message_length2: master
> slot: 1 length: 34
>
> 2015-06-02 21:57:27 DEBUG: pid 17729: 0 th backend: name:
> session_authorization value: <<user>>
>
> 2015-06-02 21:57:27 DEBUG: pid 17729: 1 th backend: name:
> session_authorization value: <<user>>
>
> 2015-06-02 21:57:27 DEBUG: pid 17729: pool_read_message_length2: master
> slot: 0 length: 35
>
> 2015-06-02 21:57:27 DEBUG: pid 17729: pool_read_message_length2: master
> slot: 1 length: 35
>
> 2015-06-02 21:57:27 DEBUG: pid 17729: 0 th backend: name:
> standard_conforming_strings value: on
>
> 2015-06-02 21:57:27 DEBUG: pid 17729: 1 th backend: name:
> standard_conforming_strings value: on
>
> 2015-06-02 21:57:27 DEBUG: pid 17729: pool_read_message_length2: master
> slot: 0 length: 24
>
> 2015-06-02 21:57:27 DEBUG: pid 17729: pool_read_message_length2: master
> slot: 1 length: 24
>
> 2015-06-02 21:57:27 DEBUG: pid 17729: 0 th backend: name: TimeZone value:
> US/Central
>
> 2015-06-02 21:57:27 DEBUG: pid 17729: 1 th backend: name: TimeZone value:
> US/Central
>
> 2015-06-02 21:57:27 DEBUG: pid 17729: pool_read_message_length: slot: 0
> length: 12
>
> 2015-06-02 21:57:27 DEBUG: pid 17729: pool_read_message_length: slot: 1
> length: 12
>
> 2015-06-02 21:57:27 DEBUG: pid 17729: pool_do_auth:
> cp->info[i]:0x7f8637bff000 pid:17758
>
> 2015-06-02 21:57:27 DEBUG: pid 17729: pool_do_auth:
> cp->info[i]:0x7f8637bff088 pid:12504
>
> 2015-06-02 21:57:27 DEBUG: pid 17729: pool_send_auth_ok: send pid 12504 to
> frontend
>
> 2015-06-02 21:57:27 DEBUG: pid 17729: select_load_balancing_node: selected
> backend id is 0
>
> 2015-06-02 21:57:27 DEBUG: pid 17729: selected load balancing node: 0
>
> 2015-06-02 21:57:27 DEBUG: pid 17729: pool_unset_query_in_progress: done
>
> 2015-06-02 21:57:27 DEBUG: pid 17729: pool_unset_command_success: done
>
> 2015-06-02 21:57:27 DEBUG: pid 17729: pool_unset_writing_transaction: done
>
> 2015-06-02 21:57:27 DEBUG: pid 17729: pool_unset_failed_transaction: done
>
> 2015-06-02 21:57:27 DEBUG: pid 17729: pool_unset_transaction_isolation:
> done
>
> 2015-06-02 21:57:27 DEBUG: pid 17729:
> pool_unset_skip_reading_from_backends: done
>
> 2015-06-02 21:57:27 DEBUG: pid 17729: pool_unset_ignore_till_sync: done
>
> 2015-06-02 21:57:27 DEBUG: pid 17729: read_kind_from_backend: kind: Z from
> 0 th backend
>
> 2015-06-02 21:57:27 DEBUG: pid 17729: read_kind_from_backend: read kind
> from 0 th backend Z NUM_BACKENDS: 2
>
> 2015-06-02 21:57:27 DEBUG: pid 17729: read_kind_from_backend: kind: Z from
> 1 th backend
>
> 2015-06-02 21:57:27 DEBUG: pid 17729: read_kind_from_backend: read kind
> from 1 th backend Z NUM_BACKENDS: 2
>
> 2015-06-02 21:57:27 DEBUG: pid 17729: ProcessBackendResponse: kind from
> backend: Z
>
> 2015-06-02 21:57:27 DEBUG: pid 17729: pool_read_message_length: slot: 0
> length: 5
>
> 2015-06-02 21:57:27 DEBUG: pid 17729: pool_read_message_length: slot: 1
> length: 5
>
> 2015-06-02 21:57:27 DEBUG: pid 17729: ReadyForQuery: transaction state:
>
> 2015-06-02 21:57:27 DEBUG: pid 17729: ReadyForQuery: transaction state:I
>
> 2015-06-02 21:57:27 DEBUG: pid 17729: ProcessBackendResponse: Ready For
> Query
>
> 2015-06-02 21:57:27 DEBUG: pid 17729: ProcessFrontendResponse: kind from
> frontend P(50)
>
> 2015-06-02 21:57:27 DEBUG: pid 17729:
> pool_unset_doing_extended_query_message: done
>
> 2015-06-02 21:57:27 DEBUG: pid 17729:
> pool_set_doing_extended_query_message: done
>
> 2015-06-02 21:57:27 DEBUG: pid 17729: pool_set_query_in_progress: done
>
> 2015-06-02 21:57:27 DEBUG: pid 17729: Parse: statement name <>
>
> 2015-06-02 21:57:27 DEBUG: pid 17729: pool_set_query_in_progress: done
>
> 2015-06-02 21:57:27 DEBUG: pid 17729: pool_read_message_length: slot: 0
> length: 5
>
> 2015-06-02 21:57:27 DEBUG: pid 17729: pool_read_message_length: slot: 1
> length: 5
>
> 2015-06-02 21:57:27 DEBUG: pid 17729: ReadyForQuery: transaction state:I
>
> 2015-06-02 21:57:27 DEBUG: pid 17729: ReadyForQuery: transaction state:I
>
> 2015-06-02 21:57:27 DEBUG: pid 17729: can_query_context_destroy: query
> context 0x769e10 is still used. query:SET extra_float_digits = 3
>
> 2015-06-02 21:57:27 DEBUG: pid 17729: pool_unset_query_in_progress: done
>
> 2015-06-02 21:57:27 DEBUG: pid 17729: pool_set_query_in_progress: done
>
> 2015-06-02 21:57:27 DEBUG: pid 17729: pool_unset_query_in_progress: done
>
> 2015-06-02 21:57:27 DEBUG: pid 17729: pool_set_query_in_progress: done
>
> 2015-06-02 21:57:27 DEBUG: pid 17729: Parse: waiting for master completing
> the query
>
> 2015-06-02 21:57:27 LOG:   pid 17729: DB node id: 0 backend pid: 17758
> statement: Parse: ���;�
>
> 2015-06-02 21:57:27 DEBUG: pid 17729: wait_for_query_response: waiting for
> backend 0 completing the query
>
> 2015-06-02 21:57:27 DEBUG: pid 17729: detect_error: kind: 1
>
> 2015-06-02 21:57:27 DEBUG: pid 11464: reap_handler called
>
> 2015-06-02 21:57:27 DEBUG: pid 11464: reap_handler: call wait3
>
> 2015-06-02 21:57:27 ERROR: pid 11464: Child process 17729 was terminated
> by segmentation fault
>
> 2015-06-02 21:57:27 DEBUG: pid 11464: child 17729 exits with status 11 by
> signal 11
>
> 2015-06-02 21:57:27 DEBUG: pid 11464: fork a new child pid 17759
>
> 2015-06-02 21:57:27 DEBUG: pid 11464: reap_handler: normally exited
>
> 2015-06-02 21:57:27 DEBUG: pid 17759: I am 17759
>
> 2015-06-02 21:57:27 DEBUG: pid 17759:
> pool_initialize_private_backend_status: initialize backend status
>
>  *Postgres log samples:*
>
>  I do see connections authorized/established but immediately
> disconnections are happening with in milliseconds.
>
>
>   ~Suresh
>
> _______________________________________________
> pgpool-general mailing list
> pgpool-general at pgpool.net
> http://www.pgpool.net/mailman/listinfo/pgpool-general
>
>
-------------- next part --------------
An HTML attachment was scrubbed...
URL: <http://www.sraoss.jp/pipermail/pgpool-general/attachments/20150604/da386f37/attachment-0001.html>

More information about the pgpool-general mailing list