View Issue Details

Jump to NotesJump to History
IDProjectCategoryView StatusDate SubmittedLast Update
0000396Pgpool-IIGeneralpublic2018-05-09 23:212020-02-18 17:11
Reporternavingupta Assigned Tot-ishii  
PriorityimmediateSeveritymajorReproducibilityunable to reproduce
Status feedbackResolutionopen 
Product Version3.7.3 
Summary0000396: pgpool is getting started but not able to connect using port 9999 using psql application
DescriptionHi Team,

I have tried a lot but I am not able to connect to database using port 9999 .please help.

Log output :-

sudo pgpool -d -n -f /usr/local/etc/pgpool.conf -F /usr/local/etc/pcp.conf 2>&1
2018-05-09 19:44:56: pid 5277: DEBUG: initializing pool configuration
2018-05-09 19:44:56: pid 5277: DETAIL: num_backends: 1 total_weight: 1.000000
2018-05-09 19:44:56: pid 5277: DEBUG: initializing pool configuration
2018-05-09 19:44:56: pid 5277: DETAIL: backend 0 weight: 2147483647.000000 flag: 0000
2018-05-09 19:44:56: pid 5277: DEBUG: pool_coninfo_size: num_init_children (32) * max_pool (4) * MAX_NUM_BACKENDS (128) * sizeof(ConnectionInfo) (136) = 2228224 bytes requested for shared memory
2018-05-09 19:44:56: pid 5277: DEBUG: ProcessInfo: num_init_children (32) * sizeof(ProcessInfo) (32) = 1024 bytes requested for shared memory
2018-05-09 19:44:56: pid 5277: DEBUG: Request info are: sizeof(POOL_REQUEST_INFO) 5264 bytes requested for shared memory
2018-05-09 19:44:56: pid 5277: DEBUG: Recovery management area: sizeof(int) 4 bytes requested for shared memory
2018-05-09 19:44:56: pid 5277: LOG: Setting up socket for 0.0.0.0:9999
2018-05-09 19:44:56: pid 5277: LOG: Setting up socket for :::9999
2018-05-09 19:44:56: pid 5278: DEBUG: initializing backend status
2018-05-09 19:44:56: pid 5279: DEBUG: initializing backend status
2018-05-09 19:44:56: pid 5280: DEBUG: initializing backend status
2018-05-09 19:44:56: pid 5281: DEBUG: initializing backend status
2018-05-09 19:44:56: pid 5285: DEBUG: initializing backend status
2018-05-09 19:44:56: pid 5282: DEBUG: initializing backend status
2018-05-09 19:44:56: pid 5287: DEBUG: initializing backend status
2018-05-09 19:44:56: pid 5283: DEBUG: initializing backend status
2018-05-09 19:44:56: pid 5286: DEBUG: initializing backend status
2018-05-09 19:44:56: pid 5284: DEBUG: initializing backend status
2018-05-09 19:44:56: pid 5291: DEBUG: initializing backend status
2018-05-09 19:44:56: pid 5297: DEBUG: initializing backend status
2018-05-09 19:44:56: pid 5288: DEBUG: initializing backend status
2018-05-09 19:44:56: pid 5292: DEBUG: initializing backend status
2018-05-09 19:44:56: pid 5289: DEBUG: initializing backend status
2018-05-09 19:44:56: pid 5293: DEBUG: initializing backend status
2018-05-09 19:44:56: pid 5290: DEBUG: initializing backend status
2018-05-09 19:44:56: pid 5294: DEBUG: initializing backend status
2018-05-09 19:44:56: pid 5295: DEBUG: initializing backend status
2018-05-09 19:44:56: pid 5296: DEBUG: initializing backend status
2018-05-09 19:44:56: pid 5298: DEBUG: initializing backend status
2018-05-09 19:44:56: pid 5299: DEBUG: initializing backend status
2018-05-09 19:44:56: pid 5300: DEBUG: initializing backend status
2018-05-09 19:44:56: pid 5303: DEBUG: initializing backend status
2018-05-09 19:44:56: pid 5304: DEBUG: initializing backend status
2018-05-09 19:44:56: pid 5305: DEBUG: initializing backend status
2018-05-09 19:44:56: pid 5301: DEBUG: initializing backend status
2018-05-09 19:44:56: pid 5306: DEBUG: initializing backend status
2018-05-09 19:44:56: pid 5307: DEBUG: initializing backend status
2018-05-09 19:44:56: pid 5308: DEBUG: initializing backend status
2018-05-09 19:44:56: pid 5277: DEBUG: find_primary_node: not in streaming replication mode
2018-05-09 19:44:56: pid 5309: DEBUG: initializing backend status
2018-05-09 19:44:56: pid 5310: DEBUG: I am PCP child with pid:5310
2018-05-09 19:44:56: pid 5311: DEBUG: I am 5311
2018-05-09 19:44:56: pid 5311: DEBUG: initializing backend status
2018-05-09 19:44:56: pid 5312: DEBUG: I am health check process pid:5312 DB node id:0
2018-05-09 19:44:56: pid 5312: DEBUG: initializing backend status
2018-05-09 19:44:56: pid 5302: DEBUG: initializing backend status
2018-05-09 19:44:56: pid 5277: LOG: pgpool-II successfully started. version 3.7.3 (amefuriboshi)


