[Pgpool-general] Error with SSL Consection

Wed Nov 23 15:25:59 UTC 2011

This is the log:

2011-11-23 06:20:03 LOG:   pid 4504: connection received: host=10.13.4.201 port=33254
2011-11-23 06:20:03 DEBUG: pid 4504: Protocol Major: 1234 Minor: 5679 database:  user: 
2011-11-23 06:20:03 DEBUG: pid 4504: SSLRequest from client
2011-11-23 06:20:03 DEBUG: pid 4504: read_startup_packet: application_name: psql
2011-11-23 06:20:03 DEBUG: pid 4504: Protocol Major: 3 Minor: 0 database: postgres user: postgres
2011-11-23 06:20:03 DEBUG: pid 4504: new_connection: connecting 0 backend
2011-11-23 06:20:03 DEBUG: pid 4504: new_connection: connecting 1 backend
2011-11-23 06:20:03 DEBUG: pid 4504: pool_ssl: sending client->server SSL request
2011-11-23 06:20:03 DEBUG: pid 4504: pool_ssl: client->server SSL response: S
2011-11-23 06:20:03 DEBUG: pid 4504: pool_ssl: sending client->server SSL request
2011-11-23 06:20:03 DEBUG: pid 4504: pool_ssl: client->server SSL response: S
2011-11-23 06:20:03 DEBUG: pid 4504: pool_read_message_length: slot: 0 length: 12
2011-11-23 06:20:03 DEBUG: pid 4504: pool_read_message_length: slot: 1 length: 12
2011-11-23 06:20:03 DEBUG: pid 4504: pool_do_auth: auth kind:5
2011-11-23 06:20:03 DEBUG: pid 4504: trying md5 authentication
2011-11-23 06:20:03 ERROR: pid 4504: pool_ssl: SSL_read: no SSL error reported
2011-11-23 06:20:03 ERROR: pid 4504: pool_read: read failed (Success)
2011-11-23 06:20:03 DEBUG: pid 4504: read_password_packet_password: failed to read password packet "p"
2011-11-23 06:20:03 DEBUG: pid 4504: do_md5: read_password_packet failed
2011-11-23 06:20:03 DEBUG: pid 4504: do_md5failed in slot 0
2011-11-23 06:20:05 DEBUG: pid 4504: I am 4504 accept fd 6
2011-11-23 06:20:05 LOG:   pid 4504: connection received: host=10.13.4.201 port=33257
2011-11-23 06:20:05 DEBUG: pid 4504: Protocol Major: 1234 Minor: 5679 database:  user: 
2011-11-23 06:20:05 DEBUG: pid 4504: SSLRequest from client
2011-11-23 06:20:05 DEBUG: pid 4504: read_startup_packet: application_name: psql
2011-11-23 06:20:05 DEBUG: pid 4504: Protocol Major: 3 Minor: 0 database: postgres user: postgres
2011-11-23 06:20:05 DEBUG: pid 4504: new_connection: connecting 0 backend
2011-11-23 06:20:05 DEBUG: pid 4504: new_connection: connecting 1 backend
2011-11-23 06:20:05 DEBUG: pid 4504: pool_ssl: sending client->server SSL request
2011-11-23 06:20:05 DEBUG: pid 4504: pool_ssl: client->server SSL response: S
2011-11-23 06:20:05 DEBUG: pid 4504: pool_ssl: sending client->server SSL request
2011-11-23 06:20:05 DEBUG: pid 4504: pool_ssl: client->server SSL response: S
2011-11-23 06:20:05 DEBUG: pid 4504: pool_read_message_length: slot: 0 length: 12
2011-11-23 06:20:05 DEBUG: pid 4504: pool_read_message_length: slot: 1 length: 12
2011-11-23 06:20:05 DEBUG: pid 4504: pool_do_auth: auth kind:5
2011-11-23 06:20:05 DEBUG: pid 4504: trying md5 authentication
2011-11-23 06:20:05 DEBUG: pid 4504: DB node id: 0 salt: 93aed894
2011-11-23 06:20:05 DEBUG: pid 4504: trying md5 authentication
2011-11-23 06:20:05 DEBUG: pid 4504: DB node id: 1 salt: e2c21f77
2011-11-23 06:20:05 DEBUG: pid 4504: pool_read_message_length2: master slot: 0 length: 26
2011-11-23 06:20:05 DEBUG: pid 4504: pool_read_message_length2: master slot: 1 length: 26
2011-11-23 06:20:05 DEBUG: pid 4504: 0 th backend: name: application_name value: psql
2011-11-23 06:20:05 DEBUG: pid 4504: 1 th backend: name: application_name value: psql
2011-11-23 06:20:05 DEBUG: pid 4504: pool_read_message_length2: master slot: 0 length: 25
2011-11-23 06:20:05 DEBUG: pid 4504: pool_read_message_length2: master slot: 1 length: 25
2011-11-23 06:20:05 DEBUG: pid 4504: 0 th backend: name: client_encoding value: UTF8
2011-11-23 06:20:05 DEBUG: pid 4504: 1 th backend: name: client_encoding value: UTF8
2011-11-23 06:20:05 DEBUG: pid 4504: pool_read_message_length2: master slot: 0 length: 23
2011-11-23 06:20:05 DEBUG: pid 4504: pool_read_message_length2: master slot: 1 length: 23
2011-11-23 06:20:05 DEBUG: pid 4504: 0 th backend: name: DateStyle value: ISO, DMY
2011-11-23 06:20:05 DEBUG: pid 4504: 1 th backend: name: DateStyle value: ISO, DMY
2011-11-23 06:20:05 DEBUG: pid 4504: pool_read_message_length2: master slot: 0 length: 25
2011-11-23 06:20:05 DEBUG: pid 4504: pool_read_message_length2: master slot: 1 length: 25
2011-11-23 06:20:05 DEBUG: pid 4504: 0 th backend: name: integer_datetimes value: on
2011-11-23 06:20:05 DEBUG: pid 4504: 1 th backend: name: integer_datetimes value: on
2011-11-23 06:20:05 DEBUG: pid 4504: pool_read_message_length2: master slot: 0 length: 27
2011-11-23 06:20:05 DEBUG: pid 4504: pool_read_message_length2: master slot: 1 length: 27
2011-11-23 06:20:05 DEBUG: pid 4504: 0 th backend: name: IntervalStyle value: postgres
2011-11-23 06:20:05 DEBUG: pid 4504: 1 th backend: name: IntervalStyle value: postgres
2011-11-23 06:20:05 DEBUG: pid 4504: pool_read_message_length2: master slot: 0 length: 20
2011-11-23 06:20:05 DEBUG: pid 4504: pool_read_message_length2: master slot: 1 length: 20
2011-11-23 06:20:05 DEBUG: pid 4504: 0 th backend: name: is_superuser value: on
2011-11-23 06:20:05 DEBUG: pid 4504: 1 th backend: name: is_superuser value: on
2011-11-23 06:20:05 DEBUG: pid 4504: pool_read_message_length2: master slot: 0 length: 25
2011-11-23 06:20:05 DEBUG: pid 4504: pool_read_message_length2: master slot: 1 length: 25
2011-11-23 06:20:05 DEBUG: pid 4504: 0 th backend: name: server_encoding value: UTF8
2011-11-23 06:20:05 DEBUG: pid 4504: 1 th backend: name: server_encoding value: UTF8
2011-11-23 06:20:05 DEBUG: pid 4504: pool_read_message_length2: master slot: 0 length: 25
2011-11-23 06:20:05 DEBUG: pid 4504: pool_read_message_length2: master slot: 1 length: 25
2011-11-23 06:20:05 DEBUG: pid 4504: 0 th backend: name: server_version value: 9.0.5
2011-11-23 06:20:05 DEBUG: pid 4504: 1 th backend: name: server_version value: 9.0.5
2011-11-23 06:20:05 DEBUG: pid 4504: pool_read_message_length2: master slot: 0 length: 35
2011-11-23 06:20:05 DEBUG: pid 4504: pool_read_message_length2: master slot: 1 length: 35
2011-11-23 06:20:05 DEBUG: pid 4504: 0 th backend: name: session_authorization value: postgres
2011-11-23 06:20:05 DEBUG: pid 4504: 1 th backend: name: session_authorization value: postgres
2011-11-23 06:20:05 DEBUG: pid 4504: pool_read_message_length2: master slot: 0 length: 36
2011-11-23 06:20:05 DEBUG: pid 4504: pool_read_message_length2: master slot: 1 length: 36
2011-11-23 06:20:05 DEBUG: pid 4504: 0 th backend: name: standard_conforming_strings value: off
2011-11-23 06:20:05 DEBUG: pid 4504: 1 th backend: name: standard_conforming_strings value: off
2011-11-23 06:20:05 DEBUG: pid 4504: pool_read_message_length2: master slot: 0 length: 29
2011-11-23 06:20:05 DEBUG: pid 4504: pool_read_message_length2: master slot: 1 length: 29
2011-11-23 06:20:05 DEBUG: pid 4504: 0 th backend: name: TimeZone value: America/Caracas
2011-11-23 06:20:05 DEBUG: pid 4504: 1 th backend: name: TimeZone value: America/Caracas
2011-11-23 06:20:05 DEBUG: pid 4504: pool_read_message_length: slot: 0 length: 12
2011-11-23 06:20:05 DEBUG: pid 4504: pool_read_message_length: slot: 1 length: 12
2011-11-23 06:20:05 DEBUG: pid 4504: pool_do_auth: cp->info[i]:0xb783f000 pid:4515
2011-11-23 06:20:05 DEBUG: pid 4504: pool_do_auth: cp->info[i]:0xb783f084 pid:32236
2011-11-23 06:20:05 DEBUG: pid 4504: pool_send_auth_ok: send pid 32236 to frontend
2011-11-23 06:20:05 DEBUG: pid 4504: pool_unset_query_in_progress: done
2011-11-23 06:20:05 DEBUG: pid 4504: pool_unset_command_success: done
2011-11-23 06:20:05 DEBUG: pid 4504: pool_unset_writing_transaction: done
2011-11-23 06:20:05 DEBUG: pid 4504: pool_unset_failed_transaction: done
2011-11-23 06:20:05 DEBUG: pid 4504: pool_unset_transaction_isolation: done
2011-11-23 06:20:05 DEBUG: pid 4504: pool_unset_skip_reading_from_backends: done
2011-11-23 06:20:05 DEBUG: pid 4504: pool_unset_ignore_till_sync: done
2011-11-23 06:20:05 DEBUG: pid 4504: read_kind_from_backend: read kind from 0 th backend Z NUM_BACKENDS: 2
2011-11-23 06:20:05 DEBUG: pid 4504: read_kind_from_backend: read kind from 1 th backend Z NUM_BACKENDS: 2
2011-11-23 06:20:05 DEBUG: pid 4504: ProcessBackendResponse: kind from backend: Z
2011-11-23 06:20:05 DEBUG: pid 4504: pool_read_message_length: slot: 0 length: 5
2011-11-23 06:20:05 DEBUG: pid 4504: pool_read_message_length: slot: 1 length: 5
2011-11-23 06:20:05 DEBUG: pid 4504: ReadyForQuery: transaction state:

Regards.

-----Mensaje original-----
De: Tatsuo Ishii [mailto:ishii at sraoss.co.jp] 
Enviado el: miércoles, 23 de noviembre de 2011 10:18
Para: Lazaro Rubén García Martinez
CC: pgpool-general at pgfoundry.org
Asunto: Re: [Pgpool-general] Error with SSL Consection

Could you show logs after this:
2011-11-23 04:37:25 ERROR: pid 17472: pool_read: read failed (Success)
--
Tatsuo Ishii
SRA OSS, Inc. Japan
English: http://www.sraoss.co.jp/index_en.php
Japanese: http://www.sraoss.co.jp

> Tatsuo, thank you very much for your answer, the problem was solved and now I can connect through SSL:
> 
> In the command window i can see that:
> 
> psql -U desarrollo -h 10.13.4.201 -p 9999 -d postgres
> Contraseña para usuario desarrollo:
> psql (9.0.5)
> conexión SSL (cifrado: AES256-SHA, bits: 256)
> Digite «help» para obtener ayuda.
> 
> However in the pgpool log these errors are shown, although the connection was succesful, there are some errors in pgpool log file.
> The log says that the connection was established without problem, but the debug message are matched to ERROR label. Would this a possible bug?
> 
> 2011-11-23 04:37:25 LOG:   pid 17472: connection received: host=10.13.4.201 port=47519
> 2011-11-23 04:37:25 DEBUG: pid 17472: Protocol Major: 1234 Minor: 5679 database:  user: 
> 2011-11-23 04:37:25 DEBUG: pid 17472: SSLRequest from client
> 2011-11-23 04:37:25 DEBUG: pid 17472: read_startup_packet: application_name: psql
> 2011-11-23 04:37:25 DEBUG: pid 17472: Protocol Major: 3 Minor: 0 database: postgres user: desarrollo
> 2011-11-23 04:37:25 DEBUG: pid 17472: new_connection: connecting 0 backend
> 2011-11-23 04:37:25 DEBUG: pid 17472: new_connection: connecting 1 backend
> 2011-11-23 04:37:25 DEBUG: pid 17472: pool_ssl: sending client->server SSL request
> 2011-11-23 04:37:25 DEBUG: pid 17472: pool_ssl: client->server SSL response: S
> 2011-11-23 04:37:25 DEBUG: pid 17472: pool_ssl: sending client->server SSL request
> 2011-11-23 04:37:25 DEBUG: pid 17472: pool_ssl: client->server SSL response: S
> 2011-11-23 04:37:25 DEBUG: pid 17472: pool_read_message_length: slot: 0 length: 12
> 2011-11-23 04:37:25 DEBUG: pid 17472: pool_read_message_length: slot: 1 length: 12
> 2011-11-23 04:37:25 DEBUG: pid 17472: pool_do_auth: auth kind:5
> 2011-11-23 04:37:25 DEBUG: pid 17472: trying md5 authentication
> 2011-11-23 04:37:25 ERROR: pid 17472: pool_ssl: SSL_read: no SSL error reported
> 2011-11-23 04:37:25 ERROR: pid 17472: pool_read: read failed (Success)
> 
> 
> Regards.
> 
> -----Mensaje original-----
> De: Tatsuo Ishii [mailto:ishii at sraoss.co.jp] 
> Enviado el: miércoles, 23 de noviembre de 2011 04:21
> Para: Lazaro Rubén García Martinez
> CC: pgpool-general at pgfoundry.org
> Asunto: Re: [Pgpool-general] Error with SSL Consection
> 
> Can you try like this?
> 
> 1) configure num_init_children to 1.
> 2) restart pgpool
> 3) find pgpool child process pid(hint: ps status is "pgpool: wait for connection request")
> 4) strace -p the_pid
> 5) connect to pgpool
> 
> strace should show where pgpool tried to find ssl cert file. Make sure that
> it is /opt/pgpool/ssl/server.cert.
> --
> Tatsuo Ishii
> SRA OSS, Inc. Japan
> English: http://www.sraoss.co.jp/index_en.php
> Japanese: http://www.sraoss.co.jp
> 
>> Hello everyone in the list, I am proving the connecting SSL through with Pgpool, the pgpool configuration parameters related with SSL are:
>> 
>> # - SSL Connections -
>> 
>> ssl = on
>> ssl_key = '/opt/pgpool/ssl/server.key'
>> ssl_cert = '/opt/pgpool/ssl/server.cert'
>> #ssl_ca_cert = ''
>> #ssl_ca_cert_dir = ''
>> 
>> But in pgpool.log file i see this error:
>> 
>> 2011-11-22 06:42:02 LOG:   pid 14011: connection received: host=10.13.4.201 port=40434
>> 2011-11-22 06:42:02 DEBUG: pid 14011: Protocol Major: 1234 Minor: 5679 database:  user:
>> 2011-11-22 06:42:02 DEBUG: pid 14011: SSLRequest from client
>> 2011-11-22 06:42:02 ERROR: pid 14011: pool_ssl: Loading SSL certificate: No such file or directory
>> 
>> Nevertheless I can connect to postgreSQL through Pgpool.
>> 
>> Please can anybody tell me, What could be the reason for this error?
>> 
>> I am using Pgpool-II V_3.1_stable with PostgreSQL 9.0.5.
>> 
>> Regards.