[Pgpool-general] pgpool 2.2.4: DEALLOCATED children
Tatsuo Ishii
ishii at sraoss.co.jp
Tue Sep 22 13:47:45 UTC 2009
Oops. Wrong patch. Please try this one.
--
Tatsuo Ishii
SRA OSS, Inc. Japan
> 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:46:42 -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