[Pgpool-general] Problem with load balancing + automatic failover

Michael SALOMON michaelsalomon78 at gmail.com
Mon May 5 08:54:23 UTC 2008 

Hi !
Sorry for the late, we had a few day off last week...

Here are the log outputs I could get :

--------------> startup :
2008-05-05 10:25:54 DEBUG: pid 8537: key: replication_mode
2008-05-05 10:25:54 DEBUG: pid 8537: value: false kind: 1
2008-05-05 10:25:54 DEBUG: pid 8537: key: load_balance_mode
2008-05-05 10:25:54 DEBUG: pid 8537: value: true kind: 1
2008-05-05 10:25:54 DEBUG: pid 8537: key: replication_stop_on_mismatch
2008-05-05 10:25:54 DEBUG: pid 8537: value: false kind: 1
2008-05-05 10:25:54 DEBUG: pid 8537: replication_stop_on_mismatch: 0
2008-05-05 10:25:54 DEBUG: pid 8537: key: replicate_select
2008-05-05 10:25:54 DEBUG: pid 8537: value: false kind: 1
2008-05-05 10:25:54 DEBUG: pid 8537: replicate_select: 0
2008-05-05 10:25:54 DEBUG: pid 8537: key: reset_query_list
2008-05-05 10:25:54 DEBUG: pid 8537: value: 'ABORT; RESET ALL; SET SESSION
AUTHORIZATION DEFAULT' kind: 4
2008-05-05 10:25:54 DEBUG: pid 8537: extract_string_tokens: token: ABORT
2008-05-05 10:25:54 DEBUG: pid 8537: extract_string_tokens: token:  RESET
ALL
2008-05-05 10:25:54 DEBUG: pid 8537: extract_string_tokens: token:  SET
SESSION AUTHORIZATION DEFAULT
2008-05-05 10:25:54 DEBUG: pid 8537: key: print_timestamp
2008-05-05 10:25:54 DEBUG: pid 8537: value: true kind: 1
2008-05-05 10:25:54 DEBUG: pid 8537: key: master_slave_mode
2008-05-05 10:25:54 DEBUG: pid 8537: value: true kind: 1
2008-05-05 10:25:54 DEBUG: pid 8537: key: connection_cache
2008-05-05 10:25:54 DEBUG: pid 8537: value: false kind: 1
2008-05-05 10:25:54 DEBUG: pid 8537: key: health_check_timeout
2008-05-05 10:25:54 DEBUG: pid 8537: value: 2 kind: 2
2008-05-05 10:25:54 DEBUG: pid 8537: key: health_check_period
2008-05-05 10:25:54 DEBUG: pid 8537: value: 3 kind: 2
2008-05-05 10:25:54 DEBUG: pid 8537: key: health_check_user
2008-05-05 10:25:54 DEBUG: pid 8537: value: 'postgres' kind: 4
2008-05-05 10:25:54 DEBUG: pid 8537: key: failover_command
2008-05-05 10:25:54 DEBUG: pid 8537: value: '' kind: 4
2008-05-05 10:25:54 DEBUG: pid 8537: key: failback_command
2008-05-05 10:25:54 DEBUG: pid 8537: value: 'echo node = %d old master = %M
new master = %m > /tmp/failback_master' kind: 4
2008-05-05 10:25:54 DEBUG: pid 8537: key: insert_lock
2008-05-05 10:25:54 DEBUG: pid 8537: value: false kind: 1
2008-05-05 10:25:54 DEBUG: pid 8537: key: ignore_leading_white_space
2008-05-05 10:25:54 DEBUG: pid 8537: value: true kind: 1
2008-05-05 10:25:54 DEBUG: pid 8537: key: log_statement
2008-05-05 10:25:54 DEBUG: pid 8537: value: false kind: 1
2008-05-05 10:25:54 DEBUG: pid 8537: key: log_connections
2008-05-05 10:25:54 DEBUG: pid 8537: value: false kind: 1
2008-05-05 10:25:54 DEBUG: pid 8537: key: log_hostname
2008-05-05 10:25:54 DEBUG: pid 8537: value: false kind: 1
08-05-05 10:25:54 DEBUG: pid 8537: key: parallel_mode
2008-05-05 10:25:54 DEBUG: pid 8537: value: false kind: 1
2008-05-05 10:25:54 DEBUG: pid 8537: key: enable_query_cache
2008-05-05 10:25:54 DEBUG: pid 8537: value: false kind: 1
2008-05-05 10:25:54 DEBUG: pid 8537: key: pgpool2_hostname
2008-05-05 10:25:54 DEBUG: pid 8537: value: 'squale.pern.theralys.com' kind:
4
2008-05-05 10:25:54 DEBUG: pid 8537: key: backend_hostname0
2008-05-05 10:25:54 DEBUG: pid 8537: value: 'squale.pern.theralys.com' kind:
4
2008-05-05 10:25:54 DEBUG: pid 8537: key: backend_port0
2008-05-05 10:25:54 DEBUG: pid 8537: value: 5432 kind: 2
2008-05-05 10:25:54 DEBUG: pid 8537: pool_config: port slot number 0
2008-05-05 10:25:54 DEBUG: pid 8537: key: backend_weight0
2008-05-05 10:25:54 DEBUG: pid 8537: value: 1 kind: 2
2008-05-05 10:25:54 DEBUG: pid 8537: pool_config: weight slot number 0
weight: 1.000000
2008-05-05 10:25:54 DEBUG: pid 8537: key: backend_data_directory0
2008-05-05 10:25:54 DEBUG: pid 8537: value: '/var/lib/pgsql/data' kind: 4
2008-05-05 10:25:54 DEBUG: pid 8537: key: backend_hostname1
2008-05-05 10:25:54 DEBUG: pid 8537: value: 'binewtown2.remote.theralys.com'
kind: 4
2008-05-05 10:25:54 DEBUG: pid 8537: key: backend_port1
2008-05-05 10:25:54 DEBUG: pid 8537: value: 5432 kind: 2
2008-05-05 10:25:54 DEBUG: pid 8537: pool_config: port slot number 1
2008-05-05 10:25:54 DEBUG: pid 8537: key: backend_weight1
2008-05-05 10:25:54 DEBUG: pid 8537: value: 0 kind: 2
2008-05-05 10:25:54 DEBUG: pid 8537: pool_config: weight slot number 1
weight: 0.000000
2008-05-05 10:25:54 DEBUG: pid 8537: key: backend_data_directory1
2008-05-05 10:25:54 DEBUG: pid 8537: value: '/images_mirroir/pgsql/data'
kind: 4
2008-05-05 10:25:54 DEBUG: pid 8537: key: backend_hostname2
2008-05-05 10:25:54 DEBUG: pid 8537: value: 'squale.pern.theralys.com' kind:
4
2008-05-05 10:25:54 DEBUG: pid 8537: key: backend_port2
2008-05-05 10:25:54 DEBUG: pid 8537: value: 5431 kind: 2
2008-05-05 10:25:54 DEBUG: pid 8537: pool_config: port slot number 2
2008-05-05 10:25:54 DEBUG: pid 8537: key: backend_weight2
2008-05-05 10:25:54 DEBUG: pid 8537: value: 0 kind: 2
2008-05-05 10:25:54 DEBUG: pid 8537: pool_config: weight slot number 2
weight: 0.000000
2008-05-05 10:25:54 DEBUG: pid 8537: key: backend_data_directory2
2008-05-05 10:25:54 DEBUG: pid 8537: value: '/var/lib/pgsql2/data' kind: 4
2008-05-05 10:25:54 DEBUG: pid 8537: key: enable_pool_hba
2008-05-05 10:25:54 DEBUG: pid 8537: value: true kind: 1
2008-05-05 10:25:54 DEBUG: pid 8537: key: recovery_user
2008-05-05 10:25:54 DEBUG: pid 8537: value: 'nobody' kind: 4
2008-05-05 10:25:54 DEBUG: pid 8537: key: recovery_password
2008-05-05 10:25:54 DEBUG: pid 8537: value: '' kind: 4
2008-05-05 10:25:54 DEBUG: pid 8537: key: recovery_1st_stage_command
2008-05-05 10:25:54 DEBUG: pid 8537: value: '' kind: 4
2008-05-05 10:25:54 DEBUG: pid 8537: key: recovery_2nd_stage_command
2008-05-05 10:25:54 DEBUG: pid 8537: value: '' kind: 4
2008-05-05 10:25:54 DEBUG: pid 8537: key: recovery_timeout
2008-05-05 10:25:54 DEBUG: pid 8537: value: 90 kind: 2
2008-05-05 10:25:54 DEBUG: pid 8537: num_backends: 3 num_backends: 3
total_weight: 1.000000
2008-05-05 10:25:54 DEBUG: pid 8537: backend 0 weight: 2147483647.000000
2008-05-05 10:25:54 DEBUG: pid 8537: backend 1 weight: 0.000000
2008-05-05 10:25:54 DEBUG: pid 8537: backend 2 weight: 0.000000
.....
.....
2008-05-05 10:25:54 LOG:   pid 8537: pgpool successfully started
2008-05-05 10:25:54 DEBUG: pid 8537: starting health checking
2008-05-05 10:25:54 DEBUG: pid 8537: health_check: 0 the DB node status: 1
2008-05-05 10:25:54 DEBUG: pid 8537: health_check: 1 the DB node status: 1
2008-05-05 10:25:55 DEBUG: pid 8537: health_check: 2 the DB node status: 1