Psql connect :-

/home/postgres/bin/pgsql-9.6.1/bin/psql -h localhost -p 9999 -U postgres
Password for user postgres:
psql: ERROR: authentication failed
DETAIL: password authentication failed for user "postgres"


Log after firing above command :-

2018-05-09 19:45:24: pid 5302: DEBUG: I am 5302 accept fd 9
2018-05-09 19:45:24: pid 5302: DEBUG: reading startup packet
2018-05-09 19:45:24: pid 5302: DETAIL: Protocol Major: 1234 Minor: 5679 database: user:
2018-05-09 19:45:24: pid 5302: DEBUG: selecting backend connection
2018-05-09 19:45:24: pid 5302: DETAIL: SSLRequest from client
2018-05-09 19:45:24: pid 5302: DEBUG: SSL is requested but SSL support is not available
2018-05-09 19:45:24: pid 5302: DEBUG: pool_write: to frontend: kind:N po:0
2018-05-09 19:45:24: pid 5302: DEBUG: pool_flush_it: flush size: 1
2018-05-09 19:45:24: pid 5302: DEBUG: reading startup packet
2018-05-09 19:45:24: pid 5302: DETAIL: application_name: psql
2018-05-09 19:45:24: pid 5302: DEBUG: reading startup packet
2018-05-09 19:45:24: pid 5302: DETAIL: Protocol Major: 3 Minor: 0 database: postgres user: postgres
2018-05-09 19:45:24: pid 5302: DEBUG: creating new connection to backend
2018-05-09 19:45:24: pid 5302: DETAIL: connecting 0 backend
2018-05-09 19:45:24: pid 5302: DEBUG: SSL is requested but SSL support is not available
2018-05-09 19:45:24: pid 5302: DEBUG: pool_flush_it: flush size: 84
2018-05-09 19:45:24: pid 5302: DEBUG: pool_read: read 13 bytes from backend 0
2018-05-09 19:45:24: pid 5302: DEBUG: reading message length
2018-05-09 19:45:24: pid 5302: DETAIL: slot: 0 length: 12
2018-05-09 19:45:24: pid 5302: DEBUG: authentication backend
2018-05-09 19:45:24: pid 5302: DETAIL: auth kind:5
2018-05-09 19:45:24: pid 5302: DEBUG: authentication backend
2018-05-09 19:45:24: pid 5302: DETAIL: trying md5 authentication
2018-05-09 19:45:24: pid 5302: DEBUG: performing md5 authentication
2018-05-09 19:45:24: pid 5302: DETAIL: DB node id: 0 salt: fb7cb627
2018-05-09 19:45:24: pid 5302: DEBUG: pool_write: to frontend: kind:R po:0
2018-05-09 19:45:24: pid 5302: DEBUG: pool_write: to frontend: length:4 po:1
2018-05-09 19:45:24: pid 5302: DEBUG: pool_write: to frontend: length:4 po:5
2018-05-09 19:45:24: pid 5302: DEBUG: pool_write: to frontend: length:4 po:9
2018-05-09 19:45:24: pid 5302: DEBUG: pool_flush_it: flush size: 13

TagsNo tags attached.

Activities

t-ishii

2018-05-10 07:33

developer   ~0002012

Sounds like a configuration problem. Please share: pgpool.conf, pool_hba.conf, pg_hba.conf.

navingupta

2018-05-11 02:05

reporter   ~0002013

As you asked, please find the attached conf file.

Thanks,
Navin.
pool_hba.conf (3,432 bytes)
pcp.conf (884 bytes)
pgpool.conf (35,852 bytes)

t-ishii

2018-05-11 08:03

developer   ~0002014

I think the password for postgres user in pool_passwd does not match with PostgreSQL's password.
You can verify this by:
$ grep postgres pool_passwd
and
select passwd from pg_shadow where usename = 'postgres';
The output of select should match with the password part of pool_passwd .

navingupta

2018-05-11 15:00

reporter   ~0002015

Hi ,

