[Pgpool-general] PGPool II Replication Mode Fails

David Jantzen david.jantzen at comcast.net
Fri Sep 7 03:34:28 UTC 2007 

I have verified that the pg_hba.conf files are identical.  Also,
pgpool.conf is ignoring pool_hba.conf via "enable_pool_hba = false".

Here is the permissions section of pg_hba.conf:

local   all         postgres                          trust sameuser

# TYPE  DATABASE    USER        CIDR-ADDRESS          METHOD

# "local" is for Unix domain socket connections only
local   all         all                               trust sameuser
# IPv4 local connections:
host    all         all         127.0.0.1/32          trust sameuser

# IPv6 local connections:
host    all         all         ::1/128               md5
host all mbimporter,importer,processor,recommender,webapp,postgres
0.0.0.0/0  md5

Is there more verbose debug logging available? 

Thanks,
David

On Fri, 2007-09-07 at 10:26 +0900, Tatsuo Ishii wrote:
> It seems you are using different auth methods for those PostgreSQL
> servers. Can you check pg_hba.conf settings of those servers?
> --
> Tatsuo Ishii
> SRA OSS, Inc. Japan
> 
> > Hello,
> > 
> > The postgres superuser has the same password on both machines.  Both are
> > installations of 8.2.4 from the same Debian apt repository.  
> > 
> > Here's what I see in syslog with the -d option enabled when I try to
> > connect to pgpool with psql -p 9999 template1 -U postgres:
> > 
> > Sep  6 17:40:07 gcc-ami pgpool: 2007-09-06 17:40:07 DEBUG: pid 3930: I
> > am 3930 accept fd 0
> > Sep  6 17:40:07 gcc-ami pgpool: 2007-09-06 17:40:07 DEBUG: pid 3930:
> > Protocol Major: 3 Minor: 0 database: template1 user: postgres
> > Sep  6 17:40:07 gcc-ami pgpool: 2007-09-06 17:40:07 DEBUG: pid 3930:
> > new_connection: connecting 0 backend
> > Sep  6 17:40:07 gcc-ami pgpool: 2007-09-06 17:40:07 DEBUG: pid 3930:
> > new_connection: connecting 1 backend
> > Sep  6 17:40:07 gcc-ami pgpool: 2007-09-06 17:40:07 DEBUG: pid 3930:
> > pool_read_message_length: slot: 0 length: 8
> > Sep  6 17:40:07 gcc-ami pgpool: 2007-09-06 17:40:07 DEBUG: pid 3930:
> > pool_read_message_length: slot: 1 length: 12
> > Sep  6 17:40:07 gcc-ami pgpool: 2007-09-06 17:40:07 ERROR: pid 3930:
> > pool_read_message_length: message length (12) in slot 1 does not match
> > with slot 0
> > 
> > Here's what the server says at startup, it looks fine to me:
> > 
> > Sep  6 17:49:54 gcc-ami pgpool: 2007-09-06 17:49:54 DEBUG: pid 5375:
> > key: listen_addresses
> > Sep  6 17:49:54 gcc-ami pgpool: 2007-09-06 17:49:54 DEBUG: pid 5375:
> > value: '*' kind: 4
> > Sep  6 17:49:54 gcc-ami pgpool: 2007-09-06 17:49:54 DEBUG: pid 5375:
> > key: pcp_port
> > Sep  6 17:49:54 gcc-ami pgpool: 2007-09-06 17:49:54 DEBUG: pid 5375:
> > value: 9898 kind: 2
> > Sep  6 17:49:54 gcc-ami pgpool: 2007-09-06 17:49:54 DEBUG: pid 5375:
> > key: socket_dir
> > Sep  6 17:49:54 gcc-ami pgpool: 2007-09-06 17:49:54 DEBUG: pid 5375:
> > value: '/var/run/postgresql' kind: 4
> > Sep  6 17:49:54 gcc-ami pgpool: 2007-09-06 17:49:54 DEBUG: pid 5375:
> > key: pcp_socket_dir
> > Sep  6 17:49:54 gcc-ami pgpool: 2007-09-06 17:49:54 DEBUG: pid 5375:
> > value: '/var/run/postgresql' kind: 4
> > Sep  6 17:49:54 gcc-ami pgpool: 2007-09-06 17:49:54 DEBUG: pid 5375:
> > key: backend_socket_dir
> > Sep  6 17:49:54 gcc-ami pgpool: 2007-09-06 17:49:54 DEBUG: pid 5375:
> > value: '/var/run/postgresql' kind: 4
> > Sep  6 17:49:54 gcc-ami pgpool: 2007-09-06 17:49:54 DEBUG: pid 5375:
> > key: pcp_timeout
> > Sep  6 17:49:54 gcc-ami pgpool: 2007-09-06 17:49:54 DEBUG: pid 5375:
> > value: 10 kind: 2
> > Sep  6 17:49:54 gcc-ami pgpool: 2007-09-06 17:49:54 DEBUG: pid 5375:
> > key: num_init_children
> > Sep  6 17:49:54 gcc-ami pgpool: 2007-09-06 17:49:54 DEBUG: pid 5375:
> > value: 32 kind: 2
> > Sep  6 17:49:54 gcc-ami pgpool: 2007-09-06 17:49:54 DEBUG: pid 5375:
> > key: max_pool
> > Sep  6 17:49:54 gcc-ami pgpool: 2007-09-06 17:49:54 DEBUG: pid 5375:
> > value: 4 kind: 2
> > Sep  6 17:49:54 gcc-ami pgpool: 2007-09-06 17:49:54 DEBUG: pid 5375:
> > key: child_life_time
> > Sep  6 17:49:54 gcc-ami pgpool: 2007-09-06 17:49:54 DEBUG: pid 5375:
> > value: 300 kind: 2
> > Sep  6 17:49:54 gcc-ami pgpool: 2007-09-06 17:49:54 DEBUG: pid 5375:
> > key: connection_life_time
> > Sep  6 17:49:54 gcc-ami pgpool: 2007-09-06 17:49:54 DEBUG: pid 5375:
> > value: 0 kind: 2
> > Sep  6 17:49:54 gcc-ami pgpool: 2007-09-06 17:49:54 DEBUG: pid 5375:
> > key: child_max_connections
> > Sep  6 17:49:54 gcc-ami pgpool: 2007-09-06 17:49:54 DEBUG: pid 5375:
> > value: 0 kind: 2
> > Sep  6 17:49:54 gcc-ami pgpool: 2007-09-06 17:49:54 DEBUG: pid 5375:
> > key: logdir
> > Sep  6 17:49:54 gcc-ami pgpool: 2007-09-06 17:49:54 DEBUG: pid 5375:
> > value: '/var/run/postgresql' kind: 4
> > Sep  6 17:49:54 gcc-ami pgpool: 2007-09-06 17:49:54 DEBUG: pid 5375:
> > key: replication_mode
> > Sep  6 17:49:54 gcc-ami pgpool: 2007-09-06 17:49:54 DEBUG: pid 5375:
> > value: true kind: 1
> > Sep  6 17:49:54 gcc-ami pgpool: 2007-09-06 17:49:54 DEBUG: pid 5375:
> > key: replication_strict
> > Sep  6 17:49:54 gcc-ami pgpool: 2007-09-06 17:49:54 DEBUG: pid 5375:
> > value: true kind: 1
> > Sep  6 17:49:54 gcc-ami pgpool: 2007-09-06 17:49:54 DEBUG: pid 5375:
> > key: replication_timeout
> > Sep  6 17:49:54 gcc-ami pgpool: 2007-09-06 17:49:54 DEBUG: pid 5375:
> > value: 5000 kind: 2
> > Sep  6 17:49:54 gcc-ami pgpool: 2007-09-06 17:49:54 DEBUG: pid 5375:
> > key: load_balance_mode
> > Sep  6 17:49:54 gcc-ami pgpool: 2007-09-06 17:49:54 DEBUG: pid 5375:
> > value: true kind: 1
> > Sep  6 17:49:54 gcc-ami pgpool: 2007-09-06 17:49:54 DEBUG: pid 5375:
> > key: replication_stop_on_mismatch
> > Sep  6 17:49:54 gcc-ami pgpool: 2007-09-06 17:49:54 DEBUG: pid 5375:
> > value: false kind: 1
> > Sep  6 17:49:54 gcc-ami pgpool: 2007-09-06 17:49:54 DEBUG: pid 5375:
> > replication_stop_on_mismatch: 0
> > Sep  6 17:49:54 gcc-ami pgpool: 2007-09-06 17:49:54 DEBUG: pid 5375:
> > key: replicate_select
> > Sep  6 17:49:54 gcc-ami pgpool: 2007-09-06 17:49:54 DEBUG: pid 5375:
> > value: true kind: 1
> > Sep  6 17:49:54 gcc-ami pgpool: 2007-09-06 17:49:54 DEBUG: pid 5375:
> > replicate_select: 1
> > Sep  6 17:49:54 gcc-ami pgpool: 2007-09-06 17:49:54 DEBUG: pid 5375:
> > key: reset_query_list
> > Sep  6 17:49:54 gcc-ami pgpool: 2007-09-06 17:49:54 DEBUG: pid 5375:
> > value: 'ABORT; RESET ALL; SET SESSION AUTHORIZATION DEFAULT' kind: 4
> > Sep  6 17:49:54 gcc-ami pgpool: 2007-09-06 17:49:54 DEBUG: pid 5375:
> > extract_string_tokens: token: ABORT
> > Sep  6 17:49:54 gcc-ami pgpool: 2007-09-06 17:49:54 DEBUG: pid 5375:
> > extract_string_tokens: token:  RESET ALL
> > Sep  6 17:49:54 gcc-ami pgpool: 2007-09-06 17:49:54 DEBUG: pid 5375:
> > extract_string_tokens: token:  SET SESSION AUTHORIZATION DEFAULT
> > Sep  6 17:49:54 gcc-ami pgpool: 2007-09-06 17:49:54 DEBUG: pid 5375:
> > key: print_timestamp
> > Sep  6 17:49:54 gcc-ami pgpool: 2007-09-06 17:49:54 DEBUG: pid 5375:
> > value: true kind: 1
> > Sep  6 17:49:54 gcc-ami pgpool: 2007-09-06 17:49:54 DEBUG: pid 5375:
> > key: master_slave_mode
> > Sep  6 17:49:54 gcc-ami pgpool: 2007-09-06 17:49:54 DEBUG: pid 5375:
> > value: false kind: 1
> > Sep  6 17:49:54 gcc-ami pgpool: 2007-09-06 17:49:54 DEBUG: pid 5375:
> > key: connection_cache
> > Sep  6 17:49:54 gcc-ami pgpool: 2007-09-06 17:49:54 DEBUG: pid 5375:
> > value: true kind: 1
> > Sep  6 17:49:54 gcc-ami pgpool: 2007-09-06 17:49:54 DEBUG: pid 5375:
> > key: health_check_timeout
> > Sep  6 17:49:54 gcc-ami pgpool: 2007-09-06 17:49:54 DEBUG: pid 5375:
> > value: 20 kind: 2
> > Sep  6 17:49:54 gcc-ami pgpool: 2007-09-06 17:49:54 DEBUG: pid 5375:
> > key: health_check_period
> > Sep  6 17:49:54 gcc-ami pgpool: 2007-09-06 17:49:54 DEBUG: pid 5375:
> > value: 0 kind: 2
> > Sep  6 17:49:54 gcc-ami pgpool: 2007-09-06 17:49:54 DEBUG: pid 5375:
> > key: health_check_user
> > Sep  6 17:49:54 gcc-ami pgpool: 2007-09-06 17:49:54 DEBUG: pid 5375:
> > value: 'nobody' kind: 4
> > Sep  6 17:49:54 gcc-ami pgpool: 2007-09-06 17:49:54 DEBUG: pid 5375:
> > key: insert_lock
> > Sep  6 17:49:54 gcc-ami pgpool: 2007-09-06 17:49:54 DEBUG: pid 5375:
> > value: true kind: 1
> > Sep  6 17:49:54 gcc-ami pgpool: 2007-09-06 17:49:54 DEBUG: pid 5375:
> > key: ignore_leading_white_space
> > Sep  6 17:49:54 gcc-ami pgpool: 2007-09-06 17:49:54 DEBUG: pid 5375:
> > value: false kind: 1
> > Sep  6 17:49:54 gcc-ami pgpool: 2007-09-06 17:49:54 DEBUG: pid 5375:
> > key: log_statement
> > Sep  6 17:49:54 gcc-ami pgpool: 2007-09-06 17:49:54 DEBUG: pid 5375:
> > value: false kind: 1
> > Sep  6 17:49:54 gcc-ami pgpool: 2007-09-06 17:49:54 DEBUG: pid 5375:
> > key: log_connections
> > Sep  6 17:49:54 gcc-ami pgpool: 2007-09-06 17:49:54 DEBUG: pid 5375:
> > value: false kind: 1
> > Sep  6 17:49:54 gcc-ami pgpool: 2007-09-06 17:49:54 DEBUG: pid 5375:
> > key: log_hostname
> > Sep  6 17:49:54 gcc-ami pgpool: 2007-09-06 17:49:54 DEBUG: pid 5375:
> > value: false kind: 1
> > Sep  6 17:49:54 gcc-ami pgpool: 2007-09-06 17:49:54 DEBUG: pid 5375:
> > key: parallel_mode
> > Sep  6 17:49:54 gcc-ami pgpool: 2007-09-06 17:49:54 DEBUG: pid 5375:
> > value: false kind: 1
> > Sep  6 17:49:54 gcc-ami pgpool: 2007-09-06 17:49:54 DEBUG: pid 5375:
> > key: enable_query_cache
> > Sep  6 17:49:54 gcc-ami pgpool: 2007-09-06 17:49:54 DEBUG: pid 5375:
> > value: false kind: 1
> > Sep  6 17:49:54 gcc-ami pgpool: 2007-09-06 17:49:54 DEBUG: pid 5375:
> > key: pgpool2_hostname
> > Sep  6 17:49:54 gcc-ami pgpool: 2007-09-06 17:49:54 DEBUG: pid 5375:
> > value: 'localhost' kind: 4
> > Sep  6 17:49:54 gcc-ami pgpool: 2007-09-06 17:49:54 DEBUG: pid 5375:
> > key: system_db_hostname
> > Sep  6 17:49:54 gcc-ami pgpool: 2007-09-06 17:49:54 DEBUG: pid 5375:
> > value: 'localhost' kind: 4
> > Sep  6 17:49:54 gcc-ami pgpool: 2007-09-06 17:49:54 DEBUG: pid 5375:
> > key: system_db_port
> > Sep  6 17:49:54 gcc-ami pgpool: 2007-09-06 17:49:54 DEBUG: pid 5375:
> > value: 5432 kind: 2
> > Sep  6 17:49:54 gcc-ami pgpool: 2007-09-06 17:49:54 DEBUG: pid 5375:
> > key: system_db_dbname
> > Sep  6 17:49:54 gcc-ami pgpool: 2007-09-06 17:49:54 DEBUG: pid 5375:
> > value: 'pgpool' kind: 4
> > Sep  6 17:49:54 gcc-ami pgpool: 2007-09-06 17:49:54 DEBUG: pid 5375:
> > key: system_db_schema
> > Sep  6 17:49:54 gcc-ami pgpool: 2007-09-06 17:49:54 DEBUG: pid 5375:
> > value: 'pgpool_catalog' kind: 4
> > Sep  6 17:49:54 gcc-ami pgpool: 2007-09-06 17:49:54 DEBUG: pid 5375:
> > key: system_db_user
> > Sep  6 17:49:54 gcc-ami pgpool: 2007-09-06 17:49:54 DEBUG: pid 5375:
> > value: 'pgpool' kind: 4
> > Sep  6 17:49:54 gcc-ami pgpool: 2007-09-06 17:49:54 DEBUG: pid 5375:
> > key: system_db_password
> > Sep  6 17:49:54 gcc-ami pgpool: 2007-09-06 17:49:54 DEBUG: pid 5375:
> > value: '' kind: 4
> > Sep  6 17:49:54 gcc-ami pgpool: 2007-09-06 17:49:54 DEBUG: pid 5375:
> > key: backend_hostname0
> > Sep  6 17:49:54 gcc-ami pgpool: 2007-09-06 17:49:54 DEBUG: pid 5375:
> > value: 'localhost' kind: 4
> > Sep  6 17:49:54 gcc-ami pgpool: 2007-09-06 17:49:54 DEBUG: pid 5375:
> > key: backend_port0
> > Sep  6 17:49:54 gcc-ami pgpool: 2007-09-06 17:49:54 DEBUG: pid 5375:
> > value: 5432 kind: 2
> > Sep  6 17:49:54 gcc-ami pgpool: 2007-09-06 17:49:54 DEBUG: pid 5375:
> > pool_config: port slot number 0
> > Sep  6 17:49:54 gcc-ami pgpool: 2007-09-06 17:49:54 DEBUG: pid 5375:
> > key: backend_weight0
> > Sep  6 17:49:54 gcc-ami pgpool: 2007-09-06 17:49:54 DEBUG: pid 5375:
> > value: 1 kind: 2
> > Sep  6 17:49:54 gcc-ami pgpool: 2007-09-06 17:49:54 DEBUG: pid 5375:
> > pool_config: weight slot number 0 weight: 1.000000
> > Sep  6 17:49:54 gcc-ami pgpool: 2007-09-06 17:49:54 DEBUG: pid 5375:
> > key: backend_hostname1
> > Sep  6 17:49:54 gcc-ami pgpool: 2007-09-06 17:49:54 DEBUG: pid 5375:
> > value: 'domU-12-31-35-00-24-D3.z-2.compute-1.internal' kind: 4
> > Sep  6 17:49:54 gcc-ami pgpool: 2007-09-06 17:49:54 DEBUG: pid 5375:
> > key: backend_port1
> > Sep  6 17:49:54 gcc-ami pgpool: 2007-09-06 17:49:54 DEBUG: pid 5375:
> > value: 5432 kind: 2
> > Sep  6 17:49:54 gcc-ami pgpool: 2007-09-06 17:49:54 DEBUG: pid 5375:
> > pool_config: port slot number 1
> > Sep  6 17:49:54 gcc-ami pgpool: 2007-09-06 17:49:54 DEBUG: pid 5375:
> > key: backend_weight1
> > Sep  6 17:49:54 gcc-ami pgpool: 2007-09-06 17:49:54 DEBUG: pid 5375:
> > value: 1 kind: 2
> > Sep  6 17:49:54 gcc-ami pgpool: 2007-09-06 17:49:54 DEBUG: pid 5375:
> > pool_config: weight slot number 1 weight: 1.000000
> > Sep  6 17:49:54 gcc-ami pgpool: 2007-09-06 17:49:54 DEBUG: pid 5375:
> > key: enable_pool_hba
> > Sep  6 17:49:54 gcc-ami pgpool: 2007-09-06 17:49:54 DEBUG: pid 5375:
> > value: false kind: 1
> > Sep  6 17:49:54 gcc-ami pgpool: 2007-09-06 17:49:54 DEBUG: pid 5375:
> > num_backends: 2 num_backends: 2 total_weight: 2.000000
> > Sep  6 17:49:54 gcc-ami pgpool: 2007-09-06 17:49:54 DEBUG: pid 5375:
> > backend 0 weight: 1073741823.500000
> > Sep  6 17:49:54 gcc-ami pgpool: 2007-09-06 17:49:54 DEBUG: pid 5375:
> > backend 1 weight: 1073741823.500000
> > Sep  6 17:49:54 gcc-ami pgpool: 2007-09-06 17:49:54 DEBUG: pid 5381: I
> > am 5381
> >   ...
> > Sep  6 17:49:54 gcc-ami pgpool: 2007-09-06 17:49:54 LOG:   pid 5375:
> > pgpool successfully started
> > Sep  6 17:49:54 gcc-ami pgpool: 2007-09-06 17:49:54 DEBUG: pid 5413: I
> > am PCP 5413
> > 
> > Thanks,
> > David
> > 
> > 
> > On Thu, 2007-09-06 at 22:52 +0900, Tatsuo Ishii wrote:
> > > It seems some PostgreSQL settings, for example super user name, server
> > > encoding etc., do not agree among two servers. Can you enable the
> > > debug option (-d) of pgpool-II and show the debug messages around the
> > > error message?
> > > --
> > > Tatsuo Ishii
> > > SRA OSS, Inc. Japan
> > > 
> > > > Hello, thanks for the help.  It looks like there was an authentication
> > > > problem to the secondary server, and I have verified that I can now
> > > > connect to the secondary server as the postgres user.
> > > > 
> > > > However, now I see in /var/log/syslog:
> > > > 
> > > > pool_read_message_length: message length (12) in slot 1 does not match
> > > > with slot 0
> > > > 
> > > > Any ideas?
> > > > 
> > > > Oh, versions:
> > > > PostgreSQL 8.2.4
> > > > PGPool II 1.2-1
> > > > 
> > > > Thanks,
> > > > David
> > > > 
> > > > On Thu, 2007-09-06 at 10:49 +0900, Yoshiyuki Asaba wrote:
> > > > > Hi,
> > > > > 
> > > > > From: David Jantzen <david.jantzen at comcast.net>
> > > > > Subject: [Pgpool-general] PGPool II Replication Mode Fails
> > > > > Date: Wed, 05 Sep 2007 17:57:48 -0700
> > > > > 
> > > > > > However, when I enable replication_mode and try to connect to pgpool
> > > > > > I run into an error:
> > > > > > 
> > > > > > psql -p 9999 -U postgres template1
> > > > > > 
> > > > > > psql: server closed the connection unexpectedly
> > > > > >         This probably means the server terminated abnormally
> > > > > >         before or while processing the request.
> > > > > > 
> > > > > > In /var/log/syslog I see:
> > > > > > 
> > > > > > pool_read_kind: kind does not match between master(82) slot[1] (69)
> > > > > 
> > > > > It seems that a client authentication failed on secondary server.
> > > > > 
> > > > > Could you try the operations on pgpool host?
> > > > > 
> > > > >   % psql -h master -U postgres template1
> > > > >   % psql -h secondary -U postgres template1
> > > > > 
> > > > > --
> > > > > Yoshiyuki Asaba
> > > > > y-asaba at sraoss.co.jp
> > > > 
> > > > _______________________________________________
> > > > Pgpool-general mailing list
> > > > Pgpool-general at pgfoundry.org
> > > > http://pgfoundry.org/mailman/listinfo/pgpool-general
> >

More information about the Pgpool-general mailing list