Galera crash

[Haris Zukanovic]

Hi everyone,

Maybe someone could help me diagnose what happed today with my Galera cluster 3 nodes (WAN cluster)..
Database is the Drupal 7 and practically without data since it is a new test installation. I only inserted some articles and enabled some extra modules..


The Galera servers are mysql2, mysql3, mysql4 (I changed myself the IPs in log file with these names) in a WAN cluster, installed and monitored by SeveralNines admin application for Galera.

I am only writing to and reading from mysql3 in this test setup.

While mysql3 does not have any errors, below is the extract from mysql2 log "grep ERROR mysql2_error.log" from today...
mysql4 has exactly the same errors in the log as mysql2.

The error seems to cause a WSREP_FATAL which brings down (restarts) the mysql server and breaks the WAN cluster which then resyncs and so on ...

The whole log files are attached..

from mysql2_error.log:
120404 10:13:12 [ERROR] Slave SQL: Could not execute Write_rows event on table staging_drupal.drupal_cache_bootstrap; Duplicate entry 'hook_info' for key 'PRIMARY', Error_code: 1062; handler error HA_ERR_FOUND_DUPP_KEY; the event's master log FIRST, end_log_pos 395, Error_code: 1062
120404 10:13:12 [ERROR] WSREP: Failed to apply trx: source: f358b863-74ce-11e1-0800-7584d5c2c4ea version: 2 local: 0 state: CERTIFYING flags: 1 conn_id: 554534 trx_id: 2957462 seqnos (l: 792, g: 9241, s: 9240, d: 9240, ts: 1333527181674499070)
120404 10:13:12 [ERROR] WSREP: Failed to apply app buffer: ?|O, seqno: 9241, status: WSREP_FATAL
120404 10:13:12 [ERROR] WSREP: Node consistency compromized, aborting...
120404 10:25:28 [ERROR] Slave SQL: Could not execute Write_rows event on table staging_drupal.drupal_cache_bootstrap; Duplicate entry 'hook_info' for key 'PRIMARY', Error_code: 1062; handler error HA_ERR_FOUND_DUPP_KEY; the event's master log FIRST, end_log_pos 1671, Error_code: 1062
120404 10:25:28 [ERROR] WSREP: Failed to apply trx: source: f358b863-74ce-11e1-0800-7584d5c2c4ea version: 2 local: 0 state: CERTIFYING flags: 1 conn_id: 554942 trx_id: 2963543 seqnos (l: 63, g: 9666, s: 9665, d: 9665, ts: 1333527917845603820)
120404 10:25:28 [ERROR] WSREP: Failed to apply app buffer: m|O, seqno: 9666, status: WSREP_FATAL
120404 10:25:28 [ERROR] WSREP: Node consistency compromized, aborting...
120404 10:29:12 [ERROR] Slave SQL: Could not execute Write_rows event on table staging_drupal.drupal_cache_bootstrap; Duplicate entry 'variables' for key 'PRIMARY', Error_code: 1062; handler error HA_ERR_FOUND_DUPP_KEY; the event's master log FIRST, end_log_pos 9268, Error_code: 1062
120404 10:29:12 [ERROR] WSREP: Failed to apply trx: source: f358b863-74ce-11e1-0800-7584d5c2c4ea version: 2 local: 0 state: CERTIFYING flags: 1 conn_id: 555064 trx_id: 2969401 seqnos (l: 53, g: 10119, s: 10118, d: 10112, ts: 1333528142353585540)
120404 10:29:12 [ERROR] WSREP: Failed to apply app buffer: N|O, seqno: 10119, status: WSREP_FATAL
120404 10:29:12 [ERROR] WSREP: Node consistency compromized, aborting...




show create table staging_drupal.drupal_cache_bootstrap;
+------------------------+-------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------+
| Table                  | Create Table                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                         |
+------------------------+-------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------+
| drupal_cache_bootstrap | CREATE TABLE `drupal_cache_bootstrap` (
  `cid` varchar(255) NOT NULL DEFAULT '' COMMENT 'Primary Key: Unique cache ID.',
  `data` longblob COMMENT 'A collection of data to cache.',
  `expire` int(11) NOT NULL DEFAULT '0' COMMENT 'A Unix timestamp indicating when the cache entry should expire, or 0 for never.',
  `created` int(11) NOT NULL DEFAULT '0' COMMENT 'A Unix timestamp indicating when the cache entry was created.',
  `serialized` smallint(6) NOT NULL DEFAULT '0' COMMENT 'A flag to indicate whether content is serialized (1) or not (0).',
  PRIMARY KEY (`cid`),
  KEY `expire` (`expire`)
) ENGINE=InnoDB DEFAULT CHARSET=utf8 COMMENT='Cache table for data required to bootstrap Drupal, may be...' |
+------------------------+-------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------+


