[Pgpool-general] PGPool II Replication Mode Fails

Tatsuo Ishii ishii at sraoss.co.jp
Fri Sep 7 01:26:12 UTC 2007


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