[Pgpool-general] pgpool 2.2.4: DEALLOCATED children
Tatsuo Ishii
ishii at sraoss.co.jp
Tue Sep 22 13:26:05 UTC 2009
So far I suspect that your clients disconnects to pgpool but pgpool
does not detect it for unknown reason and it's a source of problem.
From your debug log:
> 2009-09-12 00:46:16 ERROR: pid 17759: pool_flush_it: write failed (Broken pipe) offset: 0 wlen: 149
This means the connection between your client and pgpool has been
closed. But *later* pgpool read a close request packet from your client:
> 2009-09-12 00:46:16 DEBUG: pid 17759: read kind from frontend X(58)
This is really weird. Anyway this makes pgpool confused and goes into
problems you are observing I guess.
Attached is a patch that should deal with your problem. Please try it.
--
Tatsuo Ishii
SRA OSS, Inc. Japan
> Hi
> Did you have the chance to analyze this issue?
>
> We are doing some new test in our laboratory, adding more log to
> provide you more details.
>
> Any particular test we can do, to help your analisys?
>
> Thanks
>
> Agustín Almonte F.
>
>
>
>
>
> El 13-09-2009, a las 18:02, Agustin Almonte Ferrada escribió:
>
> > Here is de pgpool.conf file without comments.
> >
> > listen_addresses = '*'
> > port = 9999
> > pcp_port = 9898
> > socket_dir = '/var/run/postgresql'
> > pcp_socket_dir = '/var/run/postgresql'
> > backend_socket_dir = '/var/run/postgresql'
> > pcp_timeout = 10
> > num_init_children = 150
> > max_pool = 2
> > child_life_time = 30
> > connection_life_time = 0
> > child_max_connections = 30
> > client_idle_limit = 0
> > authentication_timeout = 60
> > logdir = '/var/run'
> > replication_mode = true
> > replication_timeout = 5000
> > load_balance_mode = true
> > replication_stop_on_mismatch = false
> > replicate_select = false
> > reset_query_list = 'ABORT; RESET ALL; SET SESSION AUTHORIZATION
> > DEFAULT'
> > print_timestamp = true
> > master_slave_mode = false
> > connection_cache = true
> > health_check_timeout = 20
> > health_check_period = 30
> > health_check_user = 'pgpool'
> > failover_command = '/etc/pgpool/scripts/failover.sh %d %h %p %D %m %M'
> > failback_command = '/etc/pgpool/scripts/failback.sh %d %h %p %D %m %M'
> > insert_lock = false
> > ignore_leading_white_space = true
> > log_statement = true
> > log_connections = true
> > log_hostname = false
> > parallel_mode = false
> > enable_query_cache = false
> >
> > pgpool2_hostname = 'pgpool1'
> > backend_hostname0 = '172.30.0.8'
> > backend_port0 = 5432
> > backend_weight0 = 1
> > backend_data_directory0 = '/var/lib/postgresql/8.1/main'
> >
> > backend_hostname1 = '172.30.0.7'
> > backend_port1 = 5432
> > backend_weight1 = 1
> > backend_data_directory1 = '/var/lib/postgresql/8.1/main'
> >
> > enable_pool_hba = false
> > recovery_user = 'postgres'
> > recovery_password = 'antica'
> > recovery_1st_stage_command = 'pgpool_copy_backup_to_remote'
> > recovery_2nd_stage_command = 'pgpool_recovery_pitr'
> >
> >
> > Agustín Almonte F.
> >
> >
> >
> >
> >
> > El 13-09-2009, a las 2:50, Tatsuo Ishii escribió:
> >
> >> Still studying what's going on...
> >>
> >> Can you show me pgpool.conf file?
> >> --
> >> Tatsuo Ishii
> >> SRA OSS, Inc. Japan
> >>
> >>> Thanks Tatsuo for your reply.
> >>>
> >>> The diferences between backends are just data. We are working with
> >>> pgpool 2.2.1 and some inserts/updates don't get to the second
> >>> backend,
> >>> always is the second backend wich has less data, so we are trying
> >>> now
> >>> with version 2.2.4.
> >>>
> >>>
> >>> Here is the filtered log output for a pid that gets into DEALLOCATE
> >>> state:
> >>>
> >>> 2009-09-12 00:44:31 DEBUG: pid 17759: I am 17759
> >>> 2009-09-12 00:45:51 DEBUG: pid 17759: I am 17759 accept fd 5
> >>> 2009-09-12 00:45:51 LOG: pid 17759: connection received:
> >>> host=127.0.0.1 port=44029
> >>> 2009-09-12 00:45:51 DEBUG: pid 17759: Protocol Major: 3 Minor: 0
> >>> database: sess user: sess
> >>> 2009-09-12 00:45:51 DEBUG: pid 17759: new_connection: connecting 0
> >>> backend
> >>> 2009-09-12 00:45:51 DEBUG: pid 17759: new_connection: connecting 1
> >>> backend
> >>> 2009-09-12 00:45:51 DEBUG: pid 17759: pool_read_message_length:
> >>> slot:
> >>> 0 length: 8
> >>> 2009-09-12 00:45:51 DEBUG: pid 17759: pool_read_message_length:
> >>> slot:
> >>> 1 length: 8
> >>> 2009-09-12 00:45:51 DEBUG: pid 17759: trying clear text password
> >>> authentication
> >>> 2009-09-12 00:45:51 DEBUG: pid 17759: trying clear text password
> >>> authentication
> >>> 2009-09-12 00:45:51 DEBUG: pid 17759: pool_read_message_length2:
> >>> master slot: 0 length: 28
> >>> 2009-09-12 00:45:51 DEBUG: pid 17759: pool_read_message_length2:
> >>> master slot: 1 length: 28
> >>> 2009-09-12 00:45:51 DEBUG: pid 17759: 0 th backend: name:
> >>> client_encoding value: UNICODE
> >>> 2009-09-12 00:45:51 DEBUG: pid 17759: 1 th backend: name:
> >>> client_encoding value: UNICODE
> >>> 2009-09-12 00:45:51 DEBUG: pid 17759: pool_read_message_length2:
> >>> master slot: 0 length: 23
> >>> 2009-09-12 00:45:51 DEBUG: pid 17759: pool_read_message_length2:
> >>> master slot: 1 length: 23
> >>> 2009-09-12 00:45:51 DEBUG: pid 17759: 0 th backend: name: DateStyle
> >>> value: ISO, MDY
> >>> 2009-09-12 00:45:51 DEBUG: pid 17759: 1 th backend: name: DateStyle
> >>> value: ISO, MDY
> >>> 2009-09-12 00:45:51 DEBUG: pid 17759: pool_read_message_length2:
> >>> master slot: 0 length: 25
> >>> 2009-09-12 00:45:51 DEBUG: pid 17759: pool_read_message_length2:
> >>> master slot: 1 length: 25
> >>> 2009-09-12 00:45:51 DEBUG: pid 17759: 0 th backend: name:
> >>> integer_datetimes value: on
> >>> 2009-09-12 00:45:51 DEBUG: pid 17759: 1 th backend: name:
> >>> integer_datetimes value: on
> >>> 2009-09-12 00:45:51 DEBUG: pid 17759: pool_read_message_length2:
> >>> master slot: 0 length: 21
> >>> 2009-09-12 00:45:51 DEBUG: pid 17759: pool_read_message_length2:
> >>> master slot: 1 length: 21
> >>> 2009-09-12 00:45:51 DEBUG: pid 17759: 0 th backend: name:
> >>> is_superuser
> >>> value: off
> >>> 2009-09-12 00:45:51 DEBUG: pid 17759: 1 th backend: name:
> >>> is_superuser
> >>> value: off
> >>> 2009-09-12 00:45:51 DEBUG: pid 17759: pool_read_message_length2:
> >>> master slot: 0 length: 25
> >>> 2009-09-12 00:45:51 DEBUG: pid 17759: pool_read_message_length2:
> >>> master slot: 1 length: 25
> >>> 2009-09-12 00:45:51 DEBUG: pid 17759: 0 th backend: name:
> >>> server_encoding value: UTF8
> >>> 2009-09-12 00:45:51 DEBUG: pid 17759: 1 th backend: name:
> >>> server_encoding value: UTF8
> >>> 2009-09-12 00:45:51 DEBUG: pid 17759: pool_read_message_length2:
> >>> master slot: 0 length: 26
> >>> 2009-09-12 00:45:51 DEBUG: pid 17759: pool_read_message_length2:
> >>> master slot: 1 length: 26
> >>> 2009-09-12 00:45:51 DEBUG: pid 17759: 0 th backend: name:
> >>> server_version value: 8.1.15
> >>> 2009-09-12 00:45:51 DEBUG: pid 17759: 1 th backend: name:
> >>> server_version value: 8.1.15
> >>> 2009-09-12 00:45:51 DEBUG: pid 17759: pool_read_message_length2:
> >>> master slot: 0 length: 31
> >>> 2009-09-12 00:45:51 DEBUG: pid 17759: pool_read_message_length2:
> >>> master slot: 1 length: 31
> >>> 2009-09-12 00:45:51 DEBUG: pid 17759: 0 th backend: name:
> >>> session_authorization value: sess
> >>> 2009-09-12 00:45:51 DEBUG: pid 17759: 1 th backend: name:
> >>> session_authorization value: sess
> >>> 2009-09-12 00:45:51 DEBUG: pid 17759: pool_read_message_length2:
> >>> master slot: 0 length: 36
> >>> 2009-09-12 00:45:51 DEBUG: pid 17759: pool_read_message_length2:
> >>> master slot: 1 length: 36
> >>> 2009-09-12 00:45:51 DEBUG: pid 17759: 0 th backend: name:
> >>> standard_conforming_strings value: off
> >>> 2009-09-12 00:45:51 DEBUG: pid 17759: 1 th backend: name:
> >>> standard_conforming_strings value: off
> >>> 2009-09-12 00:45:51 DEBUG: pid 17759: pool_read_message_length2:
> >>> master slot: 0 length: 23
> >>> 2009-09-12 00:45:51 DEBUG: pid 17759: pool_read_message_length2:
> >>> master slot: 1 length: 23
> >>> 2009-09-12 00:45:51 DEBUG: pid 17759: 0 th backend: name: TimeZone
> >>> value: localtime
> >>> 2009-09-12 00:45:51 DEBUG: pid 17759: 1 th backend: name: TimeZone
> >>> value: localtime
> >>> 2009-09-12 00:45:51 DEBUG: pid 17759: pool_read_message_length:
> >>> slot:
> >>> 0 length: 12
> >>> 2009-09-12 00:45:51 DEBUG: pid 17759: pool_read_message_length:
> >>> slot:
> >>> 1 length: 12
> >>> 2009-09-12 00:45:51 DEBUG: pid 17759: pool_send_auth_ok: send pid
> >>> 26722 to frontend
> >>> 2009-09-12 00:45:51 DEBUG: pid 17759: select_load_balancing_node:
> >>> selected backend id is 1
> >>> 2009-09-12 00:45:51 DEBUG: pid 17759: read_kind_from_backend: read
> >>> kind from 0 th backend Z NUM_BACKENDS: 2
> >>> 2009-09-12 00:45:51 DEBUG: pid 17759: read_kind_from_backend: read
> >>> kind from 1 th backend Z NUM_BACKENDS: 2
> >>> 2009-09-12 00:45:51 DEBUG: pid 17759: pool_process_query: kind from
> >>> backend: Z
> >>> 2009-09-12 00:45:51 DEBUG: pid 17759: pool_read_message_length:
> >>> slot:
> >>> 0 length: 5
> >>> 2009-09-12 00:45:51 DEBUG: pid 17759: pool_read_message_length:
> >>> slot:
> >>> 1 length: 5
> >>> 2009-09-12 00:45:51 DEBUG: pid 17759: ReadyForQuery: message
> >>> length: 5
> >>> 2009-09-12 00:45:51 DEBUG: pid 17759: ReadyForQuery: transaction
> >>> state: I
> >>> 2009-09-12 00:45:51 DEBUG: pid 17759: read kind from frontend P(50)
> >>> 2009-09-12 00:45:51 DEBUG: pid 17759: Parse: portal name <>
> >>> 2009-09-12 00:45:51 DEBUG: pid 17759: pool_read_message_length:
> >>> slot:
> >>> 0 length: 5
> >>> 2009-09-12 00:45:51 DEBUG: pid 17759: pool_read_message_length:
> >>> slot:
> >>> 1 length: 5
> >>> 2009-09-12 00:45:51 DEBUG: pid 17759: ReadyForQuery: message
> >>> length: 5
> >>> 2009-09-12 00:45:51 DEBUG: pid 17759: ReadyForQuery: transaction
> >>> state: I
> >>> 2009-09-12 00:45:51 DEBUG: pid 17759: waiting for master completing
> >>> the query
> >>> 2009-09-12 00:45:51 DEBUG: pid 17759: detect_error: kind: 1
> >>> 2009-09-12 00:45:51 DEBUG: pid 17759: waiting for 1th backend
> >>> completing the query
> >>> 2009-09-12 00:45:51 DEBUG: pid 17759: read_kind_from_backend: read
> >>> kind from 0 th backend 1 NUM_BACKENDS: 2
> >>> 2009-09-12 00:45:51 DEBUG: pid 17759: read_kind_from_backend: read
> >>> kind from 1 th backend 1 NUM_BACKENDS: 2
> >>> 2009-09-12 00:45:51 DEBUG: pid 17759: read kind from frontend B(42)
> >>> 2009-09-12 00:45:51 DEBUG: pid 17759: bind message: portal_name
> >>> stmt_name
> >>> 2009-09-12 00:45:51 DEBUG: pid 17759: read_kind_from_backend: read
> >>> kind from 0 th backend 2 NUM_BACKENDS: 2
> >>> 2009-09-12 00:45:51 DEBUG: pid 17759: read_kind_from_backend: read
> >>> kind from 1 th backend 2 NUM_BACKENDS: 2
> >>> 2009-09-12 00:45:51 DEBUG: pid 17759: read kind from frontend D(44)
> >>> 2009-09-12 00:45:51 DEBUG: pid 17759: read_kind_from_backend: read
> >>> kind from 0 th backend T NUM_BACKENDS: 2
> >>> 2009-09-12 00:45:51 DEBUG: pid 17759: read_kind_from_backend: read
> >>> kind from 1 th backend T NUM_BACKENDS: 2
> >>> 2009-09-12 00:45:51 DEBUG: pid 17759: read kind from frontend E(45)
> >>> 2009-09-12 00:45:51 DEBUG: pid 17759: Execute: portal name <>
> >>> 2009-09-12 00:45:51 DEBUG: pid 17759: wait_for_query_response:
> >>> waiting
> >>> for backend 0 completing the query
> >>> 2009-09-12 00:45:51 DEBUG: pid 17759: detect_error: kind: D
> >>> 2009-09-12 00:45:51 DEBUG: pid 17759: detect_error: kind: D
> >>> 2009-09-12 00:45:51 DEBUG: pid 17759: detect_error: kind: D
> >>> 2009-09-12 00:45:51 DEBUG: pid 17759: detect_error: kind: D
> >>> 2009-09-12 00:45:51 DEBUG: pid 17759: wait_for_query_response:
> >>> waiting
> >>> for backend 1 completing the query
> >>> 2009-09-12 00:45:51 DEBUG: pid 17759: read_kind_from_backend: read
> >>> kind from 0 th backend D NUM_BACKENDS: 2
> >>> 2009-09-12 00:45:51 DEBUG: pid 17759: read_kind_from_backend: read
> >>> kind from 1 th backend D NUM_BACKENDS: 2
> >>> 2009-09-12 00:45:51 DEBUG: pid 17759: read_kind_from_backend: read
> >>> kind from 0 th backend C NUM_BACKENDS: 2
> >>> 2009-09-12 00:45:51 DEBUG: pid 17759: read_kind_from_backend: read
> >>> kind from 1 th backend C NUM_BACKENDS: 2
> >>> 2009-09-12 00:45:51 DEBUG: pid 17759: read kind from frontend S(53)
> >>> 2009-09-12 00:45:51 DEBUG: pid 17759: detect_error: kind: Z
> >>> 2009-09-12 00:45:51 DEBUG: pid 17759: detect_error: kind: Z
> >>> .
> >>> .
> >>> .
> >>> 2009-09-12 00:45:56 DEBUG: pid 17759: Execute: portal name <>
> >>> 2009-09-12 00:45:56 DEBUG: pid 17759: wait_for_query_response:
> >>> waiting
> >>> for backend 1 completing the query
> >>> 2009-09-12 00:45:56 DEBUG: pid 17759: read_kind_from_backend: read
> >>> kind from 1 th backend C NUM_BACKENDS: 2
> >>> 2009-09-12 00:45:56 DEBUG: pid 17759: read kind from frontend S(53)
> >>> 2009-09-12 00:45:56 DEBUG: pid 17759: detect_error: kind: Z
> >>> 2009-09-12 00:45:56 DEBUG: pid 17759: detect_error: kind: Z
> >>> 2009-09-12 00:45:56 DEBUG: pid 17759: read_kind_from_backend: read
> >>> kind from 1 th backend Z NUM_BACKENDS: 2
> >>> 2009-09-12 00:45:56 DEBUG: pid 17759: pool_process_query: kind from
> >>> backend: Z
> >>> 2009-09-12 00:45:56 DEBUG: pid 17759: pool_read_message_length:
> >>> slot:
> >>> 1 length: 5
> >>> 2009-09-12 00:45:56 DEBUG: pid 17759: ReadyForQuery: message
> >>> length: 5
> >>> 2009-09-12 00:45:56 DEBUG: pid 17759: ReadyForQuery: transaction
> >>> state: I
> >>> 2009-09-12 00:45:56 DEBUG: pid 17759: end_load_balance: end load
> >>> balance mode
> >>> 2009-09-12 00:46:06 DEBUG: pid 17759: read kind from frontend P(50)
> >>> 2009-09-12 00:46:06 DEBUG: pid 17759: Parse: portal name <>
> >>> 2009-09-12 00:46:06 DEBUG: pid 17759: pool_read_message_length:
> >>> slot:
> >>> 0 length: 5
> >>> 2009-09-12 00:46:06 DEBUG: pid 17759: pool_read_message_length:
> >>> slot:
> >>> 1 length: 5
> >>> 2009-09-12 00:46:06 DEBUG: pid 17759: ReadyForQuery: message
> >>> length: 5
> >>> 2009-09-12 00:46:06 DEBUG: pid 17759: ReadyForQuery: transaction
> >>> state: I
> >>> 2009-09-12 00:46:06 DEBUG: pid 17759: waiting for master completing
> >>> the query
> >>> 2009-09-12 00:46:06 DEBUG: pid 17759: detect_error: kind: 1
> >>> 2009-09-12 00:46:06 DEBUG: pid 17759: waiting for 1th backend
> >>> completing the query
> >>> 2009-09-12 00:46:06 DEBUG: pid 17759: read_kind_from_backend: read
> >>> kind from 0 th backend 1 NUM_BACKENDS: 2
> >>> 2009-09-12 00:46:06 DEBUG: pid 17759: read_kind_from_backend: read
> >>> kind from 1 th backend 1 NUM_BACKENDS: 2
> >>> 2009-09-12 00:46:06 DEBUG: pid 17759: read kind from frontend B(42)
> >>> 2009-09-12 00:46:06 DEBUG: pid 17759: bind message: portal_name
> >>> stmt_name
> >>> 2009-09-12 00:46:06 DEBUG: pid 17759: read_kind_from_backend: read
> >>> kind from 0 th backend 2 NUM_BACKENDS: 2
> >>> 2009-09-12 00:46:06 DEBUG: pid 17759: read_kind_from_backend: read
> >>> kind from 1 th backend 2 NUM_BACKENDS: 2
> >>> 2009-09-12 00:46:06 DEBUG: pid 17759: read kind from frontend D(44)
> >>> 2009-09-12 00:46:06 DEBUG: pid 17759: read_kind_from_backend: read
> >>> kind from 0 th backend T NUM_BACKENDS: 2
> >>> 2009-09-12 00:46:06 DEBUG: pid 17759: read_kind_from_backend: read
> >>> kind from 1 th backend T NUM_BACKENDS: 2
> >>> 2009-09-12 00:46:06 DEBUG: pid 17759: read kind from frontend E(45)
> >>> 2009-09-12 00:46:06 DEBUG: pid 17759: Execute: portal name <>
> >>> 2009-09-12 00:46:06 DEBUG: pid 17759: wait_for_query_response:
> >>> waiting
> >>> for backend 1 completing the query
> >>> 2009-09-12 00:46:06 DEBUG: pid 17759: read_kind_from_backend: read
> >>> kind from 1 th backend C NUM_BACKENDS: 2
> >>> 2009-09-12 00:46:06 DEBUG: pid 17759: read kind from frontend S(53)
> >>> 2009-09-12 00:46:06 DEBUG: pid 17759: detect_error: kind: Z
> >>> 2009-09-12 00:46:06 DEBUG: pid 17759: detect_error: kind: Z
> >>> 2009-09-12 00:46:06 DEBUG: pid 17759: read_kind_from_backend: read
> >>> kind from 1 th backend Z NUM_BACKENDS: 2
> >>> 2009-09-12 00:46:06 DEBUG: pid 17759: pool_process_query: kind from
> >>> backend: Z
> >>> 2009-09-12 00:46:06 DEBUG: pid 17759: pool_read_message_length:
> >>> slot:
> >>> 1 length: 5
> >>> 2009-09-12 00:46:06 DEBUG: pid 17759: ReadyForQuery: message
> >>> length: 5
> >>> 2009-09-12 00:46:06 DEBUG: pid 17759: ReadyForQuery: transaction
> >>> state: I
> >>> 2009-09-12 00:46:06 DEBUG: pid 17759: end_load_balance: end load
> >>> balance mode
> >>> 2009-09-12 00:46:16 DEBUG: pid 17759: read kind from frontend P(50)
> >>> 2009-09-12 00:46:16 DEBUG: pid 17759: Parse: portal name <>
> >>> 2009-09-12 00:46:16 DEBUG: pid 17759: pool_read_message_length:
> >>> slot:
> >>> 0 length: 5
> >>> 2009-09-12 00:46:16 DEBUG: pid 17759: pool_read_message_length:
> >>> slot:
> >>> 1 length: 5
> >>> 2009-09-12 00:46:16 DEBUG: pid 17759: ReadyForQuery: message
> >>> length: 5
> >>> 2009-09-12 00:46:16 DEBUG: pid 17759: ReadyForQuery: transaction
> >>> state: I
> >>> 2009-09-12 00:46:16 DEBUG: pid 17759: waiting for master completing
> >>> the query
> >>> 2009-09-12 00:46:16 DEBUG: pid 17759: detect_error: kind: 1
> >>> 2009-09-12 00:46:16 DEBUG: pid 17759: waiting for 1th backend
> >>> completing the query
> >>> 2009-09-12 00:46:16 DEBUG: pid 17759: read_kind_from_backend: read
> >>> kind from 0 th backend 1 NUM_BACKENDS: 2
> >>> 2009-09-12 00:46:16 DEBUG: pid 17759: read_kind_from_backend: read
> >>> kind from 1 th backend 1 NUM_BACKENDS: 2
> >>> 2009-09-12 00:46:16 DEBUG: pid 17759: read kind from frontend B(42)
> >>> 2009-09-12 00:46:16 DEBUG: pid 17759: bind message: portal_name
> >>> stmt_name
> >>> 2009-09-12 00:46:16 DEBUG: pid 17759: read_kind_from_backend: read
> >>> kind from 0 th backend 2 NUM_BACKENDS: 2
> >>> 2009-09-12 00:46:16 DEBUG: pid 17759: read_kind_from_backend: read
> >>> kind from 1 th backend 2 NUM_BACKENDS: 2
> >>> 2009-09-12 00:46:16 ERROR: pid 17759: pool_flush_it: write failed
> >>> (Broken pipe) offset: 0 wlen: 5
> >>> 2009-09-12 00:46:16 DEBUG: pid 17759: read kind from frontend D(44)
> >>> 2009-09-12 00:46:16 DEBUG: pid 17759: read_kind_from_backend: read
> >>> kind from 0 th backend T NUM_BACKENDS: 2
> >>> 2009-09-12 00:46:16 DEBUG: pid 17759: read_kind_from_backend: read
> >>> kind from 1 th backend T NUM_BACKENDS: 2
> >>> 2009-09-12 00:46:16 ERROR: pid 17759: pool_flush_it: write failed
> >>> (Broken pipe) offset: 0 wlen: 149
> >>> 2009-09-12 00:46:16 DEBUG: pid 17759: read kind from frontend E(45)
> >>> 2009-09-12 00:46:16 DEBUG: pid 17759: Execute: portal name <>
> >>> 2009-09-12 00:46:16 DEBUG: pid 17759: wait_for_query_response:
> >>> waiting
> >>> for backend 1 completing the query
> >>> 2009-09-12 00:46:16 DEBUG: pid 17759: read_kind_from_backend: read
> >>> kind from 1 th backend C NUM_BACKENDS: 2
> >>> 2009-09-12 00:46:16 DEBUG: pid 17759: read kind from frontend S(53)
> >>> 2009-09-12 00:46:16 DEBUG: pid 17759: read kind from frontend X(58)
> >>> 2009-09-12 00:46:16 LOG: pid 17759: statement: RESET ALL
> >>> 2009-09-12 00:46:16 DEBUG: pid 17759: do_command: Query: BEGIN
> >>> 2009-09-12 00:46:16 DEBUG: pid 17759: detect_error: kind: C
> >>> 2009-09-12 00:46:16 DEBUG: pid 17759: do_command: kind: C
> >>> 2009-09-12 00:46:16 DEBUG: pid 17759: do_command: kind: Z
> >>> 2009-09-12 00:46:16 DEBUG: pid 17759: do_command: transaction
> >>> state: T
> >>> 2009-09-12 00:46:16 DEBUG: pid 17759: do_command: Query: BEGIN
> >>> 2009-09-12 00:46:16 DEBUG: pid 17759: detect_error: kind: Z
> >>> 2009-09-12 00:46:16 DEBUG: pid 17759: do_command: kind: Z
> >>> 2009-09-12 00:46:16 DEBUG: pid 17759: do_command: transaction
> >>> state: I
> >>> 2009-09-12 00:46:16 DEBUG: pid 17759: wait_for_query_response:
> >>> waiting
> >>> for backend 0 completing the query
> >>> 2009-09-12 00:46:16 DEBUG: pid 17759: detect_error: kind: C
> >>> 2009-09-12 00:46:16 DEBUG: pid 17759: detect_error: kind: C
> >>> 2009-09-12 00:46:16 DEBUG: pid 17759: detect_error: kind: C
> >>> 2009-09-12 00:46:16 DEBUG: pid 17759: detect_error: kind: C
> >>> 2009-09-12 00:46:16 DEBUG: pid 17759: wait_for_query_response:
> >>> waiting
> >>> for backend 1 completing the query
> >>> 2009-09-12 00:46:16 DEBUG: pid 17759: read_kind_from_backend: read
> >>> kind from 0 th backend C NUM_BACKENDS: 2
> >>> 2009-09-12 00:46:16 DEBUG: pid 17759: read_kind_from_backend: read
> >>> kind from 1 th backend C NUM_BACKENDS: 2
> >>> 2009-09-12 00:46:16 DEBUG: pid 17759: pool_process_query: kind from
> >>> backend: C
> >>> 2009-09-12 00:46:16 ERROR: pid 17759: pool_flush_it: write failed
> >>> (Broken pipe) offset: 0 wlen: 12
> >>> 2009-09-12 00:46:16 DEBUG: pid 17759: read_kind_from_backend: read
> >>> kind from 0 th backend Z NUM_BACKENDS: 2
> >>> 2009-09-12 00:46:16 DEBUG: pid 17759: read_kind_from_backend: read
> >>> kind from 1 th backend Z NUM_BACKENDS: 2
> >>> 2009-09-12 00:46:16 DEBUG: pid 17759: pool_process_query: kind from
> >>> backend: Z
> >>> 2009-09-12 00:46:16 DEBUG: pid 17759: pool_read_message_length:
> >>> slot:
> >>> 0 length: 5
> >>> 2009-09-12 00:46:16 DEBUG: pid 17759: pool_read_message_length:
> >>> slot:
> >>> 1 length: 5
> >>> 2009-09-12 00:46:16 DEBUG: pid 17759: ReadyForQuery: message
> >>> length: 5
> >>> 2009-09-12 00:46:16 DEBUG: pid 17759: ReadyForQuery: transaction
> >>> state: T
> >>> 2009-09-12 00:46:16 DEBUG: pid 17759: do_command: Query: COMMIT
> >>> 2009-09-12 00:46:16 DEBUG: pid 17759: detect_error: kind: C
> >>> 2009-09-12 00:46:16 DEBUG: pid 17759: do_command: kind: C
> >>> 2009-09-12 00:46:16 DEBUG: pid 17759: do_command: kind: Z
> >>> 2009-09-12 00:46:16 DEBUG: pid 17759: do_command: Query: COMMIT
> >>> 2009-09-12 00:46:16 DEBUG: pid 17759: detect_error: kind: C
> >>> 2009-09-12 00:46:16 DEBUG: pid 17759: do_command: kind: C
> >>> 2009-09-12 00:46:16 DEBUG: pid 17759: do_command: kind: Z
> >>> 2009-09-12 00:46:16 DEBUG: pid 17759: pool_read_message_length:
> >>> slot:
> >>> 0 length: 5
> >>> 2009-09-12 00:46:16 DEBUG: pid 17759: pool_read_message_length:
> >>> slot:
> >>> 1 length: 5
> >>> 2009-09-12 00:46:16 DEBUG: pid 17759: ReadyForQuery: message
> >>> length: 5
> >>> 2009-09-12 00:46:16 ERROR: pid 17759: pool_read_kind: kind does not
> >>> match between master(73) slot[1] (84)
> >>> 2009-09-12 00:46:16 DEBUG: pid 17759: error in resetting
> >>> connections.
> >>> discarding connection pools...
> >>> 2009-09-12 00:46:16 DEBUG: pid 17759: I am 17759 accept fd 5
> >>> 2009-09-12 00:46:16 LOG: pid 17759: connection received:
> >>> host=127.0.0.1 port=51447
> >>> 2009-09-12 00:46:16 DEBUG: pid 17759: Protocol Major: 3 Minor: 0
> >>> database: sess user: sess
> >>> 2009-09-12 00:46:16 DEBUG: pid 17759: new_connection: connecting 0
> >>> backend
> >>> 2009-09-12 00:46:16 DEBUG: pid 17759: new_connection: connecting 1
> >>> backend
> >>>
> >>>
> >>>
> >>> Agustín Almonte F.
> >>>
> >>>
> >>>
> >>>
> >>>
> >>> El 11-09-2009, a las 22:06, Tatsuo Ishii escribió:
> >>>
> >>>> My guess is DEALLOCATE is being issued at end of session between
> >>>> pgpool and PostgreSQL. For some reason PostgreSQL returns weired
> >>>> packet kind 0x73 on node 0 and 0x84 on node 1.
> >>>>
> >>>> Anyway, I need more information.
> >>>>
> >>>> Do you find some errors in PostgreSQL log? What kind of
> >>>> difference are
> >>>> there in your databases?
> >>>> --
> >>>> Tatsuo Ishii
> >>>> SRA OSS, Inc. Japan
> >>>>
> >>>>> Hi,
> >>>>>
> >>>>> I'm testing pgpool 2.2.4 with some problems.... i hope someone can
> >>>>> help me to figure out what the problem is.
> >>>>>
> >>>>>
> >>>>> I have two backends that unfortunately have diferences, that's the
> >>>>> initial scenario when i started pgpool, everything goes well for
> >>>>> some
> >>>>> seconds but after a while a lot of error come out:
> >>>>>
> >>>>> (filtered output)
> >>>>> 2009-09-11 02:19:03 ERROR: pid 28468: pool_flush_it: write failed
> >>>>> (Broken pipe) offset: 0 wlen: 12
> >>>>> 2009-09-11 02:19:03 ERROR: pid 27857: pool_flush_it: write failed
> >>>>> (Broken pipe) offset: 0 wlen: 12
> >>>>> 2009-09-11 02:19:03 ERROR: pid 27857: pool_read_kind: kind does
> >>>>> not
> >>>>> match between master(73) slot[1] (84)
> >>>>> 2009-09-11 02:19:03 ERROR: pid 28235: pool_read_kind: kind does
> >>>>> not
> >>>>> match between master(84) slot[1] (73)
> >>>>> 2009-09-11 02:19:03 ERROR: pid 28414: pool_flush_it: write failed
> >>>>> (Broken pipe) offset: 0 wlen: 12
> >>>>> 2009-09-11 02:19:03 ERROR: pid 27866: pool_flush_it: write failed
> >>>>> (Broken pipe) offset: 0 wlen: 12
> >>>>> 2009-09-11 02:19:03 ERROR: pid 28414: pool_read_kind: kind does
> >>>>> not
> >>>>> match between master(73) slot[1] (84)
> >>>>> 2009-09-11 02:19:03 ERROR: pid 28310: pool_flush_it: write failed
> >>>>> (Broken pipe) offset: 0 wlen: 12
> >>>>> 2009-09-11 02:19:03 ERROR: pid 28469: pool_read_kind: kind does
> >>>>> not
> >>>>> match between master(73) slot[1] (84)
> >>>>> 2009-09-11 02:19:03 ERROR: pid 28419: pool_flush_it: write failed
> >>>>> (Broken pipe) offset: 0 wlen: 5
> >>>>> 2009-09-11 02:19:03 ERROR: pid 28419: pool_flush_it: write failed
> >>>>> (Broken pipe) offset: 0 wlen: 149
> >>>>> 2009-09-11 02:19:03 ERROR: pid 27866: pool_read_kind: kind does
> >>>>> not
> >>>>> match between master(84) slot[1] (73)
> >>>>> 2009-09-11 02:19:03 ERROR: pid 28310: pool_read_kind: kind does
> >>>>> not
> >>>>> match between master(84) slot[1] (73)
> >>>>> 2009-09-11 02:19:03 ERROR: pid 28221: pool_flush_it: write failed
> >>>>> (Broken pipe) offset: 0 wlen: 5
> >>>>>
> >>>>> pgpool processes go from:
> >>>>>
> >>>>> root 28166 27814 0 02:13 ? 00:00:00 pgpool: wait for
> >>>>> connection request
> >>>>> root 28167 27814 0 02:13 ? 00:00:00 pgpool: wait for
> >>>>> connection request
> >>>>> root 28169 27814 6 02:13 ? 00:00:10 pgpool: sess sess
> >>>>> 127.0.0.1(43911) DEALLOCATE
> >>>>> root 28170 27814 0 02:13 ? 00:00:00 pgpool: wait for
> >>>>> connection request
> >>>>> root 28174 27814 0 02:13 ? 00:00:00 pgpool: sess sess
> >>>>> 127.0.0.1(35292) idle
> >>>>> root 28178 27814 1 02:13 ? 00:00:02 pgpool: sess sess
> >>>>> 127.0.0.1(44647) DEALLOCATE
> >>>>> root 28179 27814 1 02:13 ? 00:00:02 pgpool: sess sess
> >>>>> 127.0.0.1(47125) DEALLOCATE
> >>>>> root 28181 27814 0 02:13 ? 00:00:00 pgpool: wait for
> >>>>> connection request
> >>>>> root 28182 27814 0 02:13 ? 00:00:00 pgpool: sess sess
> >>>>> 127.0.0.1(52477) idle
> >>>>> root 28187 27814 0 02:13 ? 00:00:00 pgpool: wait for
> >>>>> connection request
> >>>>> root 28193 27814 0 02:14 ? 00:00:00 pgpool: wait for
> >>>>> connection request
> >>>>> root 28194 27814 0 02:14 ? 00:00:00 pgpool: wait for
> >>>>> connection request
> >>>>> root 28195 27814 0 02:14 ? 00:00:00 pgpool: wait for
> >>>>> connection request
> >>>>>
> >>>>>
> >>>>> to:
> >>>>>
> >>>>> root 27853 27814 0 02:11 ? 00:00:01 pgpool: sess sess
> >>>>> 127.0.0.1(58341) DEALLOCATE
> >>>>> root 27887 27814 7 02:11 ? 00:00:21 pgpool: sess sess
> >>>>> 127.0.0.1(49142) DEALLOCATE
> >>>>> root 27897 27814 4 02:11 ? 00:00:14 pgpool: sess sess
> >>>>> 127.0.0.1(58998) DEALLOCATE
> >>>>> root 27922 27814 5 02:11 ? 00:00:16 pgpool: sess sess
> >>>>> 127.0.0.1(49541) DEALLOCATE
> >>>>> root 27923 27814 11 02:11 ? 00:00:34 pgpool: sess sess
> >>>>> 127.0.0.1(36883) DEALLOCATE
> >>>>> root 27933 27814 7 02:11 ? 00:00:21 pgpool: sess sess
> >>>>> 127.0.0.1(42722) DEALLOCATE
> >>>>> root 27937 27814 7 02:11 ? 00:00:22 pgpool: sess sess
> >>>>> 127.0.0.1(52656) DEALLOCATE
> >>>>> root 27939 27814 3 02:11 ? 00:00:10 pgpool: sess sess
> >>>>> 127.0.0.1(47648) DEALLOCATE
> >>>>> root 27947 27814 11 02:11 ? 00:00:35 pgpool: sess sess
> >>>>> 127.0.0.1(44597) DEALLOCATE
> >>>>> root 27952 27814 5 02:11 ? 00:00:16 pgpool: sess sess
> >>>>> 127.0.0.1(57546) DEALLOCATE
> >>>>> root 27954 27814 11 02:11 ? 00:00:34 pgpool: sess sess
> >>>>> 127.0.0.1(50946) DEALLOCATE
> >>>>> root 28155 27814 2 02:12 ? 00:00:04 pgpool: sess sess
> >>>>> 127.0.0.1(47095) DEALLOCATE
> >>>>> root 28159 27814 0 02:13 ? 00:00:00 pgpool: sess sess
> >>>>> 127.0.0.1(52691) DEALLOCATE
> >>>>> root 28163 27814 6 02:13 ? 00:00:10 pgpool: sess sess
> >>>>> 127.0.0.1(56219) DEALLOCATE
> >>>>> root 28169 27814 6 02:13 ? 00:00:11 pgpool: sess sess
> >>>>> 127.0.0.1(43911) DEALLOCATE
> >>>>> root 28178 27814 1 02:13 ? 00:00:02 pgpool: sess sess
> >>>>> 127.0.0.1(44647) DEALLOCATE
> >>>>>
> >>>>>
> >>>>> And then everything stop working....
> >>>>>
> >>>>>
> >>>>> Is this a normal behaviour when backends are diferents? What can
> >>>>> be
> >>>>> the reason for children going to DEALLOCATE state?
> >>>>>
> >>>>>
> >>>>> Thanks in Advance
> >>>>> Agustín Almonte F.
> >>>>>
> >>>>>
> >>>>>
> >>>>>
> >>>>>
> >>>>> _______________________________________________
> >>>>> Pgpool-general mailing list
> >>>>> Pgpool-general at pgfoundry.org
> >>>>> http://pgfoundry.org/mailman/listinfo/pgpool-general
-------------- next part --------------
Index: pool_process_query.c
===================================================================
RCS file: /cvsroot/pgpool/pgpool-II/pool_process_query.c,v
retrieving revision 1.141.2.19
diff -c -r1.141.2.19 pool_process_query.c
*** pool_process_query.c 17 Sep 2009 11:17:09 -0000 1.141.2.19
--- pool_process_query.c 22 Sep 2009 13:14:44 -0000
***************
*** 1755,1761 ****
pool_write(frontend, &kind, 1);
sendlen = htonl(len1+4);
pool_write(frontend, &sendlen, sizeof(sendlen));
! status = pool_write(frontend, p1, len1);
}
/* save the received result for each kind */
--- 1755,1761 ----
pool_write(frontend, &kind, 1);
sendlen = htonl(len1+4);
pool_write(frontend, &sendlen, sizeof(sendlen));
! pool_write(frontend, p1, len1);
}
/* save the received result for each kind */
***************
*** 1863,1870 ****
ret = SimpleForwardToFrontend(kind1, frontend, backend);
if (ret != POOL_CONTINUE)
return ret;
! if (pool_flush(frontend))
! return POOL_END;
}
if (ret != POOL_CONTINUE)
--- 1863,1869 ----
ret = SimpleForwardToFrontend(kind1, frontend, backend);
if (ret != POOL_CONTINUE)
return ret;
! pool_flush(frontend;
}
if (ret != POOL_CONTINUE)
More information about the Pgpool-general
mailing list