Mike
Mike

Reputation: 43

Strange MySQL replication update error (Magento)

MySQL replication is a little bit new to me, but it looks like I've got it working up till some errors I don't understand.

Some background: I'm replicating all databases (over SSL) from a MySQL 5.6.22 server to a MariaDB 10.0.15 server, which isn't doing anything else than being a dedicated slave to the master. It executes some queries but then runs into an updating problem with a Magento database. If I skip this query, it will just run into a similar query which causes the same error.

This is the error the slave status gives me:

Could not execute Update_rows event on table magento_db.log_visitor; Column 'visitor_id' cannot be null, Error_code: 1048; Can't find record in 'log_visitor', Error_code: 1032; Column 'visitor_id' cannot be null, Error_code: 1048; handler error HA_ERR_KEY_NOT_FOUND; the event's master log mysql-bin.000121, end_log_pos 7656

Exec_Master_Log_Pos is 7215, but I assume that's irrelevant and the error is in the next query (/transaction block).

Here is a piece of the (verbose) mysqlbinlog:

COMMIT/*!*/;
# at 7215
#150330  2:19:45 server id 1  end_log_pos 7292 CRC32 0xf975481b 	Query	thread_id=25	exec_time=0	error_code=0
SET TIMESTAMP=1427674785/*!*/;
BEGIN
/*!*/;
# at 7292
# at 7358
#150330  2:19:45 server id 1  end_log_pos 7358 CRC32 0x0312921e 	Table_map: `magento_db`.`log_url_info` mapped to number 2528
#150330  2:19:45 server id 1  end_log_pos 7497 CRC32 0xe3704a8b 	Write_rows: table id 2528 flags: STMT_END_F
### INSERT INTO `magento_db`.`log_url_info`
### SET
###   @1=12534083 /* LONGINT meta=0 nullable=0 is_null=0 */
###   @2='http://www.myshop.com/catalog/category/view/id/29?cat=31&color=22&dir=desc&order=position&price=9-' /* VARSTRING(765) meta=765 nullable=1 is_null=0 */
###   @3=NULL /* VARSTRING(765) meta=765 nullable=1 is_null=1 */
# at 7497
# at 7565
#150330  2:19:45 server id 1  end_log_pos 7565 CRC32 0x340012cd 	Table_map: `magento_db`.`log_visitor` mapped to number 2513
#150330  2:19:45 server id 1  end_log_pos 7656 CRC32 0xd3d2e26f 	Update_rows: table id 2513 flags: STMT_END_F
### UPDATE `magento_db`.`log_visitor`
### WHERE
###   @1=3036630 /* LONGINT meta=0 nullable=0 is_null=0 */
### SET
###   @2='deq65v4ks7tgahp2lvih8s74j1' /* VARSTRING(192) meta=192 nullable=0 is_null=0 */
###   @3=1427667585 /* TIMESTAMP(0) meta=0 nullable=1 is_null=0 */
###   @4=1427667585 /* TIMESTAMP(0) meta=0 nullable=0 is_null=0 */
###   @5=12534083 /* LONGINT meta=0 nullable=0 is_null=0 */
###   @6=1 /* SHORTINT meta=0 nullable=0 is_null=0 */
# at 7656
# at 7714
#150330  2:19:45 server id 1  end_log_pos 7714 CRC32 0xc1eee09b 	Table_map: `magento_db`.`log_url` mapped to number 2529
#150330  2:19:45 server id 1  end_log_pos 7770 CRC32 0xf7bcccad 	Write_rows: table id 2529 flags: STMT_END_F
### INSERT INTO `magento_db`.`log_url`
### SET
###   @1=12534083 /* LONGINT meta=0 nullable=0 is_null=0 */
###   @2=3036630 /* LONGINT meta=0 nullable=1 is_null=0 */
###   @3=1427667585 /* TIMESTAMP(0) meta=0 nullable=0 is_null=0 */
# at 7770
#150330  2:19:45 server id 1  end_log_pos 7801 CRC32 0x51775dd4 	Xid = 29537
COMMIT/*!*/;
# at 7801
#150330  2:19:53 server id 1  end_log_pos 7886 CRC32 0xd6d724c7 	Query	thread_id=26	exec_time=0	error_code=0
SET TIMESTAMP=1427674793/*!*/;

visitor_id is the first column that shows in phpMyAdmin, but also when I perform SHOW COLUMNS FROM log_visitor;, so I'm guessing this column maps to '@1' (couldn't find how to verify this). But when I search for a record with visitor_id 3036630, it just finds one. Note that this is not due to external queries, when I perform START SLAVE; again, it hangs on the same error. Also, I tried running mysql_upgrade on the slave, but other than some warning, this solved nothing.

Bottom line is: I don't know how to interpret this error, am I maybe looking at the wrong query? It feels to me there shouldn't be an error, maybe some incompatibility?

Any suggestions are welcome!

EDIT: As requested, a SHOW CREATE TABLE, which seem the same on both servers after doing a diff, except for the increment index:

CREATE TABLE `log_visitor` (
 `visitor_id` bigint(20) unsigned NOT NULL AUTO_INCREMENT COMMENT 'Visitor ID',
 `session_id` varchar(64) NOT NULL COMMENT 'Session ID',
 `first_visit_at` timestamp NULL DEFAULT NULL COMMENT 'First Visit Time',
 `last_visit_at` timestamp NOT NULL DEFAULT '0000-00-00 00:00:00' COMMENT 'Last Visit Time',
 `last_url_id` bigint(20) unsigned NOT NULL DEFAULT '0' COMMENT 'Last URL ID',
 `store_id` smallint(5) unsigned NOT NULL COMMENT 'Store ID',
 PRIMARY KEY (`visitor_id`)
) ENGINE=InnoDB AUTO_INCREMENT=3036631 DEFAULT CHARSET=utf8 COMMENT='Log Visitors Table'

The slave was created by dropping all databases (I've had multiple attempts), doing a mysqldump with all databases after acquiring a read lock on the master, importing it into the slave and then starting the slave at the right position. It does some queries and when I look, it already got to an update error like the one described here.

Upvotes: 0

Views: 1768

Answers (1)

Mike
Mike

Reputation: 43

It seems like I found the solution. I once copied/adjusted a nice my.cnf for the master, which included the MySQL 5.6 setting "binlog_row_image = MINIMAL". This causes the binlog to skip columns in the SET-clause of an UPDATE, that are already in the WHERE-clause and are unchanged. MariaDB does not seem to have implemented this setting and the default binlog ROW format requires a value for all fields.

Upvotes: 1

Related Questions