[Pgpool-general] Error with SSL Consection

Wed Nov 23 15:33:23 UTC 2011

Looks normal. psql first tried with trust auth. Backend requires md5
auth and pool propagated to psql. psql disconnected connection to
pgpool and tried with md5 auth again. This time it was successfull.
--
Tatsuo Ishii
SRA OSS, Inc. Japan
English: http://www.sraoss.co.jp/index_en.php
Japanese: http://www.sraoss.co.jp

> 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.