[Pgpool-general] Pgpool Replication failure, kind does not match

[Axel.Weber at rtl.de]

Hello,

I am running pgpool 3.0.1 on a gentoo server.
On a weekly period I get a replication failure, but I can' t find the
reason why. 

It has been running for over a year without any problems (older
version). The difference is replication_stop_on_mismatch was set to
false now it is set to true.


I enabled the debug mode and the last failure happend while running a
simple select statement, how could that be???.
I would be pleased to get any help since the service is online!

Best regards

Axel

Underneath you will find an syslog excerpt:
Jun 15 16:46:57 clever pgpool: 2006-06-15 16:46:57 DEBUG: pid 19153:
Query: SELECT name FROM comp WHERE se_id='TESTPR88'
Jun 15 16:46:57 clever pgpool: 2006-06-15 16:46:57 DEBUG: pid 19153:
waiting for master completing the query
Jun 15 16:46:57 clever pgpool: 2006-06-15 16:46:57 DEBUG: pid 19153:
read kind from backend T
Jun 15 16:46:57 clever pgpool: 2006-06-15 16:46:57 DEBUG: pid 19153:
pool_process_query: waiting for secondary for data ready
Jun 15 16:46:57 clever pgpool: 2006-06-15 16:46:57 DEBUG: pid 19153:
pool_process_query: kind from backend: T
Jun 15 16:46:57 clever pgpool: 2006-06-15 16:46:57 DEBUG: pid 19153:
read kind from backend pending data D len: 40 po: 30
Jun 15 16:46:57 clever pgpool: 2006-06-15 16:46:57 DEBUG: pid 19153:
pool_process_query: kind from backend: D
Jun 15 16:46:57 clever pgpool: 2006-06-15 16:46:57 DEBUG: pid 19153:
read kind from backend pending data C len: 17 po: 53
Jun 15 16:46:57 clever pgpool: 2006-06-15 16:46:57 DEBUG: pid 19153:
pool_process_query: kind from backend: C
Jun 15 16:46:57 clever pgpool: 2006-06-15 16:46:57 DEBUG: pid 19153:
read kind from backend pending data Z len: 5 po: 65
Jun 15 16:46:57 clever pgpool: 2006-06-15 16:46:57 DEBUG: pid 19153:
pool_process_query: kind from backend: Z
Jun 15 16:46:57 clever pgpool: 2006-06-15 16:46:57 DEBUG: pid 19153:
pool_read_message_length: lenghth: 5
Jun 15 16:46:57 clever pgpool: 2006-06-15 16:46:57 DEBUG: pid 19153:
ReadyForQuery: message length: 5
Jun 15 16:46:57 clever pgpool: 2006-06-15 16:46:57 DEBUG: pid 19153:
ReadyForQuery: transaction state: I
Jun 15 16:46:57 clever pgpool: 2006-06-15 16:46:57 DEBUG: pid 19153:
read kind from frontend Q(51)
Jun 15 16:46:57 clever pgpool: 2006-06-15 16:46:57 DEBUG: pid 19153:
Query: SELECT name, level FROM wav WHERE se_id='TESTPR88'
Jun 15 16:46:57 clever pgpool: 2006-06-15 16:46:57 DEBUG: pid 19153:
waiting for master completing the query
Jun 15 16:46:57 clever pgpool: 2006-06-15 16:46:57 DEBUG: pid 19153:
read kind from backend T
Jun 15 16:46:57 clever pgpool: 2006-06-15 16:46:57 DEBUG: pid 19153:
pool_process_query: waiting for secondary for data ready
Jun 15 16:46:57 clever pgpool: 2006-06-15 16:46:57 DEBUG: pid 19153:
pool_process_query: kind from backend: T
Jun 15 16:46:57 clever pgpool: 2006-06-15 16:46:57 DEBUG: pid 19153:
read kind from backend pending data C len: 17 po: 54
Jun 15 16:46:57 clever pgpool: 2006-06-15 16:46:57 DEBUG: pid 19153:
pool_process_query: kind from backend: C
Jun 15 16:46:57 clever pgpool: 2006-06-15 16:46:57 DEBUG: pid 19153:
read kind from backend pending data Z len: 5 po: 66
Jun 15 16:46:57 clever pgpool: 2006-06-15 16:46:57 DEBUG: pid 19153:
pool_process_query: kind from backend: Z
Jun 15 16:46:57 clever pgpool: 2006-06-15 16:46:57 DEBUG: pid 19153:
pool_read_message_length: lenghth: 5
Jun 15 16:46:57 clever pgpool: 2006-06-15 16:46:57 DEBUG: pid 19153:
ReadyForQuery: message length: 5
Jun 15 16:46:57 clever pgpool: 2006-06-15 16:46:57 DEBUG: pid 19153:
ReadyForQuery: transaction state: I
Jun 15 16:46:57 clever pgpool: 2006-06-15 16:46:57 DEBUG: pid 19153:
read kind from frontend Q(51)
Jun 15 16:46:57 clever pgpool: 2006-06-15 16:46:57 DEBUG: pid 19153:
Query: SELECT name, content FROM TEXTBOX WHERE se_id='TESTPR88'
Jun 15 16:46:57 clever pgpool: 2006-06-15 16:46:57 DEBUG: pid 19153:
waiting for master completing the query
Jun 15 16:46:57 clever pgpool: 2006-06-15 16:46:57 DEBUG: pid 19153:
read kind from backend T
Jun 15 16:46:57 clever pgpool: 2006-06-15 16:46:57 DEBUG: pid 19153:
pool_process_query: waiting for secondary for data ready
Jun 15 16:46:57 clever pgpool: 2006-06-15 16:46:57 DEBUG: pid 19153:
pool_process_query: kind from backend: T
Jun 15 16:46:57 clever pgpool: 2006-06-15 16:46:57 ERROR: pid 19153:
pool_process_query: kind does not match between backends master(C) sec
ondary(D)
Jun 15 16:46:57 clever pgpool: 2006-06-15 16:46:57 LOG:   pid 19153:
notice_backend_error: master: 1 fail over request from pid 19153
Jun 15 16:46:57 clever pgpool: 2006-06-15 16:46:57 DEBUG: pid 19146: I
am 19146 accept fd 6
Jun 15 16:46:57 clever pgpool: 2006-06-15 16:46:57 DEBUG: pid 19146:
Protocol Major: 1234 Minor: 5679 database:  user:
Jun 15 16:46:57 clever pgpool: 2006-06-15 16:46:57 DEBUG: pid 19146:
SSLRequest: sent N; retry startup
Jun 15 16:46:57 clever pgpool: 2006-06-15 16:46:57 DEBUG: pid 19141:
reap_handler called
Jun 15 16:46:57 clever pgpool: 2006-06-15 16:46:57 DEBUG: pid 19141:
child 19153 exits with status 256 by signal 0
Jun 15 16:46:57 clever pgpool: 2006-06-15 16:46:57 DEBUG: pid 19146:
Protocol Major: 3 Minor: 0 database: SmartMaz user: abit
Jun 15 16:46:57 clever pgpool: 2006-06-15 16:46:57 DEBUG: pid 28879: I
am 28879
Jun 15 16:46:57 clever pgpool: 2006-06-15 16:46:57 DEBUG: pid 19141:
fork a new child pid 28879
Jun 15 16:46:57 clever pgpool: 2006-06-15 16:46:57 DEBUG: pid 19141:
failover_handler called
Jun 15 16:46:57 clever pgpool: 2006-06-15 16:46:57 LOG:   pid 19141:
starting degeneration. shutdown master host clever(5432)
Jun 15 16:46:57 clever pgpool: 2006-06-15 16:46:57 DEBUG: pid 19146:
child receives shutdown request signal 3
Jun 15 16:46:57 clever pgpool: 2006-06-15 16:46:57 DEBUG: pid 19141:
kill 19146
Jun 15 16:46:57 clever pgpool: 2006-06-15 16:46:57 DEBUG: pid 19147:
child receives shutdown request signal 3
Jun 15 16:46:57 clever pgpool: 2006-06-15 16:46:57 DEBUG: pid 19148: I
am 19148 accept fd 6
Jun 15 16:46:57 clever pgpool: 2006-06-15 16:46:57 DEBUG: pid 19148:
Protocol Major: 1234 Minor: 5679 database:  user:
Jun 15 16:46:57 clever pgpool: 2006-06-15 16:46:57 DEBUG: pid 19148:
SSLRequest: sent N; retry startup
Jun 15 16:46:57 clever pgpool: 2006-06-15 16:46:57 DEBUG: pid 19141:
kill 19147
Jun 15 16:46:57 clever pgpool: 2006-06-15 16:46:57 DEBUG: pid 19148:
child receives shutdown request signal 3
Jun 15 16:46:57 clever pgpool: 2006-06-15 16:46:57 DEBUG: pid 19141:
kill 19148
Jun 15 16:46:57 clever pgpool: 2006-06-15 16:46:57 DEBUG: pid 19149:
child receives shutdown request signal 3
Jun 15 16:46:57 clever pgpool: 2006-06-15 16:46:57 DEBUG: pid 19141:
kill 19149
Jun 15 16:46:57 clever pgpool: 2006-06-15 16:46:57 DEBUG: pid 19141:
kill 19150
Jun 15 16:46:57 clever pgpool: 2006-06-15 16:46:57 DEBUG: pid 19141:
kill 19151
Jun 15 16:46:57 clever pgpool: 2006-06-15 16:46:57 DEBUG: pid 19141:
kill 19152
Jun 15 16:46:57 clever pgpool: 2006-06-15 16:46:57 DEBUG: pid 19141:
kill 28879
Jun 15 16:46:57 clever pgpool: 2006-06-15 16:46:57 DEBUG: pid 19150:
child receives shutdown request signal 3
Jun 15 16:46:57 clever pgpool: 2006-06-15 16:46:57 DEBUG: pid 19151:
child receives shutdown request signal 3
Jun 15 16:46:57 clever pgpool: 2006-06-15 16:46:57 DEBUG: pid 19152:
child receives shutdown request signal 3
Jun 15 16:46:57 clever pgpool: 2006-06-15 16:46:57 DEBUG: pid 28879:
child receives shutdown request signal 3
Jun 15 16:46:57 clever pgpool: 2006-06-15 16:46:57 DEBUG: pid 28880: I
am 28880
Jun 15 16:46:57 clever pgpool: 2006-06-15 16:46:57 DEBUG: pid 28880: I
am 28880 accept fd 6
Jun 15 16:46:57 clever pgpool: 2006-06-15 16:46:57 DEBUG: pid 28880:
Protocol Major: 1234 Minor: 5679 database:  user:
Jun 15 16:46:57 clever pgpool: 2006-06-15 16:46:57 DEBUG: pid 28880:
SSLRequest: sent N; retry startup
Jun 15 16:46:57 clever pgpool: 2006-06-15 16:46:57 DEBUG: pid 28881: I
am 28881
Jun 15 16:46:57 clever pgpool: 2006-06-15 16:46:57 DEBUG: pid 28882: I
am 28882
Jun 15 16:46:57 clever pgpool: 2006-06-15 16:46:57 DEBUG: pid 28880:
Protocol Major: 3 Minor: 0 database: SmartMaz user: abit
Jun 15 16:46:57 clever pgpool: 2006-06-15 16:46:57 DEBUG: pid 28883: I
am 28883
Jun 15 16:46:57 clever pgpool: 2006-06-15 16:46:57 DEBUG: pid 28884: I
am 28884
Jun 15 16:46:57 clever pgpool: 2006-06-15 16:46:57 DEBUG: pid 28885: I
am 28885
Jun 15 16:46:57 clever pgpool: 2006-06-15 16:46:57 DEBUG: pid 28886: I
am 28886
Jun 15 16:46:57 clever pgpool: 2006-06-15 16:46:57 DEBUG: pid 28887: I
am 28887
Jun 15 16:46:57 clever pgpool: 2006-06-15 16:46:57 LOG:   pid 19141:
degeneration done. shutdown master host clever(5432)
Jun 15 16:46:57 clever pgpool: 2006-06-15 16:46:57 DEBUG: pid 19141:
reap_handler called
Jun 15 16:46:57 clever pgpool: 2006-06-15 16:46:57 DEBUG: pid 28880:
pool_read_message_length: lenghth: 8
Jun 15 16:46:57 clever pgpool: 2006-06-15 16:46:57 DEBUG: pid 28880:
trying clear text password authentication
Jun 15 16:46:57 clever pgpool: 2006-06-15 16:46:57 DEBUG: pid 28880:
pool_read_message_length2: master lenghth: 28
Jun 15 16:46:57 clever pgpool: 2006-06-15 16:46:57 DEBUG: pid 28880:
name: client_encoding value: UNICODE
Jun 15 16:46:57 clever pgpool: 2006-06-15 16:46:57 DEBUG: pid 28880:
pool_read_message_length2: master lenghth: 26
Jun 15 16:46:57 clever pgpool: 2006-06-15 16:46:57 DEBUG: pid 28880:
name: DateStyle value: German, DMY
Jun 15 16:46:57 clever pgpool: 2006-06-15 16:46:57 DEBUG: pid 28880:
pool_read_message_length2: master lenghth: 26
Jun 15 16:46:57 clever pgpool: 2006-06-15 16:46:57 DEBUG: pid 28880:
name: integer_datetimes value: off
Jun 15 16:46:57 clever pgpool: 2006-06-15 16:46:57 DEBUG: pid 28880:
pool_read_message_length2: master lenghth: 21
Jun 15 16:46:57 clever pgpool: 2006-06-15 16:46:57 DEBUG: pid 28880:
name: is_superuser value: off
Jun 15 16:46:57 clever pgpool: 2006-06-15 16:46:57 DEBUG: pid 28880:
pool_read_message_length2: master lenghth: 28
Jun 15 16:46:57 clever pgpool: 2006-06-15 16:46:57 DEBUG: pid 28880:
name: server_encoding value: UNICODE
Jun 15 16:46:57 clever pgpool: 2006-06-15 16:46:57 DEBUG: pid 28880:
pool_read_message_length2: master lenghth: 25
Jun 15 16:46:57 clever pgpool: 2006-06-15 16:46:57 DEBUG: pid 28880:
name: server_version value: 8.0.4
Jun 15 16:46:57 clever pgpool: 2006-06-15 16:46:57 DEBUG: pid 28880:
pool_read_message_length2: master lenghth: 31
Jun 15 16:46:57 clever pgpool: 2006-06-15 16:46:57 DEBUG: pid 28880:
name: session_authorization value: abit

