Moodle with galera, problem with deadlocks

[Gessy Junior]

Hi ,

I'm trying to use moodle ( a free source e-learning software platform ). I'm installed MySQL 5.1.61 + 23.3 wsrep patch compiled on Gentoo Linux. So i used three nodes and the RHEL Piranha (centos 6) like load balancing  and in the installation was everywhing ok.

but when using moodle (when i try to access a class), it try do execute the follows statements on node:

LOCK TABLES `mdl_sessions` WRITE;

/*!40000 ALTER TABLE `mdl_sessions` DISABLE KEYS */;

INSERT INTO mdl_sessions (state,sid,sessdata,userid,timemodified,timecreated,lastip,firstip) VALUES('0','qgd7cg2v24iqcfa03m4293','U0VTU0lPTnxPOjg6InN0ZENsYXNzIjowOnt9VVNFUnxPOjg6InN0ZENsYXNzIjoyOntzOjI6ImlkIjtpOjA7czoxMDoibW5ldGhvc3RpZCI7czoxOiIxIjt9','0','1337179416','1337179416','.<here was a client address>','<here was a client address>');

The error message is: Deadlock found when trying to get lock; try restarting transaction

Thank you guys for everything and case somebody knows it... help me

Gessy Jr.

PS.: Sorry for my poor english...

[seppo....@codership.com]

I installed moodle to see what kind of SQL comes out of it. In my
experiments I could not see such LOCK TABLES...INSERT session as in
your sample. Your sample looks more like loading in a mysqldump, I would
not expect to see such in middle of regular application processing.