----------------------------> postgres master db goes down

2008-05-05 10:29:21 ERROR: pid 8537: connect_inet_domain_socket: connect()
failed: Connection refused
2008-05-05 10:29:21 ERROR: pid 8537: health check failed. 0 th host
squale.pern.theralys.com at port 5432 is down
2008-05-05 10:29:21 LOG:   pid 8537: set 0 th backend down status
2008-05-05 10:29:21 DEBUG: pid 8537: failover_handler called
2008-05-05 10:29:21 DEBUG: pid 8537: failover_handler: starting to select
new master node
2008-05-05 10:29:21 LOG:   pid 8537: starting degeneration. shutdown host
squale.pern.theralys.com(5432)
....
....

2008-05-05 10:29:21 LOG:   pid 8537: failover done. shutdown host
squale.pern.theralys.com(5432)
2008-05-05 10:29:21 DEBUG: pid 8537: reap_handler called
2008-05-05 10:29:21 DEBUG: pid 8537: reap_handler: call wait3
....
....
2008-05-05 10:29:21 DEBUG: pid 8537: reap_handler: normally exited
2008-05-05 10:29:24 DEBUG: pid 8537: starting health checking
2008-05-05 10:29:24 DEBUG: pid 8537: health_check: 0 the DB node status: 3
2008-05-05 10:29:24 DEBUG: pid 8537: health_check: 1 the DB node status: 2
2008-05-05 10:29:24 DEBUG: pid 8537: health_check: 2 the DB node status: 2
2008-05-05 10:29:27 DEBUG: pid 8537: starting health checking
2008-05-05 10:29:27 DEBUG: pid 8537: health_check: 0 the DB node status: 3
2008-05-05 10:29:27 DEBUG: pid 8537: health_check: 1 the DB node status: 2
2008-05-05 10:29:28 DEBUG: pid 8537: health_check: 2 the DB node status: 2
2008-05-05 10:29:35 DEBUG: pid 9058: I am 9058 accept fd 5
2008-05-05 10:29:35 DEBUG: pid 9058: Protocol Major: 3 Minor: 0 database:
biopacs user: postgres
2008-05-05 10:29:35 DEBUG: pid 9058: new_connection: connecting 0 backend
2008-05-05 10:29:35 DEBUG: pid 9058: new_connection: skipping slot 0 because
backend_status = 3
2008-05-05 10:29:35 DEBUG: pid 9058: new_connection: connecting 1 backend
2008-05-05 10:29:35 DEBUG: pid 9058: new_connection: connecting 2 backend
2008-05-05 10:29:35 DEBUG: pid 9058: pool_read_message_length: slot: 1
length: 8
2008-05-05 10:29:35 DEBUG: pid 9058: pool_read_message_length: slot: 2
length: 8
2008-05-05 10:29:35 DEBUG: pid 9058: pool_read_message_length2: master slot:
1 length: 27
2008-05-05 10:29:35 DEBUG: pid 9058: pool_read_message_length2: master slot:
2 length: 27
2008-05-05 10:29:35 DEBUG: pid 9058: 1 th backend: name: client_encoding
value: LATIN9
2008-05-05 10:29:35 DEBUG: pid 9058: 2 th backend: name: client_encoding
value: LATIN9
2008-05-05 10:29:35 DEBUG: pid 9058: pool_read_message_length2: master slot:
1 length: 23
2008-05-05 10:29:35 DEBUG: pid 9058: pool_read_message_length2: master slot:
2 length: 23
2008-05-05 10:29:35 DEBUG: pid 9058: 1 th backend: name: DateStyle value:
ISO, MDY
2008-05-05 10:29:35 DEBUG: pid 9058: 2 th backend: name: DateStyle value:
ISO, MDY
2008-05-05 10:29:35 DEBUG: pid 9058: pool_read_message_length2: master slot:
1 length: 26
2008-05-05 10:29:35 DEBUG: pid 9058: pool_read_message_length2: master slot:
2 length: 26
2008-05-05 10:29:35 DEBUG: pid 9058: 1 th backend: name: integer_datetimes
value: off
2008-05-05 10:29:35 DEBUG: pid 9058: 2 th backend: name: integer_datetimes
value: off
2008-05-05 10:29:35 DEBUG: pid 9058: pool_read_message_length2: master slot:
1 length: 20
2008-05-05 10:29:35 DEBUG: pid 9058: pool_read_message_length2: master slot:
2 length: 20
2008-05-05 10:29:35 DEBUG: pid 9058: 1 th backend: name: is_superuser value:
on
2008-05-05 10:29:35 DEBUG: pid 9058: 2 th backend: name: is_superuser value:
on
2008-05-05 10:29:35 DEBUG: pid 9058: pool_read_message_length2: master slot:
1 length: 27
2008-05-05 10:29:35 DEBUG: pid 9058: pool_read_message_length2: master slot:
2 length: 27
2008-05-05 10:29:35 DEBUG: pid 9058: 1 th backend: name: server_encoding
value: LATIN9
2008-05-05 10:29:35 DEBUG: pid 9058: 2 th backend: name: server_encoding
value: LATIN9
2008-05-05 10:29:35 DEBUG: pid 9058: pool_read_message_length2: master slot:
1 length: 25
2008-05-05 10:29:35 DEBUG: pid 9058: pool_read_message_length2: master slot:
2 length: 25
2008-05-05 10:29:35 DEBUG: pid 9058: 1 th backend: name: server_version
value: 8.3.1
2008-05-05 10:29:35 DEBUG: pid 9058: 2 th backend: name: server_version
value: 8.3.1
2008-05-05 10:29:35 DEBUG: pid 9058: pool_read_message_length2: master slot:
1 length: 35
2008-05-05 10:29:35 DEBUG: pid 9058: pool_read_message_length2: master slot:
2 length: 35
2008-05-05 10:29:35 DEBUG: pid 9058: 1 th backend: name:
session_authorization value: postgres
2008-05-05 10:29:35 DEBUG: pid 9058: 2 th backend: name:
session_authorization value: postgres
2008-05-05 10:29:35 DEBUG: pid 9058: pool_read_message_length2: master slot:
1 length: 36
2008-05-05 10:29:35 DEBUG: pid 9058: pool_read_message_length2: master slot:
2 length: 36
2008-05-05 10:29:35 DEBUG: pid 9058: 1 th backend: name:
standard_conforming_strings value: off
2008-05-05 10:29:35 DEBUG: pid 9058: 2 th backend: name:
standard_conforming_strings value: off