Jun 15 16:46:57 clever pgpool: 2006-06-15 16:46:57 DEBUG: pid 28880:
pool_read_message_length2: master lenghth: 17
Jun 15 16:46:57 clever pgpool: 2006-06-15 16:46:57 DEBUG: pid 28880:
name: TimeZone value: UTC
Jun 15 16:46:57 clever pgpool: 2006-06-15 16:46:57 DEBUG: pid 28880:
pool_read_message_length: lenghth: 12
Jun 15 16:46:57 clever pgpool: 2006-06-15 16:46:57 DEBUG: pid 28880:
read kind from backend pending data Z len: 5 po: 232
Jun 15 16:46:57 clever pgpool: 2006-06-15 16:46:57 DEBUG: pid 28880:
pool_process_query: kind from backend: Z
Jun 15 16:46:57 clever pgpool: 2006-06-15 16:46:57 DEBUG: pid 28880:
pool_read_message_length: lenghth: 5
Jun 15 16:46:57 clever pgpool: 2006-06-15 16:46:57 DEBUG: pid 28880:
ReadyForQuery: message length: 5
Jun 15 16:46:57 clever pgpool: 2006-06-15 16:46:57 DEBUG: pid 28880:
ReadyForQuery: transaction state: I
Jun 15 16:46:57 clever pgpool: 2006-06-15 16:46:57 DEBUG: pid 28880:
read kind from frontend Q(51)
Jun 15 16:46:57 clever pgpool: 2006-06-15 16:46:57 DEBUG: pid 28880:
Query: SELECT (SELECT name FROM dve WHERE type='start' AND se.dve_star
t=dve_id) AS start, (SELECT name FROM dve WHERE type='term' AND
se.dve_term=dve_id) AS term, duration, tmpl FROM se WHERE
se_id='TESTPR9W'
Jun 15 16:46:57 clever pgpool: 2006-06-15 16:46:57 DEBUG: pid 28880:
read kind from backend T

-------------- next part --------------
An HTML attachment was scrubbed...
URL: http://pgfoundry.org/pipermail/pgpool-general/attachments/20060619/7bdb85ac/attachment-0001.html