You are here

failed MySQL DDL commands and Galera replication

We have recently seen a case where the following command was executed on a Galera Cluster node:

SQL> GRANT SUPER ON userdb.* TO root@127.0.0.111;
ERROR 1221 (HY000): Incorrect usage of DB GRANT and GLOBAL PRIVILEGES

2014-12-09 14:53:55 7457 [Warning] Did not write failed 'GRANT SUPER ON userdb.* TO root@127.0.0.111' into binary log while granting/revoking privileges in databases.
2014-12-09 14:53:55 7457 [ERROR] Slave SQL: Error 'Incorrect usage of DB GRANT and GLOBAL PRIVILEGES' on query. Default database: ''. Query: 'GRANT SUPER ON userdb.* TO root@127.0.0.111', Error_code: 1221
2014-12-09 14:53:55 7457 [Warning] WSREP: RBR event 1 Query apply warning: 1, 17
2014-12-09 14:53:55 7457 [Warning] WSREP: Ignoring error for TO isolated action: source: c5e54ef5-7faa-11e4-97b0-5e5c695f08a5 version: 3 local: 0 state: APPLYING flags: 65 conn_id: 4 trx_id: -1 seqnos (l: 4, g: 17, s: 15, d: 15, ts: 113215863294782)

According to the error message it looks like this command is done in Total Order Isolation (TOI) mode during the Rolling Schema Upgrade (RSU).

Only on the nodes which did NOT receive this wrong command the error log message was written and further they have received a GRA_*.log file.

Analysis of the GRA_*.log (failed transactions) files:

hexdump -C GRA_2_16.log 
00000000  f3 fe 86 54 02 53 14 00  00 76 00 00 00 76 00 00  |...T.S...v...v..|
00000010  00 00 00 04 00 00 00 00  00 00 00 00 00 00 2a 00  |..............*.|
00000020  00 00 00 00 00 01 00 00  00 40 00 00 00 00 06 03  |.........@......|
00000030  73 74 64 04 21 00 21 00  08 00 0b 04 72 6f 6f 74  |std.!.!.....root|
00000040  09 6c 6f 63 61 6c 68 6f  73 74 00 67 72 61 6e 74  |.localhost.grant|
00000050  20 53 55 50 45 52 20 6f  6e 20 75 73 65 72 64 62  | SUPER on userdb|
00000060  2e 2a 20 74 6f 20 72 6f  6f 74 40 31 32 37 2e 30  |.* to root@127.0|
00000070  2e 30 2e 31 31 31                                 |.0.111          |

dd if=bin-log.000001 of=binlog.header bs=1 count=120
cat binlog.header GRA_2_17.log > GRA_2_17.binlog_events
mysqlbinlog GRA_2_17.binlog_events
...
# at 120
#141209 15:04:54 server id 5201  end_log_pos 118 CRC32 0x3432312e       Query   thread_id=45    exec_time=0     error_code=0
SET TIMESTAMP=1418133894/*!*/;
SET @@session.pseudo_thread_id=4/*!*/;
SET @@session.foreign_key_checks=1, @@session.sql_auto_is_null=0, @@session.unique_checks=1, @@session.autocommit=1/*!*/;
SET @@session.sql_mode=1073741824/*!*/;
SET @@session.auto_increment_increment=1, @@session.auto_increment_offset=1/*!*/;
/*!\C utf8 *//*!*/;
SET @@session.character_set_client=33,@@session.collation_connection=33,@@session.collation_server=8/*!*/;
SET @@session.lc_time_names=0/*!*/;
SET @@session.collation_database=DEFAULT/*!*/;
grant SUPER on userdb.* to root@127.0.0.111
/*!*/;
DELIMITER ;
# End of log file
ROLLBACK /* added by mysqlbinlog */;
/*!50003 SET COMPLETION_TYPE=@OLD_COMPLETION_TYPE*/;
/*!50530 SET @@SESSION.PSEUDO_SLAVE_MODE=0*/;

It further looks like this command was issues by Connection ID number 4: conn_id: 4.

Taxonomy upgrade extras: 

Comments

... show that this is expected behavior:
  • Galera will replicate a DDL statement first, before it gets executed locally.
  • Local execution will fail, because the "super" privilege is a global one, it cannot be granted for a specific database "db.*" but only for all of them "*.*"
  • Of course, execution on the other nodes will fail in the same way.
So: While it looks ugly, it is nothing to worry about.
joergcomment

XXX means Thread ID (= Connection ID) and YYY wsrep transaction sequence number (wsrep_last_committed?):

snprintf(filename, len+1, "%s/GRA_%lld_%lld.log",
         wsrep_data_home_dir, (long long) thd->thread_id,
         (long long) wsrep_thd_trx_seqno(thd));

Shinguzcomment