2008-05-05 10:29:35 DEBUG: pid 9058: 1 th backend: name:
standard_conforming_strings value: off
2008-05-05 10:29:35 DEBUG: pid 9058: 2 th backend: name:
standard_conforming_strings value: off
2008-05-05 10:29:35 DEBUG: pid 9058: pool_read_message_length2: master slot:
1 length: 24
2008-05-05 10:29:35 DEBUG: pid 9058: pool_read_message_length2: master slot:
2 length: 26
2008-05-05 10:29:35 ERROR: pid 9058: pool_read_message_length2: message
length (26) in slot 2 does not match with slot 0(24)
2008-05-05 10:29:35 DEBUG: pid 9058: 1 th backend: name: TimeZone value:
US/Eastern
2008-05-05 10:29:35 DEBUG: pid 9058: 2 th backend: name: TimeZone value:
Europe/Paris
2008-05-05 10:29:35 DEBUG: pid 9058: pool_read_message_length: slot: 1
length: 12
2008-05-05 10:29:35 DEBUG: pid 9058: pool_read_message_length: slot: 2
length: 12
2008-05-05 10:29:35 DEBUG: pid 9058: pool_send_auth_ok: send pid 9140 to
frontend
2008-05-05 10:29:35 DEBUG: pid 9058: select_load_balancing_node: selected
backend id is 0
2008-05-05 10:29:35 DEBUG: pid 9058: read_kind_from_backend: read kind from
1 th backend Z NUM_BACKENDS: 3
2008-05-05 10:29:35 DEBUG: pid 9058: read_kind_from_backend: read kind from
2 th backend Z NUM_BACKENDS: 3
2008-05-05 10:29:35 DEBUG: pid 9058: pool_process_query: kind from backend:
Z
2008-05-05 10:29:35 DEBUG: pid 9058: pool_read_message_length: slot: 1
length: 5
2008-05-05 10:29:35 DEBUG: pid 9058: pool_read_message_length: slot: 2
length: 5
2008-05-05 10:29:35 DEBUG: pid 9058: ReadyForQuery: message length: 5
2008-05-05 10:29:35 DEBUG: pid 9058: ReadyForQuery: transaction state: I
2008-05-05 10:29:35 DEBUG: pid 9058: select_load_balancing_node: selected
backend id is 0
2008-05-05 10:29:35 DEBUG: pid 9058: read kind from frontend Q(51)