thank you in advance

-- 
--
Haris Zukanovic

[seppo....@codership.com]

Hi Haris,

I'm working on a smilar issue atm, D7 caching causes some challenging
SQL to deal with. We have a hotfix build which seems to be effecive
for this. It might help as a workaround for you, if you enable log-bin
in my.cnf.

Thanks for reporting this, Seppo

[Haris Zukanovic]

Would you like me to test this fix?

--
--
Haris Zukanovic

[will]

Which build is this issue resolved in?  I'm seeing the same problem with D7 and a three cluster setup.  Where can it be downloaded?  And or where can I find out more (follow) this issue?

-TIA

[seppo....@codership.com]

Hi,

The bug that you are hitting with D7 testing is probably this one:
https://bugs.launchpad.net/codership-mysql/+bug/959512 . We have a
hotfix for it for Redhat 6, but as we are preparing complete 5.5
branch build atm, it makes sense to wait for it.

-seppo

Quoting will <adr...@br3asts.com>:

> --
> You received this message because you are subscribed to the Google
> Groups "codership" group.
> To view this discussion on the web visit
> https://groups.google.com/d/msg/codership-team/-/CcUv1xpq07cJ.
> To post to this group, send email to codersh...@googlegroups.com.
> To unsubscribe from this group, send email to
> codership-tea...@googlegroups.com.
> For more options, visit this group at
> http://groups.google.com/group/codership-team?hl=en.

[Haris Zukanovic]

Indeed, my case does resemble the
https://bugs.launchpad.net/codership-mysql/+bug/959512

I will wait for the new release
https://launchpad.net/codership-mysql/+milestone/5.5.21-23.5
to test it..

kind regards
Haris

--
--
Haris Zukanovic

[Haris Zukanovic]

Hi Seppo,

Ok. I am waiting for Mysql 5.5.22-23.5 to re-test this then...
If I understand correctly it is not Galera but the Mysql "incompatibility" that is the source of this.
BTW, is there a way to know if also Percona version of Mysql is affected by this problem?

kind regards
Haris

On 08/04/12 13.39, seppo....@codership.com wrote:

-- 
--
Haris Zukanovic

[seppo....@codership.com]

Hi Haris,

As you probably have noticed already, the release has been published
now. We had to add one more merge with upstream MySQL 5.5.23, as there
is a security fix. The final MySQL wsrep release number is therefore:
5.5.23-23.5.

Galera library has not been upgraded with this release, we still use
Galera 2.0 here.

I expect that Percona XtraDB Cluster faced the same issue, but I have
not tested and cannot say for sure. Percona takes our wsrep patch set
and merges with Percona Server, they should have corresponding Percona
XtraDB Cluster release coming out pretty soon.

-seppo

Quoting Haris Zukanovic <haris.zu...@gmail.com>:

> --

[Haris Zukanovic]

Thank you for info.
I will retest my case and let you all know the result...

kind regards
Haris

--
--
Haris Zukanovic

[Erik]

Hi all,

we had the same symptoms as initially described when using Drupal 6 and 7 on a Galera 3 node setup. So we upgraded to following version:

Server version: 5.5.23 Percona XtraDB Cluster (GPL), wsrep_23.5.r333.

Reads and writes are currently only on node 1.

at first, symptoms disappeared. But today they were back and caused Galera cluster to fail.

first node 2 showed the error, after SST from node 3 to node 1, then node 3 got the errors as described here:

Node 2:

120522 23:30:03 [ERROR] Slave SQL: Could not execute Write_rows event on table vlaanderenebl.search_index; Duplicate entry 'beleid-466561-node' for key 'word_sid_type', Error_code: 1062; handler error HA_ERR_FOUND_DUPP_KEY; the event's master log FIRST, end_log_pos 118, Error_code: 1062

120522 23:30:03 [Warning] WSREP: RBR event 2 Write_rows apply warning: 121, 648109

