[pgpool-general: 2359] Re: Problems with recovered master node.

Mario Adrián López Alemán mario.lopez at gazzang.com
Sat Dec 21 09:13:54 JST 2013


Hi.
Here are the logs:
In this log we have
node 0 master
node 1 slave
node 2 slave

Here we can see that the rollback is only sent to the node 0, that is
the actual master.

2013-12-20 19:09:33 LOG:   pid 10454: pgpool-II successfully started.
version 3.3.2 (tokakiboshi)
2013-12-20 19:09:33 LOG:   pid 10454: find_primary_node: primary node id
is 0
2013-12-20 19:09:48 LOG:   pid 10487: statement: SET DATESTYLE TO 'ISO'
2013-12-20 19:09:48 LOG:   pid 10487: DB node id: 0 backend pid: 11392
statement: BEGIN
2013-12-20 19:09:48 LOG:   pid 10487: DB node id: 1 backend pid: 8744
statement: BEGIN
2013-12-20 19:09:48 LOG:   pid 10487: DB node id: 2 backend pid: 2708
statement: BEGIN
2013-12-20 19:09:48 LOG:   pid 10487: DB node id: 0 backend pid: 11392
statement: SET DATESTYLE TO 'ISO'
2013-12-20 19:09:48 LOG:   pid 10487: DB node id: 1 backend pid: 8744
statement: SET DATESTYLE TO 'ISO'
2013-12-20 19:09:48 LOG:   pid 10487: DB node id: 2 backend pid: 2708
statement: SET DATESTYLE TO 'ISO'
2013-12-20 19:09:48 LOG:   pid 10487: DB node id: 1 backend pid: 8744
statement: COMMIT
2013-12-20 19:09:48 LOG:   pid 10487: DB node id: 2 backend pid: 2708
statement: COMMIT
2013-12-20 19:09:48 LOG:   pid 10487: DB node id: 0 backend pid: 11392
statement: COMMIT
2013-12-20 19:09:48 LOG:   pid 10487: statement: SHOW client_encoding
2013-12-20 19:09:48 LOG:   pid 10487: DB node id: 0 backend pid: 11392
statement: SHOW client_encoding
2013-12-20 19:09:48 LOG:   pid 10487: statement: SHOW
default_transaction_isolation
2013-12-20 19:09:48 LOG:   pid 10487: DB node id: 0 backend pid: 11392
statement: SHOW default_transaction_isolation
2013-12-20 19:09:48 LOG:   pid 10487: statement: BEGIN; SET TRANSACTION
ISOLATION LEVEL READ COMMITTED
2013-12-20 19:09:48 LOG:   pid 10487: DB node id: 0 backend pid: 11392
statement: BEGIN; SET TRANSACTION ISOLATION LEVEL READ COMMITTED
2013-12-20 19:09:48 LOG:   pid 10487: statement: select version()
2013-12-20 19:09:48 LOG:   pid 10487: DB node id: 0 backend pid: 11392
statement: select version()
2013-12-20 19:09:48 LOG:   pid 10487: statement: select current_schema()
2013-12-20 19:09:48 LOG:   pid 10487: DB node id: 0 backend pid: 11392
statement: select current_schema()
2013-12-20 19:09:48 LOG:   pid 10487: statement: show transaction
isolation level
2013-12-20 19:09:48 LOG:   pid 10487: DB node id: 0 backend pid: 11392
statement: show transaction isolation level
2013-12-20 19:09:48 LOG:   pid 10487: statement: SELECT CAST('test plain
returns' AS VARCHAR(60)) AS anon_1
2013-12-20 19:09:48 LOG:   pid 10487: DB node id: 0 backend pid: 11392
statement: SELECT CAST('test plain returns' AS VARCHAR(60)) AS anon_1
2013-12-20 19:09:48 LOG:   pid 10487: statement: SELECT CAST('test
unicode returns' AS VARCHAR(60)) AS anon_1
2013-12-20 19:09:48 LOG:   pid 10487: DB node id: 0 backend pid: 11392
statement: SELECT CAST('test unicode returns' AS VARCHAR(60)) AS anon_1
2013-12-20 19:09:48 LOG:   pid 10487: statement: ROLLBACK
2013-12-20 19:09:48 LOG:   pid 10487: DB node id: 0 backend pid: 11392
statement: ROLLBACK
2013-12-20 19:09:48 LOG:   pid 10487: statement: BEGIN; SET TRANSACTION
ISOLATION LEVEL READ COMMITTED
2013-12-20 19:09:48 LOG:   pid 10487: DB node id: 0 backend pid: 11392
statement: BEGIN; SET TRANSACTION ISOLATION LEVEL READ COMMITTED
2013-12-20 19:09:48 LOG:   pid 10487: statement: INSERT INTO transaction
(uuid, creation, server_version, server_fingerprint, client_agent,
client_ip, query) VALUES ('hTq0do5BElHrojk2tXm4vFCUo32MNbkB6lqTDVDSvs0',
'2013-12-21T00:10:00.731241+00:00', '3.5~rc2',
'4096R/BC8C3F28CCC1EEEF64429563F1FCF92CCE34DD2C',
'/usr/lib/application-server/orgtool', 'localhost', 'list')
2013-12-20 19:09:48 LOG:   pid 10487: DB node id: 0 backend pid: 11392
statement: INSERT INTO transaction (uuid, creation, server_version,
server_fingerprint, client_agent, client_ip, query) VALUES
('hTq0do5BElHrojk2tXm4vFCUo32MNbkB6lqTDVDSvs0',
'2013-12-21T00:10:00.731241+00:00', '3.5~rc2',
'4096R/BC8C3F28CCC1EEEF64429563F1FCF92CCE34DD2C',
'/usr/lib/application-server/orgtool', 'localhost', 'list')
2013-12-20 19:09:48 LOG:   pid 10487: statement: COMMIT
2013-12-20 19:09:48 LOG:   pid 10487: DB node id: 0 backend pid: 11392
statement: COMMIT
2013-12-20 19:09:48 LOG:   pid 10487: statement: BEGIN; SET TRANSACTION
ISOLATION LEVEL READ COMMITTED
2013-12-20 19:09:48 LOG:   pid 10487: DB node id: 0 backend pid: 11392
statement: BEGIN; SET TRANSACTION ISOLATION LEVEL READ COMMITTED
2013-12-20 19:09:48 LOG:   pid 10487: statement: SELECT org.uuid,
org.creation, org.expiration, org.state, org.name
FROM org
2013-12-20 19:09:48 LOG:   pid 10487: DB node id: 0 backend pid: 11392
statement: SELECT count(*) from (SELECT
has_function_privilege('application', 'pgpool_regclass(cstring)',
'execute') WHERE EXISTS(SELECT * FROM pg_catalog.pg_proc AS p WHERE
p.proname = 'pgpool_regclass')) AS s
2013-12-20 19:09:48 LOG:   pid 10487: DB node id: 0 backend pid: 11392
statement: SELECT count(*) FROM pg_class AS c, pg_namespace AS n WHERE
c.relname = 'pg_namespace' AND c.relnamespace = n.oid AND n.nspname =
'pg_catalog'
2013-12-20 19:09:48 LOG:   pid 10487: DB node id: 0 backend pid: 11392
statement: SELECT count(*) FROM pg_class AS c, pg_namespace AS n WHERE
c.relname = 'org' AND c.relnamespace = n.oid AND n.nspname = 'pg_catalog'
2013-12-20 19:09:48 LOG:   pid 10487: DB node id: 0 backend pid: 11392
statement: SELECT count(*) FROM pg_catalog.pg_class AS c, pg_attribute
AS a WHERE c.relname = 'pg_class' AND a.attrelid = c.oid AND a.attname =
'relistemp'
2013-12-20 19:09:48 LOG:   pid 10487: DB node id: 0 backend pid: 11392
statement: SELECT count(*) FROM pg_class AS c, pg_namespace AS n WHERE
c.relname = 'org' AND c.relnamespace = n.oid AND n.nspname ~ '^pg_temp_'
2013-12-20 19:09:48 LOG:   pid 10487: DB node id: 0 backend pid: 11392
statement: SELECT count(*) FROM pg_catalog.pg_class AS c,
pg_catalog.pg_attribute AS a WHERE c.relname = 'pg_class' AND a.attrelid
= c.oid AND a.attname = 'relpersistence'
2013-12-20 19:09:48 LOG:   pid 10487: DB node id: 0 backend pid: 11392
statement: SELECT count(*) FROM pg_catalog.pg_class AS c WHERE c.relname
= 'org' AND c.relpersistence = 'u'
2013-12-20 19:09:48 LOG:   pid 10487: DB node id: 0 backend pid: 11392
statement: SELECT org.uuid, org.creation, org.expiration, org.state,
org.name
FROM org
2013-12-20 19:09:48 LOG:   pid 10487: statement: ROLLBACK
2013-12-20 19:09:48 LOG:   pid 10487: DB node id: 0 backend pid: 11392
statement: ROLLBACK
2013-12-20 19:09:48 LOG:   pid 10487: statement: BEGIN; SET TRANSACTION
ISOLATION LEVEL READ COMMITTED
2013-12-20 19:09:48 LOG:   pid 10487: DB node id: 0 backend pid: 11392
statement: BEGIN; SET TRANSACTION ISOLATION LEVEL READ COMMITTED
2013-12-20 19:09:48 LOG:   pid 10487: statement: SELECT org_auth.uuid,
org_auth.creation, org_auth.expiration, org_auth.state,
org_auth.org_uuid, org_auth.auth_secret
FROM org_auth
WHERE org_auth.org_uuid = 'ypjrtlcE1I2XpTMhWpEhroUOxdOMwxiDqXqJAyg4qpK'
AND org_auth.state = 0 AND org_auth.creation <=
'2013-12-21T00:10:00.763479+00:00' AND org_auth.expiration >
'2013-12-21T00:10:00.763571+00:00' ORDER BY org_auth.creation DESC
2013-12-20 19:09:48 LOG:   pid 10487: DB node id: 0 backend pid: 11392
statement: SELECT count(*) FROM pg_class AS c, pg_namespace AS n WHERE
c.relname = 'org_auth' AND c.relnamespace = n.oid AND n.nspname =
'pg_catalog'
2013-12-20 19:09:48 LOG:   pid 10487: DB node id: 0 backend pid: 11392
statement: SELECT count(*) FROM pg_class AS c, pg_namespace AS n WHERE
c.relname = 'org_auth' AND c.relnamespace = n.oid AND n.nspname ~
'^pg_temp_'
2013-12-20 19:09:48 LOG:   pid 10487: DB node id: 0 backend pid: 11392
statement: SELECT count(*) FROM pg_catalog.pg_class AS c WHERE c.relname
= 'org_auth' AND c.relpersistence = 'u'
2013-12-20 19:09:48 LOG:   pid 10487: DB node id: 0 backend pid: 11392
statement: SELECT org_auth.uuid, org_auth.creation, org_auth.expiration,
org_auth.state, org_auth.org_uuid, org_auth.auth_secret
FROM org_auth
WHERE org_auth.org_uuid = 'ypjrtlcE1I2XpTMhWpEhroUOxdOMwxiDqXqJAyg4qpK'
AND org_auth.state = 0 AND org_auth.creation <=
'2013-12-21T00:10:00.763479+00:00' AND org_auth.expiration >
'2013-12-21T00:10:00.763571+00:00' ORDER BY org_auth.creation DESC
2013-12-20 19:09:48 LOG:   pid 10487: statement: ROLLBACK
2013-12-20 19:09:48 LOG:   pid 10487: DB node id: 0 backend pid: 11392
statement: ROLLBACK
2013-12-20 19:09:48 LOG:   pid 10487: statement: BEGIN; SET TRANSACTION
ISOLATION LEVEL READ COMMITTED
2013-12-20 19:09:48 LOG:   pid 10487: DB node id: 0 backend pid: 11392
statement: BEGIN; SET TRANSACTION ISOLATION LEVEL READ COMMITTED
2013-12-20 19:09:48 LOG:   pid 10487: statement: SELECT org.uuid AS
org_uuid, org.creation AS org_creation, org.expiration AS
org_expiration, org.state AS org_state, org.name AS org_name,
contact.uuid AS contact_uuid, contact.creation AS contact_creation,
contact.expiration AS contact_expiration, contact.state AS
contact_state, contact.fingerprint AS contact_fingerprint, contact.class
AS contact_class, contact.contact AS contact_contact,
org_to_contact.uuid AS org_to_contact_uuid, org_to_contact.creation AS
org_to_contact_creation, org_to_contact.expiration AS
org_to_contact_expiration, org_to_contact.state AS org_to_contact_state,
org_to_contact.org_uuid AS org_to_contact_org_uuid,
org_to_contact.contact_uuid AS org_to_contact_contact_uuid
FROM org, contact, org_to_contact
WHERE org.uuid = org_to_contact.org_uuid AND contact.uuid =
org_to_contact.contact_uuid AND org.uuid =
'ypjrtlcE1I2XpTMhWpEhroUOxdOMwxiDqXqJAyg4qpK'
2013-12-20 19:09:48 LOG:   pid 10487: DB node id: 0 backend pid: 11392
statement: SELECT count(*) FROM pg_class AS c, pg_namespace AS n WHERE
c.relname = 'contact' AND c.relnamespace = n.oid AND n.nspname =
'pg_catalog'
2013-12-20 19:09:48 LOG:   pid 10487: DB node id: 0 backend pid: 11392
statement: SELECT count(*) FROM pg_class AS c, pg_namespace AS n WHERE
c.relname = 'org_to_contact' AND c.relnamespace = n.oid AND n.nspname =
'pg_catalog'
2013-12-20 19:09:48 LOG:   pid 10487: DB node id: 0 backend pid: 11392
statement: SELECT count(*) FROM pg_class AS c, pg_namespace AS n WHERE
c.relname = 'contact' AND c.relnamespace = n.oid AND n.nspname ~ '^pg_temp_'
2013-12-20 19:09:48 LOG:   pid 10487: DB node id: 0 backend pid: 11392
statement: SELECT count(*) FROM pg_class AS c, pg_namespace AS n WHERE
c.relname = 'org_to_contact' AND c.relnamespace = n.oid AND n.nspname ~
'^pg_temp_'
2013-12-20 19:09:48 LOG:   pid 10487: DB node id: 0 backend pid: 11392
statement: SELECT count(*) FROM pg_catalog.pg_class AS c WHERE c.relname
= 'contact' AND c.relpersistence = 'u'
2013-12-20 19:09:48 LOG:   pid 10487: DB node id: 0 backend pid: 11392
statement: SELECT count(*) FROM pg_catalog.pg_class AS c WHERE c.relname
= 'org_to_contact' AND c.relpersistence = 'u'
2013-12-20 19:09:48 LOG:   pid 10487: DB node id: 0 backend pid: 11392
statement: SELECT org.uuid AS org_uuid, org.creation AS org_creation,
org.expiration AS org_expiration, org.state AS org_state, org.name AS
org_name, contact.uuid AS contact_uuid, contact.creation AS
contact_creation, contact.expiration AS contact_expiration,
contact.state AS contact_state, contact.fingerprint AS
contact_fingerprint, contact.class AS contact_class, contact.contact AS
contact_contact, org_to_contact.uuid AS org_to_contact_uuid,
org_to_contact.creation AS org_to_contact_creation,
org_to_contact.expiration AS org_to_contact_expiration,
org_to_contact.state AS org_to_contact_state, org_to_contact.org_uuid AS
org_to_contact_org_uuid, org_to_contact.contact_uuid AS
org_to_contact_contact_uuid
FROM org, contact, org_to_contact
WHERE org.uuid = org_to_contact.org_uuid AND contact.uuid =
org_to_contact.contact_uuid AND org.uuid =
'ypjrtlcE1I2XpTMhWpEhroUOxdOMwxiDqXqJAyg4qpK'
2013-12-20 19:09:49 LOG:   pid 10487: statement: ROLLBACK
2013-12-20 19:09:49 LOG:   pid 10487: DB node id: 0 backend pid: 11392
statement: ROLLBACK
2013-12-20 19:09:49 LOG:   pid 10487: statement: BEGIN; SET TRANSACTION
ISOLATION LEVEL READ COMMITTED
2013-12-20 19:09:49 LOG:   pid 10487: DB node id: 0 backend pid: 11392
statement: BEGIN; SET TRANSACTION ISOLATION LEVEL READ COMMITTED
2013-12-20 19:09:49 LOG:   pid 10487: statement: UPDATE transaction SET
expiration='2013-12-21T00:10:00.785848+00:00', state=0 WHERE
transaction.uuid = 'hTq0do5BElHrojk2tXm4vFCUo32MNbkB6lqTDVDSvs0'
2013-12-20 19:09:49 LOG:   pid 10487: DB node id: 0 backend pid: 11392
statement: UPDATE transaction SET
expiration='2013-12-21T00:10:00.785848+00:00', state=0 WHERE
transaction.uuid = 'hTq0do5BElHrojk2tXm4vFCUo32MNbkB6lqTDVDSvs0'
2013-12-20 19:09:49 LOG:   pid 10487: statement: COMMIT
2013-12-20 19:09:49 LOG:   pid 10487: DB node id: 0 backend pid: 11392
statement: COMMIT
2013-12-20 19:09:49 LOG:   pid 10487: statement:  DISCARD ALL
2013-12-20 19:09:49 LOG:   pid 10487: DB node id: 0 backend pid: 11392
statement:  DISCARD ALL
2013-12-20 19:09:49 LOG:   pid 10487: DB node id: 1 backend pid: 8744
statement:  DISCARD ALL
2013-12-20 19:09:49 LOG:   pid 10487: DB node id: 2 backend pid: 2708
statement:  DISCARD ALL


Regards!
On 20/12/13 17:20, Tatsuo Ishii wrote:
> Does it? It's not what I expected. Can you please show the pgpool log?
>
> Best regards,
> --
> Tatsuo Ishii
> SRA OSS, Inc. Japan
> English: http://www.sraoss.co.jp/index_en.php
> Japanese: http://www.sraoss.co.jp
>
>> But then, why  it works when master node is node 0?
>>
>> On 20/12/13 01:01, Tatsuo Ishii wrote:
>>> I see now the source of the problem:
>>>
>>>> 2013-12-19 20:35:16 LOG:   pid 4328: statement: BEGIN; SET TRANSACTION
>>>> ISOLATION LEVEL READ COMMITTED
>>> pgpool-II cannot handle "multi statement queries" (multiple SQL
>>> statement in single line like this). If pgpool-II finds such a query,
>>> it sends to the primary node (in your case node 1) regardless the
>>> contents of the query. So it sends "BEGIN" to node 1, while it does
>>> not send to node 0. Later on "ROLLBACK" is sent to both node 0 and
>>> 1. Of course there's no explicit transaction is running on node 0, it
>>> fails.
>>>
>>> If such a query is generated by the flame work, There's not much
>>> which pgpool-II can do...
>>>
>>> Best regards,
>>> --
>>> Tatsuo Ishii
>>> SRA OSS, Inc. Japan
>>> English: http://www.sraoss.co.jp/index_en.php
>>> Japanese: http://www.sraoss.co.jp
>>>
>>>> I actually don't know too  much about the internals of the application.
>>>> And the problem is when the application is trying to start a connection.
>>>> (The RollBack are probably internals of sqlalchemy, I really don't know)
>>>> The only thing I know is that they are using sqlalchemy and flask.
>>>>
>>>> Here is the pgppol log about the error:
>>>> 2013-12-19 20:32:29 LOG:   pid 31014: received smart shutdown request
>>>> 2013-12-19 20:32:30 LOG:   pid 4295: pgpool-II successfully started.
>>>> version 3.3.2 (tokakiboshi)
>>>> 2013-12-19 20:32:30 LOG:   pid 4295: find_primary_node: primary node id is 1
>>>> 2013-12-19 20:35:16 LOG:   pid 4328: statement: SET DATESTYLE TO 'ISO'
>>>> 2013-12-19 20:35:16 LOG:   pid 4328: DB node id: 0 backend pid: 5382
>>>> statement: BEGIN
>>>> 2013-12-19 20:35:16 LOG:   pid 4328: DB node id: 1 backend pid: 9744
>>>> statement: BEGIN
>>>> 2013-12-19 20:35:16 LOG:   pid 4328: DB node id: 2 backend pid: 16458
>>>> statement: BEGIN
>>>> 2013-12-19 20:35:16 LOG:   pid 4328: DB node id: 0 backend pid: 5382
>>>> statement: SET DATESTYLE TO 'ISO'
>>>> 2013-12-19 20:35:16 LOG:   pid 4328: DB node id: 1 backend pid: 9744
>>>> statement: SET DATESTYLE TO 'ISO'
>>>> 2013-12-19 20:35:16 LOG:   pid 4328: DB node id: 2 backend pid: 16458
>>>> statement: SET DATESTYLE TO 'ISO'
>>>> 2013-12-19 20:35:16 LOG:   pid 4328: DB node id: 1 backend pid: 9744
>>>> statement: COMMIT
>>>> 2013-12-19 20:35:16 LOG:   pid 4328: DB node id: 2 backend pid: 16458
>>>> statement: COMMIT
>>>> 2013-12-19 20:35:16 LOG:   pid 4328: DB node id: 0 backend pid: 5382
>>>> statement: COMMIT
>>>> 2013-12-19 20:35:16 LOG:   pid 4328: statement: SHOW client_encoding
>>>> 2013-12-19 20:35:16 LOG:   pid 4328: DB node id: 1 backend pid: 9744
>>>> statement: SHOW client_encoding
>>>> 2013-12-19 20:35:16 LOG:   pid 4328: statement: SHOW
>>>> default_transaction_isolation
>>>> 2013-12-19 20:35:16 LOG:   pid 4328: DB node id: 1 backend pid: 9744
>>>> statement: SHOW default_transaction_isolation
>>>> 2013-12-19 20:35:16 LOG:   pid 4328: statement: BEGIN; SET TRANSACTION
>>>> ISOLATION LEVEL READ COMMITTED
>>>> 2013-12-19 20:35:16 LOG:   pid 4328: DB node id: 1 backend pid: 9744
>>>> statement: BEGIN; SET TRANSACTION ISOLATION LEVEL READ COMMITTED
>>>> 2013-12-19 20:35:16 LOG:   pid 4328: statement: select version()
>>>> 2013-12-19 20:35:16 LOG:   pid 4328: DB node id: 1 backend pid: 9744
>>>> statement: select version()
>>>> 2013-12-19 20:35:16 LOG:   pid 4328: statement: select current_schema()
>>>> 2013-12-19 20:35:16 LOG:   pid 4328: DB node id: 1 backend pid: 9744
>>>> statement: select current_schema()
>>>> 2013-12-19 20:35:16 LOG:   pid 4328: statement: show transaction
>>>> isolation level
>>>> 2013-12-19 20:35:16 LOG:   pid 4328: DB node id: 1 backend pid: 9744
>>>> statement: show transaction isolation level
>>>> 2013-12-19 20:35:16 LOG:   pid 4328: statement: SELECT CAST('test plain
>>>> returns' AS VARCHAR(60)) AS anon_1
>>>> 2013-12-19 20:35:16 LOG:   pid 4328: DB node id: 1 backend pid: 9744
>>>> statement: SELECT CAST('test plain returns' AS VARCHAR(60)) AS anon_1
>>>> 2013-12-19 20:35:16 LOG:   pid 4328: statement: SELECT CAST('test
>>>> unicode returns' AS VARCHAR(60)) AS anon_1
>>>> 2013-12-19 20:35:16 LOG:   pid 4328: DB node id: 1 backend pid: 9744
>>>> statement: SELECT CAST('test unicode returns' AS VARCHAR(60)) AS anon_1
>>>> 2013-12-19 20:35:16 LOG:   pid 4328: statement: ROLLBACK
>>>> 2013-12-19 20:35:16 LOG:   pid 4328: DB node id: 1 backend pid: 9744
>>>> statement: ROLLBACK
>>>> 2013-12-19 20:35:16 LOG:   pid 4328: DB node id: 0 backend pid: 5382
>>>> statement: ROLLBACK
>>>> 2013-12-19 20:35:16 LOG:   pid 4328: pool_send_and_wait: Error or notice
>>>> message from backend: : DB node id: 0 backend pid: 5382 statement:
>>>> ROLLBACK message: there is no transaction in progress
>>>> 2013-12-19 20:35:16 ERROR: pid 4328: read_kind_from_backend: 1 th kind C
>>>> does not match with master or majority connection kind N
>>>> 2013-12-19 20:35:16 ERROR: pid 4328: kind mismatch among backends.
>>>> Possible last query was: "ROLLBACK" kind details are: 0[N: there is no
>>>> transaction in progress] 1[C]
>>>> 2013-12-19 20:35:16 LOG:   pid 4328: do_child: exits with status 1 due
>>>> to error
>>>>
>>>> And here is the stack trace:
>>>> 2013-12-19 20:35:25,080 - application.flaskapp - ERROR - kind mismatch
>>>> among backends. Possible last query was: "ROLLBACK" kind details are:
>>>> 0[N: there is no transaction in progress] 1[C]
>>>> HINT:  check data consistency among db nodes
>>>> ERROR:  kind mismatch among backends. Possible last query was:
>>>> "ROLLBACK" kind details are: 0[N: there is no transaction in progress] 1[C]
>>>> HINT:  check data consistency among db nodes
>>>> Traceback (most recent call last):
>>>>   File
>>>> "/usr/lib/python2.6/site-packages/application/server/flaskapp.py", line
>>>> 34, in __init__
>>>>     self._init_db()
>>>>   File "/usr/lib/python2.6/site-packages/application/server/orgtool.py",
>>>> line 47, in _init_db
>>>>     self.db = ApplicationMutableDb(self.config)
>>>>   File "/usr/lib/python2.6/site-packages/application/server/db.py", line
>>>> 1014, in __init__
>>>>     ApplicationAppendDb.__init__(self, *args, **kwargs)
>>>>   File "/usr/lib/python2.6/site-packages/application/server/db.py", line
>>>> 937, in __init__
>>>>     ApplicationQueryDb.__init__(self, *args, **kwargs)
>>>>   File "/usr/lib/python2.6/site-packages/application/server/db.py", line
>>>> 234, in __init__
>>>>     BaseDb.__init__(self, *args, **kwargs)
>>>>   File "/usr/lib/python2.6/site-packages/application/server/db.py", line
>>>> 192, in __init__
>>>>     self.db_conn()
>>>>   File "/usr/lib/python2.6/site-packages/application/server/db.py", line
>>>> 216, in db_conn
>>>>     self.conn = self.engine.connect()
>>>>   File "/usr/lib/python2.6/site-packages/sqlalchemy/engine/base.py",
>>>> line 2322, in connect
>>>>     return self._connection_cls(self, **kwargs)
>>>>   File "/usr/lib/python2.6/site-packages/sqlalchemy/engine/base.py",
>>>> line 872, in __init__
>>>>     self.__connection = connection or engine.raw_connection()
>>>>   File "/usr/lib/python2.6/site-packages/sqlalchemy/engine/base.py",
>>>> line 2408, in raw_connection
>>>>     return self.pool.unique_connection()
>>>>   File "/usr/lib/python2.6/site-packages/sqlalchemy/pool.py", line 169,
>>>> in unique_connection
>>>>     return _ConnectionFairy(self).checkout()
>>>>   File "/usr/lib/python2.6/site-packages/sqlalchemy/pool.py", line 371,
>>>> in __init__
>>>>     rec = self._connection_record = pool._do_get()
>>>>   File "/usr/lib/python2.6/site-packages/sqlalchemy/pool.py", line 758,
>>>> in _do_get
>>>>     return self._create_connection()
>>>>   File "/usr/lib/python2.6/site-packages/sqlalchemy/pool.py", line 174,
>>>> in _create_connection
>>>>     return _ConnectionRecord(self)
>>>>   File "/usr/lib/python2.6/site-packages/sqlalchemy/pool.py", line 259,
>>>> in __init__
>>>>     pool.dispatch.first_connect.exec_once(self.connection, self)
>>>>   File "/usr/lib/python2.6/site-packages/sqlalchemy/event.py", line 265,
>>>> in exec_once
>>>>     self(*args, **kw)
>>>>   File "/usr/lib/python2.6/site-packages/sqlalchemy/event.py", line 274,
>>>> in __call__
>>>>     fn(*args, **kw)
>>>>   File
>>>> "/usr/lib/python2.6/site-packages/sqlalchemy/engine/strategies.py", line
>>>> 166, in first_connect
>>>>     dialect.initialize(c)
>>>>   File
>>>> "/usr/lib/python2.6/site-packages/sqlalchemy/dialects/postgresql/base.py",
>>>> line 977, in initialize
>>>>     super(PGDialect, self).initialize(connection)
>>>>   File "/usr/lib/python2.6/site-packages/sqlalchemy/engine/default.py",
>>>> line 187, in initialize
>>>>     self.do_rollback(connection.connection)
>>>>   File "/usr/lib/python2.6/site-packages/sqlalchemy/engine/default.py",
>>>> line 299, in do_rollback
>>>>     connection.rollback()
>>>> InternalError: kind mismatch among backends. Possible last query was:
>>>> "ROLLBACK" kind details are: 0[N: there is no transaction in progress] 1[C]
>>>> HINT:  check data consistency among db nodes
>>>> ERROR:  kind mismatch among backends. Possible last query was:
>>>> "ROLLBACK" kind details are: 0[N: there is no transaction in progress] 1[C]
>>>> HINT:  check data consistency among db nodes
>>>>
>>>> 2013-12-19 20:35:25,085 - application - ERROR - Action failed: 500:
>>>> Internal Server Error
>>>> Traceback (most recent call last):
>>>>   File "./orgtool", line 65, in main
>>>>     org = self._get_orgtool(options.confbase)
>>>>   File "./orgtool", line 19, in _get_orgtool
>>>>     org = orgtool.OrgTool(confbase)
>>>>   File "/usr/lib/python2.6/site-packages/application/server/orgtool.py",
>>>> line 41, in __init__
>>>>     BaseServer.__init__(self, environ, os.path.join(confbase,
>>>> ".application"))
>>>>   File
>>>> "/usr/lib/python2.6/site-packages/application/server/flaskapp.py", line
>>>> 37, in __init__
>>>>     raise wzex.InternalServerError("DATABASE CONNECTION FAILED")
>>>>
>>>> On 19/12/13 17:28, Tatsuo Ishii wrote:
>>>>>> Hi.
>>>>>>
>>>>>> It wasn't installed, but I installed it and had the same result.
>>>>> Can you show the PostgreSQL around "ROLLBACK"?
>>>>>
>>>>>> By the way, to install it I just need to execute this right?
>>>>>> CREATE EXTENSION pgpool_regclass;
>>>>> Yes.
>>>>>
>>>>> Best regards,
>>>>> --
>>>>> Tatsuo Ishii
>>>>> SRA OSS, Inc. Japan
>>>>> English: http://www.sraoss.co.jp/index_en.php
>>>>> Japanese: http://www.sraoss.co.jp
>>>>>
>>>>>> On 18/12/13 18:17, Tatsuo Ishii wrote:
>>>>>>> Have you installed pgpool_regclass?
>>>>>>>
>>>>>>> Best regards,
>>>>>>> --
>>>>>>> Tatsuo Ishii
>>>>>>> SRA OSS, Inc. Japan
>>>>>>> English: http://www.sraoss.co.jp/index_en.php
>>>>>>> Japanese: http://www.sraoss.co.jp
>>>>>>>
>>>>>>>> Hi everyone.
>>>>>>>>
>>>>>>>> I'm having an issue with pgpool.
>>>>>>>> First of all my configuration:
>>>>>>>> 1 Server with pgpool-II version 3.3.2 (tokakiboshi)
>>>>>>>> 3 Servers with:
>>>>>>>> postgresql93-contrib-9.3.2-1PGDG.rhel6.x86_64
>>>>>>>> postgresql93-devel-9.3.2-1PGDG.rhel6.x86_64
>>>>>>>> postgresql93-libs-9.3.2-1PGDG.rhel6.x86_64
>>>>>>>> postgresql93-9.3.2-1PGDG.rhel6.x86_64
>>>>>>>> postgresql93-server-9.3.2-1PGDG.rhel6.x86_64
>>>>>>>>
>>>>>>>> All 4 servers are RHEL 6 machines. (Amazon AMI's actually)
>>>>>>>>
>>>>>>>> Pgpool is configured to have Master/Slave Nodes with replication
>>>>>>>> and Load Balancing.
>>>>>>>>
>>>>>>>> #------------------------------------------------------------------------------
>>>>>>>> # LOAD BALANCING MODE
>>>>>>>> #------------------------------------------------------------------------------
>>>>>>>>
>>>>>>>> load_balance_mode = on
>>>>>>>>                                    # Activate load balancing mode
>>>>>>>>                                    # (change requires restart)
>>>>>>>> ignore_leading_white_space = on
>>>>>>>>                                    # Ignore leading white spaces of each
>>>>>>>> query
>>>>>>>> white_function_list = ''
>>>>>>>>                                    # Comma separated list of function names
>>>>>>>>                                    # that don't write to database
>>>>>>>>                                    # Regexp are accepted
>>>>>>>> black_function_list = 'nextval,setval'
>>>>>>>>                                    # Comma separated list of function names
>>>>>>>>                                    # that write to database
>>>>>>>>                                    # Regexp are accepted
>>>>>>>>
>>>>>>>>
>>>>>>>> #------------------------------------------------------------------------------
>>>>>>>> # MASTER/SLAVE MODE
>>>>>>>> #------------------------------------------------------------------------------
>>>>>>>>
>>>>>>>> master_slave_mode = on
>>>>>>>>                                    # Activate master/slave mode
>>>>>>>>                                    # (change requires restart)
>>>>>>>> master_slave_sub_mode = 'stream'
>>>>>>>>                                    # Master/slave sub mode
>>>>>>>>                                    # Valid values are combinations slony or
>>>>>>>>                                    # stream. Default is slony.
>>>>>>>>                                    # (change requires restart)
>>>>>>>>
>>>>>>>> # - Streaming -
>>>>>>>>
>>>>>>>> sr_check_period = 1
>>>>>>>>                                    # Streaming replication check period
>>>>>>>>                                    # Disabled (0) by default
>>>>>>>> sr_check_user = 'postgres'
>>>>>>>>                                    # Streaming replication check user
>>>>>>>>                                    # This is necessary even if you disable
>>>>>>>>                                    # streaming replication delay check with
>>>>>>>>                                    # sr_check_period = 0
>>>>>>>> sr_check_password = ''
>>>>>>>>                                    # Password for streaming replication
>>>>>>>> check user
>>>>>>>> delay_threshold = 1
>>>>>>>>                                    # Threshold before not dispatching
>>>>>>>> query to standby node
>>>>>>>>                                    # Unit is in bytes
>>>>>>>>                                    # Disabled (0) by default
>>>>>>>>
>>>>>>>> # - Special commands -
>>>>>>>>
>>>>>>>> follow_master_command = '/bin/follow_master.sh %d %h %D %m %H %R'
>>>>>>>>                                    # Executes this command after master
>>>>>>>> failover
>>>>>>>>                                    # Special values:
>>>>>>>>                                    #   %d = node id
>>>>>>>>                                    #   %h = host name
>>>>>>>>                                    #   %p = port number
>>>>>>>>                                    #   %D = database cluster path
>>>>>>>>                                    #   %m = new master node id
>>>>>>>>                                    #   %H = hostname of the new master node
>>>>>>>>                                    #   %M = old master node id
>>>>>>>>                                    #   %P = old primary node id
>>>>>>>>                                    #   %r = new master port number
>>>>>>>>                                    #   %R = new master database cluster path
>>>>>>>>                                    #   %% = '%' character
>>>>>>>>
>>>>>>>>
>>>>>>>> #All three nodes are configured like this
>>>>>>>> backend_hostnamen = 'ip_node_n'
>>>>>>>> backend_portn = 5432
>>>>>>>> backend_weightn = 0
>>>>>>>> backend_data_directoryn = '/var/lib/pgsql/9.3/data/'
>>>>>>>> backend_flagn = 'ALLOW_TO_FAILOVER'
>>>>>>>>
>>>>>>>> I'm using repmgr to handle the replication in the nodes.
>>>>>>>>
>>>>>>>>
>>>>>>>> My problem occurs when I kill the master node, everything works as
>>>>>>>> expected and a slave takes it's place.
>>>>>>>> My application continues working with no major issues until I decide to
>>>>>>>> recover the dead master node.
>>>>>>>>
>>>>>>>> After that pgool starts sending this message:
>>>>>>>> 2013-12-18 17:19:07 LOG:   pid 30801: do_child: exits with status 1 due
>>>>>>>> to error
>>>>>>>> 2013-12-18 17:19:10 LOG:   pid 30802: pool_send_and_wait: Error or
>>>>>>>> notice message from backend: : DB node id: 0 backend pid: 27585
>>>>>>>> statement: ROLLBACK message: there is no transaction in progress
>>>>>>>> 2013-12-18 17:19:10 ERROR: pid 30802: read_kind_from_backend: 1 th kind
>>>>>>>> C does not match with master or majority connection kind N
>>>>>>>> 2013-12-18 17:19:10 ERROR: pid 30802: kind mismatch among backends.
>>>>>>>> Possible last query was: "ROLLBACK" kind details are: 0[N: there is no
>>>>>>>> transaction in progress] 1[C]
>>>>>>>>
>>>>>>>> And I identified that the problem is that pgpool is sending a rollback
>>>>>>>> to the old master node [node 0] (Something illegal as far as I know) and
>>>>>>>> then all the transaction is cancelled and my application fails.
>>>>>>>> If I promote the old master again, then the application works with no
>>>>>>>> problem.
>>>>>>>>
>>>>>>>> Anyone has an idea why is this ocurring?
>>>>>>>>
>>>>>>>> Regards!
>>>>>>>>
>>>>>>>>
>>>>>>>>
>>>>>>>> -- 
>>>>>>>>
>>>>>>>>
>>>>>>>> Be aware that if you reply directly to this message, your reply may not be 
>>>>>>>> secure. Do not send us communications that contain unencrypted confidential 
>>>>>>>> information such as passwords, account numbers, or Social Security numbers.
>>>>>>>>
>>>>>>>> This message, including any attachments, is for the sole use of the 
>>>>>>>> intended recipient(s) and may contain confidential and privileged 
>>>>>>>> information. If you are not the intended recipient, please destroy all 
>>>>>>>> copies of this message and any attachments. In addition, please notify 
>>>>>>>> Gazzang immediately by email to info at gazzang.com.
>>>>>>>> _______________________________________________
>>>>>>>> pgpool-general mailing list
>>>>>>>> pgpool-general at pgpool.net
>>>>>>>> http://www.pgpool.net/mailman/listinfo/pgpool-general
>>>>>> -- 
>>>>>>
>>>>>>
>>>>>> Be aware that if you reply directly to this message, your reply may not be 
>>>>>> secure. Do not send us communications that contain unencrypted confidential 
>>>>>> information such as passwords, account numbers, or Social Security numbers.
>>>>>>
>>>>>> This message, including any attachments, is for the sole use of the 
>>>>>> intended recipient(s) and may contain confidential and privileged 
>>>>>> information. If you are not the intended recipient, please destroy all 
>>>>>> copies of this message and any attachments. In addition, please notify 
>>>>>> Gazzang immediately by email to info at gazzang.com.
>>>> -- 
>>>>
>>>>
>>>> Be aware that if you reply directly to this message, your reply may not be 
>>>> secure. Do not send us communications that contain unencrypted confidential 
>>>> information such as passwords, account numbers, or Social Security numbers.
>>>>
>>>> This message, including any attachments, is for the sole use of the 
>>>> intended recipient(s) and may contain confidential and privileged 
>>>> information. If you are not the intended recipient, please destroy all 
>>>> copies of this message and any attachments. In addition, please notify 
>>>> Gazzang immediately by email to info at gazzang.com.
>>
>> -- 
>>
>>
>> Be aware that if you reply directly to this message, your reply may not be 
>> secure. Do not send us communications that contain unencrypted confidential 
>> information such as passwords, account numbers, or Social Security numbers.
>>
>> This message, including any attachments, is for the sole use of the 
>> intended recipient(s) and may contain confidential and privileged 
>> information. If you are not the intended recipient, please destroy all 
>> copies of this message and any attachments. In addition, please notify 
>> Gazzang immediately by email to info at gazzang.com.


-- 


Be aware that if you reply directly to this message, your reply may not be 
secure. Do not send us communications that contain unencrypted confidential 
information such as passwords, account numbers, or Social Security numbers.

This message, including any attachments, is for the sole use of the 
intended recipient(s) and may contain confidential and privileged 
information. If you are not the intended recipient, please destroy all 
copies of this message and any attachments. In addition, please notify 
Gazzang immediately by email to info at gazzang.com.


More information about the pgpool-general mailing list