-------------> SELECT COUNT executed on master node
2008-05-05 10:29:35 DEBUG: pid 9058: statement2: select count(1) from
perform.mytable;
2008-05-05 10:29:35 DEBUG: pid 8537: reap_handler called
2008-05-05 10:29:35 DEBUG: pid 8537: reap_handler: call wait3
2008-05-05 10:29:35 DEBUG: pid 8537: child 9058 exits with status 11 by
signal 11
2008-05-05 10:29:35 DEBUG: pid 9141: I am 9141
2008-05-05 10:29:35 DEBUG: pid 8537: fork a new child pid 9141
2008-05-05 10:29:35 DEBUG: pid 8537: reap_handler: normally exited
2008-05-05 10:29:37 DEBUG: pid 8537: starting health checking
2008-05-05 10:29:37 DEBUG: pid 8537: health_check: 0 the DB node status: 3
2008-05-05 10:29:37 DEBUG: pid 8537: health_check: 1 the DB node status: 2
2008-05-05 10:29:37 DEBUG: pid 8537: health_check: 2 the DB node status: 2


thanks a lot !

Regards

michael











On Fri, May 2, 2008 at 2:43 PM, Yoshiyuki Asaba <y-asaba at sraoss.co.jp>
wrote:

> Hi,
>
> From: "Michael SALOMON" <michaelsalomon78 at gmail.com>
> Subject: [Pgpool-general] Problem with load balancing + automatic failover
> Date: Tue, 29 Apr 2008 16:57:48 +0200
>
> > Fact is, as backend_weight0 = 1 on MASTER server, there is no way I can
> run
> > a SELECT statement on MASTER pgpool server, because it is 100% load
> balanced
> > to
> >  the actually failed database, and then I end up with :
> >
> > - master server -> pgsql -h master -p 9999 -d rep_db -c 'SELECT * FROM
> > my_table'
> > psql:/usr/local/pgsql/sql/select.sql:2: server closed the connection
> > unexpectedly
> >         This probably means the server terminated abnormally
> >         before or while processing the request.
> > psql:/usr/local/pgsql/sql/select.sql:2: connection to server was lost
>
> Could you show us pgpool log?
>
> Regards,
> --
> Yoshiyuki Asaba
> y-asaba at sraoss.co.jp
> _______________________________________________
> Pgpool-general mailing list
> Pgpool-general at pgfoundry.org
> http://pgfoundry.org/mailman/listinfo/pgpool-general
>
-------------- next part --------------
An HTML attachment was scrubbed...
URL: http://pgfoundry.org/pipermail/pgpool-general/attachments/20080505/965301e3/attachment-0001.html

More information about the Pgpool-general mailing list