I verified the password, it is same ..

postgres@navin-pc:~$ grep postgres /usr/local/etc/pool_passwd
postgres:md53175bce1d3201d16594cebf9d7eb3f9d

navin_test_db=# select passwd from pg_shadow where usename = 'postgres';
               passwd
-------------------------------------
 md53175bce1d3201d16594cebf9d7eb3f9d
(1 row)

t-ishii

2018-05-11 15:03

developer   ~0002016

Are you sure that you can directly login to PostgreSQL with the password?

t-ishii

2018-05-11 15:10

developer   ~0002017

Last edited: 2018-05-11 15:10

 Can you provide pg_hba.conf?

navingupta

2018-05-11 15:11

reporter   ~0002018

Yes I am able to login with pasword ..

/home/postgres/bin/pgsql-9.6.1/bin/psql navin_test_db -U postgres
Password for user postgres:
psql (9.6.1)
Type "help" for help.

navin_test_db=#

navingupta

2018-05-11 15:16

reporter   ~0002019

Please find the pg_hba.conf file..

navingupta

2018-05-11 15:20

reporter   ~0002020

Hi,

Please find the pg_hba.conf file.

navingupta

2018-05-11 15:22

reporter   ~0002021

Are you getting the file ?It is not showing on front-end.

t-ishii

2018-05-11 15:23

developer   ~0002022

No.

navingupta

2018-05-11 15:25

reporter   ~0002023

please find the file.
pg_hba.conf (4,784 bytes)

t-ishii

2018-05-11 15:28

developer   ~0002024

Thanks. Also I need pgpool log after "2018-05-09 19:45:24: pid 5302: DEBUG: pool_flush_it: flush size: 13".

This seems quite normal so I guess something happend after this.

navingupta

2018-05-11 15:45

reporter   ~0002025

Hi, actually log is not getting written in /var/log/pgpool.log file. This is getting generated on terminal when I fire command

sudo pgpool -d -n -f /usr/local/etc/pgpool.conf -F /usr/local/etc/pcp.conf 2>&1
2018-05-11 12:12:43: pid 14883: DEBUG: initializing pool configuration
2018-05-11 12:12:43: pid 14883: DETAIL: num_backends: 1 total_weight: 1.000000
2018-05-11 12:12:43: pid 14883: DEBUG: initializing pool configuration
2018-05-11 12:12:43: pid 14883: DETAIL: backend 0 weight: 2147483647.000000 flag: 0000
2018-05-11 12:12:43: pid 14883: DEBUG: pool_coninfo_size: num_init_children (32) * max_pool (4) * MAX_NUM_BACKENDS (128) * sizeof(ConnectionInfo) (136) = 2228224 bytes requested for shared memory

t-ishii

2018-07-06 13:50

developer   ~0002104

Sorry for long absence. Today I realized that you have only 1 PostgreSQL server. In this case, you should NOT use pool_passwd file. pool_passwd is only consulted when there are 2 or more PostgreSQL servers. So please set "enable_pool_hba = off" in your pgpoo.conf and restart Pgpool-II, then try to login via Pgpool-II.
You can leave pool_passwd as it is. If enable_pool_hba is disabled, it's not consulted anyway.

t-ishii

2019-05-21 14:13

developer   ~0002612

May I close this issue?

Carlos Mendez

2019-09-06 00:54

reporter   ~0002823

Hi T-Ishii
Sorry for intruding, Could you please give more details about your last comments:

I dont understand, when you say pool_passwd is only consulted when there are 2 or more PostgreSQL servers.

Regards
CAR

t-ishii

2019-09-09 13:47

developer   ~0002827

Sorry,
> you should NOT use pool_passwd file. pool_passwd
This was not correct. I should have said "you may not use pool_passwd file.".
The reason why pool_passwd is explained here. (thus you will know why pool_passwd is not necessary for 1 backend configuration).
https://pgpool.net/mediawiki/index.php/FAQ#How_does_pgpool-II_handle_md5_authentication.3F

Back to original issue. I have tried with 3.7.3 and it works for me. Here are my logs. Do you see any difference from yours?

