[Pgpool-general] PGPool II Replication Mode Fails

David Jantzen david.jantzen at comcast.net
Thu Sep 6 18:03:49 UTC 2007 

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