However, in my logs I could find several calls for GET_LOCK() and
RELEASE_LOCK(), and these are not supported in multi-master use. I
probably could see your LOCK TABLE calls also with some more
experimenting. Anyway, appears that moodle engineers have chosen to
use external locking mechanisms and understood transaction processing
all wrong :( ...

So how can Galera support moodle?
* Currently only option is to use Galera in master-slave mode. You
must direct writes (or at at least all
locking statements) to one node only. If read/write splitting is
available, then read scalability
is possible.
Note that Galera is very effective master-slave processor, giving
no lost transactions and
no slave lag guarantees. Performance should be better also due to
parallel replication (which is
effective!). And fail-over is a minimal task, you just switch
writing to any other node in the cluster.

* Clever SQL proxy could sort out locking sessions. We are working
with ScaleBase to find
optimal solution for this - more news about it later. MySQL proxy
is one open source alternative for
this task, it should be possible to write a LUA script filter to
handle moodle locking sessions.

* We have distributed locking task in Galera backlog. Technically it
is possible to support such
locking in cluster, but there is not much demand for this
currently. So this feature may (or may not)
be part of Galera feature set in the future...


-seppo

[Gessy Junior]

Hi Seppo,

Thanks a lot for reply me. 

I understand  that if i redirect all write statements to one node i can use the galera for read  in all other nodes. right? 

So i try configure mysql-proxy with rw splitting, it works but the error continues. I also tried configure my moodle to access only one node of the cluster but I still get a error. Should I have a spefic configuration to have galera working on master-slave mode?

Here is the general_log of the node where  i try to write: http://pastie.org/3926053

Thank you very much

Gessy 

[Alex Yurchenko]

Hi,

Perhaps if you could post the output of SHOW VARIABLES it could help.

Also, could you try it on a standalone Galera node (1-node cluster)?

BTW, is there a particular reason you're using MySQL 5.1? Our patch for
5.5 is far more complete.

Regards,
Alex

On 2012-05-17 18:49, Gessy Junior wrote:
> Hi Seppo,
>
> Thanks a lot for reply me.
> I understand that if i redirect all write statements to one node i
> can use
> the galera for read in all other nodes. right?
> So i try configure mysql-proxy with rw splitting, it works but the
> error
> continues. I also tried configure my moodle to access only one node
> of the
> cluster but I still get a error. Should I have a spefic configuration
> to
> have galera working on master-slave mode?
>
> Here is the general_log of the node where i try to write:
> http://pastie.org/3926053
>
> Thank you very much
> Gessy
>

--
Alexey Yurchenko,
Codership Oy, www.codership.com
Skype: alexey.yurchenko, Phone: +358-400-516-011

[Gessy Junior]

Hi,

my show variables: http://pastie.org/3927118

I used the 5.1 because my linux distribution offers  that branch like stable. I'm using moodle 2.0 branch, my production ambient is mysql 5.1 and moodle 2.0 branch so i really keep the test enviroment near to the production enviroment.

I guess the error that i get was for other reasons but   i would like know the best way for have moodle working with galera, if anyone already experiment it.

Thanks a lot Alex

Gessy Jr.

[seppo....@codership.com]

Hi Gessy,

Quoting Gessy Junior <gessyc...@gmail.com>:

> Hi Seppo,
>
> Thanks a lot for reply me.
> I understand that if i redirect all write statements to one node i can use
> the galera for read in all other nodes. right?

Yes

> So i try configure mysql-proxy with rw splitting, it works but the error
> continues. I also tried configure my moodle to access only one node of the
> cluster but I still get a error. Should I have a spefic configuration to
> have galera working on master-slave mode?

No special configuration is needed for master-slave operation. Galera
cluster is readily available for either multi-master or master-slave
use. It is just client's decision whether to write to one or several
nodes.

>
> Here is the general_log of the node where i try to write:
> http://pastie.org/3926053
>
> Thank you very much
> Gessy
>

This general log does not tell much to me. There is one INSERT and one
UPDATE statement, which probably give deadlock error for you. I can
only say that by looking at this log and if you are really writing to
one node only, there is no reason for any deadlocks. There is probably
some fundamental configuration issue, unnoticed so far. Can you
verify that your tables are really InnoDB? Try e.g.

mysql> SHOW CREATE TABLE mdl_sessions;
mysql> SHOW CREATE TABLE mdl_forum;


-seppo

[seppo....@codership.com]

One observation from your config: You have log_output=TABLE. Try
changing this to FILE.

-seppo

[Gessy Junior]

Dear Seppo,

Thank you so much for the instructions, i really was having a error not concerning to galera. I understand what did you mean.

About the variables, I'll change the log_output but i could notice that  ist.recv_addr  is set to 150.1 (http://pastie.org/3927118),  but I configure it in wsrep_provider_options with the ip of the node, is something wrong?

Thanks a lot,

Gessy

[Alex Yurchenko]

On 2012-05-18 18:15, Gessy Junior wrote:
> Dear Seppo,
>
>
> Thank you so much for the instructions, i really was having a error
> not
> concerning to galera. I understand what did you mean.
> About the variables, I'll change the log_output but i could notice
> that
> ist.recv_addr is set to 150.1 (http://pastie.org/3927118), but I
> configure it in wsrep_provider_options with the ip of the node, is
> something wrong?

This is merely a display bug - the buffer is too short to hold the
whole line.

>
> Thanks a lot,
> Gessy

[Gessy Junior]

Hi,

I realize that moodle has a issue  with binlog_format other then MIXED. On Galera documentation  states binlog_format t to ROW. Is possible run Mysql/Galera with binlog_format=MIXED?

Thanks

Gessy Jr.

[seppo....@codership.com]

Hi Gessy,

What makes you think that moodle is not compatible with ROW format
replication? This is probably misconception somewhere.

MIXED format is a hybrid mode. It defaults to STATEMENT format and
switches to ROW when needed for consistency.

We have enabled STATEMENT and MIXED modes in Galera replication, these
will be needed in future when we will implement escalation modes in
our replication. Currently, our testing is still 100% with ROW
replication only, and there is really not much experience how well
STATEMENT replication would work.

-seppo

Quoting Gessy Junior <gessyc...@gmail.com>:

[Gessy Junior]

Hi Seppo,

I talked with a moodle administrator of my sector and he reply me that moodle really has a issue with binlog_format = ROW. The error occurs when the following is executed:

Database transaction aborted automatically in /var/www/moodle/admin/index.php Default exception handler: Error writing to database Debug: Binary logging not possible. Message: Transaction level 'READ-COMMITTED' in InnoDB is not safe for binlog mode 'STATEMENT' DELETE FROM mdl_block_instances WHERE parentcontextid = ? [array ( 0 => '5', )] * line 394 of /lib/dml/moodle_database.php:

 

Cannot execute statement: impossible to write to binary log since BINLOG_FORMAT = STATEMENT and at least one table uses a storage engine limited to row-based logging. InnoDB is limited to row-logging when transaction isolation level is READ COMMITTED or READ UNCOMMITTED.

INSERT INTO mdl_message_providers (name,component,capability) VALUES(?,?,?)

[array (

0 => 'notices',

1 => 'moodle',

2 => 'moodle/site:config',

)]

I don't understand so munch but do you have any suggestion?

Thank you so much.

Gessy Jr.

[seppo....@codership.com]

Hi Gessy,

This error message tells actually that your MySQL server is configured
to use STATEMENT replication and not ROW. Check you my.cnf, and make
sure you have there:

binlog_format=ROW

[Gessy Junior]

Hi Seppo,

Sorry and thank you. You are right!

I having errors with temporary table too.Moodle need creates temporary tables. Is galera not suporting temporary tables?

120524 11:50:21 [Note] WSREP: declaring 39759a81-a4db-11e1-0800-32af3d102dbb stable

120524 11:50:21 [Note] WSREP: declaring 74049dea-a4da-11e1-0800-2e80f7f5841d stable

120524 11:50:21 [Note] WSREP: declaring bcc334a8-a4db-11e1-0800-6cb5199b7542 stable

120524 11:50:22 [Note] WSREP: gcomm: connected

120524 11:50:22 [Note] WSREP: Changing maximum packet size to 64500, resulting msg size: 32636

120524 11:50:22 [Note] WSREP: Shifting CLOSED -> OPEN (TO: 0)

120524 11:50:22 [Note] WSREP: Opened channel 'moodle_mysql_cluster'

120524 11:50:22 [Note] WSREP: New COMPONENT: primary = yes, my_idx = 3, memb_num = 4

120524 11:50:22 [Note] /usr/sbin/mysqld: ready for connections.

Version: '5.1.61-log'  socket: '/var/run/mysqld/mysqld.sock'  port: 3306  Gentoo Linux mysql-5.1.61-r1, wsrep_23.3.rxxxx

120524 11:50:22 [Note] WSREP: STATE EXCHANGE: Waiting for state UUID.

120524 11:50:22 [Note] WSREP: STATE EXCHANGE: sent state msg: cbdf7aea-a5af-11e1-0800-0836f7f8a3d7

120524 11:50:22 [Note] WSREP: STATE EXCHANGE: got state msg: cbdf7aea-a5af-11e1-0800-0836f7f8a3d7 from 0 (mysql04)

120524 11:50:22 [Note] WSREP: STATE EXCHANGE: got state msg: cbdf7aea-a5af-11e1-0800-0836f7f8a3d7 from 1 (mysql03)

120524 11:50:22 [Note] WSREP: STATE EXCHANGE: got state msg: cbdf7aea-a5af-11e1-0800-0836f7f8a3d7 from 2 (oldap2)

120524 11:50:22 [Note] WSREP: STATE EXCHANGE: got state msg: cbdf7aea-a5af-11e1-0800-0836f7f8a3d7 from 3 (mysql02)

120524 11:50:22 [Note] WSREP: Quorum results:

version    = 2,

component  = PRIMARY,

conf_id    = 11,

members    = 4/4 (joined/total),

act_id     = 25423,

last_appl. = -1,

protocols  = 0/3/1 (gcs/repl/appl),

group UUID = 986e4faf-a4d8-11e1-0800-48d3058eca09

120524 11:50:22 [Note] WSREP: Flow-control interval: [253, 256]

120524 11:50:22 [Note] WSREP: Restored state OPEN -> JOINED (25423)

120524 11:50:22 [Note] WSREP: New cluster view: global state: 986e4faf-a4d8-11e1-0800-48d3058eca09:25423, view# 12: Primary, number of nodes: 4, my index: 3, protocol version 1

120524 11:50:22 [Note] WSREP: Member 3 (mysql02) synced with group.

120524 11:50:22 [Note] WSREP: Shifting JOINED -> SYNCED (TO: 25423)

120524 11:50:22 [Note] WSREP: Assign initial position for certification: 25423, protocol version: 2

120524 11:50:22 [Note] WSREP: Synchronized with group, ready for connections

120528 16:45:59 [Warning] WSREP: Error executing 'CREATE TEMPORARY TABLE mdl_backup_ids_temp (

id BIGINT(10) unsigned NOT NULL auto_increment,

backupid VARCHAR(32) NOT NULL DEFAULT '695c7e8980c045afd33d50bd0803d761',

itemname VARCHAR(160) NOT NULL DEFAULT '',

itemid BIGINT(10) unsig

120528 16:46:28 [Warning] WSREP: Error executing 'DROP TEMPORARY TABLE mdl_backup_ids_temp', seqno: 1052290

120528 16:46:37 [Warning] WSREP: Error executing 'DROP TABLE mdl_backup_ids_temp', seqno: 1052309

120528 16:46:44 [Warning] WSREP: Error executing 'CREATE TEMPORARY TABLE mdl_backup_ids_temp (

id BIGINT(10) unsigned NOT NULL auto_increment,

backupid VARCHAR(32) NOT NULL DEFAULT '695c7e8980c045afd33d50bd0803d761',

itemname VARCHAR(160) NOT NULL DEFAULT '',

itemid BIGINT(10) unsig

120528 16:46:58 [Warning] WSREP: Error executing 'CREATE TEMPORARY TABLE mdl_backup_ids_temp (

id BIGINT(10) unsigned NOT NULL auto_increment,

backupid VARCHAR(32) NOT NULL DEFAULT '695c7e8980c045afd33d50bd0803d761',

itemname VARCHAR(160) NOT NULL DEFAULT '',

itemid BIGINT(10) unsig

120528 16:50:15 [Warning] WSREP: Error executing 'CREATE TEMPORARY TABLE mdl_backup_ids_temp (

id BIGINT(10) unsigned NOT NULL auto_increment,

backupid VARCHAR(32) NOT NULL DEFAULT '695c7e8980c045afd33d50bd0803d761',

itemname VARCHAR(160) NOT NULL DEFAULT '',

itemid BIGINT(10) unsig

120528 16:50:26 [Warning] WSREP: Error executing 'CREATE TEMPORARY TABLE mdl_backup_ids_temp (

id BIGINT(10) unsigned NOT NULL auto_increment,

backupid VARCHAR(32) NOT NULL DEFAULT '695c7e8980c045afd33d50bd0803d761',

itemname VARCHAR(160) NOT NULL DEFAULT '',

itemid BIGINT(10) unsig

Thank you so much

Gessy Jr.

[Alex Yurchenko]

IIRC this was fixed only in 5.5. I seriously think you should upgrade.
5.1 is barely maintained for old users only and is going to be dropped
as soon as 5.6 is out.

Regards,
Alex