120522 23:30:03 [ERROR] WSREP: Failed to apply trx: source: e5f48af8-9f65-11e1-0800-0125b3f4ee96 version: 2 local: 0 state: CERTIFYING flags: 1 conn_id: 4731519 trx_id: 167959436 seqnos (l: 582845, g: 648109, s: 648108, d: 647283, ts: 1337722203963450898)

120522 23:30:03 [ERROR] WSREP: Failed to apply app buffer: [^E<BC>O^S, seqno: 648109, status: WSREP_FATAL

         at galera/src/replicator_smm.cpp:apply_wscoll():51

         at galera/src/replicator_smm.cpp:apply_trx_ws():122

120522 23:30:03 [ERROR] WSREP: Node consistency compromized, aborting...

Node 3:

120522 23:30:06 [Note] WSREP: Shifting SYNCED -> DONOR/DESYNCED (TO: 648277)

120522 23:30:06 [Note] WSREP: wsrep_notify_cmd is not defined, skipping notification.

120522 23:30:06 [Note] WSREP: Running: 'wsrep_sst_rsync 'donor' '10.22.X.XX:4444/rsync_sst' 'root:passwd' '/var/lib/mysql/' '/etc/my.cnf' '9ba720b3-8d53-11e1-0800-52407

120522 23:30:06 [Note] WSREP: sst_donor_thread signaled with 0

120522 23:30:06 [Note] WSREP: Flushing tables for SST...

120522 23:30:06 [Note] WSREP: Provider paused at 9ba720b3-8d53-11e1-0800-52407463bac7:648278

120522 23:30:06 [Note] WSREP: Tables flushed.

120522 23:31:45 [Note] WSREP: Provider resumed.

120522 23:31:45 [ERROR] Slave SQL: Could not execute Write_rows event on table vlaanderenebl.search_index; Duplicate entry 'voor-474172-node' for key 'word_sid_type', E

120522 23:31:45 [ERROR] Slave SQL: Could not execute Write_rows event on table vlaanderenebl.search_index; Duplicate entry 'vlaamse-474172-node' for key 'word_sid_type'

120522 23:31:45 [Warning] WSREP: RBR event 2 Write_rows apply warning: 121, 648284

120522 23:31:45 [Warning] WSREP: RBR event 2 Write_rows apply warning: 121, 648285

120522 23:31:45 [ERROR] Slave SQL: Could not execute Write_rows event on table vlaanderenebl.search_index; Duplicate entry 'visserij-474172-node' for key 'word_sid_type

120522 23:31:45 [Warning] WSREP: RBR event 2 Write_rows apply warning: 121, 648286

120522 23:31:45 [ERROR] WSREP: Failed to apply trx: source: e5f48af8-9f65-11e1-0800-0125b3f4ee96 version: 2 local: 0 state: CERTIFYING flags: 1 conn_id: 4731519 trx_id:

120522 23:31:45 [ERROR] WSREP: Failed to apply app buffer: ^^E<BC>O^S, seqno: 648284, status: WSREP_FATAL

         at galera/src/replicator_smm.cpp:apply_wscoll():51

         at galera/src/replicator_smm.cpp:apply_trx_ws():122

120522 23:31:45 [ERROR] WSREP: Node consistency compromized, aborting...

In this case it is a Drupal 6 installation which "caused" errors.

So what could cause these inconsistenties ? Like previously mentioned, enabling log-bin in my.cnf, could this be a workaround.

I'm a little bit concerned about these failures because we would like to go to production fairly soon.

Thanks in advance for any tips/fixes!

[seppo....@codership.com]

Hi Erik,

Can you send full mysql error logs from all nodes? (use email:
seppo....@codership.com)
Attach also my.cnf at least from one cluster node.

-seppo

[Seppo Jaakola]

Erik's issue turned out to be due to a bug:

If a table has no primary key, but yet defines a unique key, it may
happen that slave configured with parallel applying has problems. This
issue surfaced with Drupal6 using apache-solr module. Although the
affected table is native D6 table, so solr is not the actual trouble
maker here.

We have a bug tracker: https://bugs.launchpad.net/codership-mysql/+bug/1003929
and a regression test, this will be an easy fix

Thanks Erik for logs and troubleshooting help!

-seppo

On 23 touko, 18:31, seppo.jaak...@codership.com wrote:
> Hi Erik,
>
> Can you send full mysql error logs from all nodes? (use email:

> seppo.jaak...@codership.com)

> Attach also my.cnf at least from one cluster node.
>
> -seppo
>