2019-09-09 13:34:12: pid 16236: DEBUG: reading startup packet
2019-09-09 13:34:12: pid 16236: DETAIL: application_name: psql
2019-09-09 13:34:12: pid 16236: DEBUG: reading startup packet
2019-09-09 13:34:12: pid 16236: DETAIL: Protocol Major: 3 Minor: 0 database: test user: foo
2019-09-09 13:34:12: pid 16236: DEBUG: creating new connection to backend
2019-09-09 13:34:12: pid 16236: DETAIL: connecting 0 backend
2019-09-09 13:34:12: pid 16236: DEBUG: pool_flush_it: flush size: 75
2019-09-09 13:34:12: pid 16236: DEBUG: pool_read: read 13 bytes from backend 0
2019-09-09 13:34:12: pid 16236: DEBUG: reading message length
2019-09-09 13:34:12: pid 16236: DETAIL: slot: 0 length: 12
2019-09-09 13:34:12: pid 16236: DEBUG: authentication backend
2019-09-09 13:34:12: pid 16236: DETAIL: auth kind:5
2019-09-09 13:34:12: pid 16236: DEBUG: authentication backend
2019-09-09 13:34:12: pid 16236: DETAIL: trying md5 authentication
2019-09-09 13:34:12: pid 16236: DEBUG: performing md5 authentication
2019-09-09 13:34:12: pid 16236: DETAIL: DB node id: 0 salt: 315d5a91
2019-09-09 13:34:12: pid 16236: DEBUG: pool_write: to frontend: kind:R po:0
2019-09-09 13:34:12: pid 16236: DEBUG: pool_write: to frontend: length:4 po:1
2019-09-09 13:34:12: pid 16236: DEBUG: pool_write: to frontend: length:4 po:5
2019-09-09 13:34:12: pid 16236: DEBUG: pool_write: to frontend: length:4 po:9
2019-09-09 13:34:12: pid 16236: DEBUG: pool_flush_it: flush size: 13
2019-09-09 13:34:12: pid 16236: DEBUG: pool_write: to backend: 0 kind:p
2019-09-09 13:34:12: pid 16236: DEBUG: pool_flush_it: flush size: 41
2019-09-09 13:34:12: pid 16236: DEBUG: pool_read: read 324 bytes from backend 0
2019-09-09 13:34:12: pid 16236: DEBUG: pool_write: to frontend: kind:R po:0
2019-09-09 13:34:12: pid 16236: DEBUG: pool_write: to frontend: length:4 po:1
2019-09-09 13:34:12: pid 16236: DEBUG: pool_write: to frontend: length:4 po:5
2019-09-09 13:34:12: pid 16236: DEBUG: pool_flush_it: flush size: 9
2019-09-09 13:34:12: pid 16236: DEBUG: pool_write: to frontend: kind:S po:0
2019-09-09 13:34:12: pid 16236: DEBUG: reading message length
2019-09-09 13:34:12: pid 16236: DETAIL: master slot: 0 length: 26
2019-09-09 13:34:12: pid 16236: DEBUG: pool_write: to frontend: length:4 po:1
2019-09-09 13:34:12: pid 16236: DEBUG: process parameter status
2019-09-09 13:34:12: pid 16236: DETAIL: backend:0 name:"application_name" value:"psql"
:
:

t-ishii

2020-02-18 17:11

developer   ~0003215

No response over 1 month. I am going to close this issue if there's no objection.

Issue History

Date Modified Username Field Change
2018-05-09 23:21 navingupta New Issue
2018-05-10 07:33 t-ishii Note Added: 0002012
2018-05-11 02:05 navingupta File Added: pool_hba.conf
2018-05-11 02:05 navingupta File Added: pcp.conf
2018-05-11 02:05 navingupta File Added: pgpool.conf
2018-05-11 02:05 navingupta Note Added: 0002013
2018-05-11 08:03 t-ishii Note Added: 0002014
2018-05-11 15:00 navingupta Note Added: 0002015
2018-05-11 15:03 t-ishii Note Added: 0002016
2018-05-11 15:10 t-ishii Note Added: 0002017
2018-05-11 15:10 t-ishii Note Edited: 0002017
2018-05-11 15:11 navingupta Note Added: 0002018
2018-05-11 15:16 navingupta Note Added: 0002019
2018-05-11 15:20 navingupta Note Added: 0002020
2018-05-11 15:22 navingupta Note Added: 0002021
2018-05-11 15:23 t-ishii Note Added: 0002022
2018-05-11 15:25 navingupta File Added: pg_hba.conf
2018-05-11 15:25 navingupta Note Added: 0002023
2018-05-11 15:28 t-ishii Note Added: 0002024
2018-05-11 15:45 navingupta Note Added: 0002025
2018-07-06 13:50 t-ishii Note Added: 0002104
2018-07-06 13:50 t-ishii Assigned To => t-ishii
2018-07-06 13:50 t-ishii Status new => feedback
2019-05-21 14:13 t-ishii Note Added: 0002612
2019-09-06 00:54 Carlos Mendez Note Added: 0002823
2019-09-09 13:47 t-ishii Note Added: 0002827
2020-02-18 17:11 t-ishii Note Added: 0003215