In one of my latest database restore jobs, I was helping a MySQL client with issues related to mysqlbinlog and I wanted to share it here. In case you didn’t know, MySQL is a simple SQL shell with input line editing capabilities, while mysqlbinlog is a utility for processing binary logs a MySQL server. In this case, the server was MariaDB, but the utilities are the same. The database version was 10.1.38-MariaDB.
mysqlbinlog mysql-bin.000072 --stop-position=16208282 --result-file=binlog72.sql Now that you have the SQL file that will apply all missing events since your last backup, you will want to run this on the MySQL server. We use MySQL client for the same. Typically, it is something like: mysql -uadmin -p < binlog72.sql But in our case, there were errors after running this command. The error is shown below: Enter **************** at line 66848: ASCII '\0' appeared in the statement, but this is not allowed unless option --binary-mode is enabled and mysql is run in non-interactive mode. Set --binary-mode to 1 if ASCII '\0' is expected. Query: 'INSERT into pythian_msq(ID, KEY, REGION, CREATED_DATE, PRIORITY, BYTES) values ('b67d8bd1-f8f7-8ffb-d2a4-88da8cf14b21', 'd4d0a754-019b-39af-b568-2f2bf93b2845', '2.8.0', 1553862137605, NULL, _binary '??. Obviously, something was wrong with binary data as the error message was showing "--binary-mode is not enabled" but the other message was also confusing - "unless MySQL is run in non-interactive mode". In our case, per my understanding, we were running MySQL in non-interactive mode. Still, the error message was not easy to understand. ASCII '\0' appeared in the statement, but this is not allowed unless option --binary-mode is enabled and mysql is run in non-interactive mode From the manual on --binary-mode
By default, ASCII '\0' is disallowed and '\r\n' is translated to '\n'. This switch turns off both features, and also turns off parsing of all client commands except \C and DELIMITER, in non-interactive mode (for input piped to MySQL or loaded using the 'source' command). This is necessary when processing output from mysqlbinlog that may contain blobs.The table was showing an error with the below design:
CREATE TABLE `pythian_msq` ( `ID` char(36) COLLATE utf8_unicode_ci NOT NULL, `KEY` char(36) COLLATE utf8_unicode_ci NOT NULL, `CREATED_DATE` bigint(20) NOT NULL, `PRIORITY` int(11) DEFAULT NULL, `SEQUENCE` bigint(20) NOT NULL AUTO_INCREMENT, `BYTES` blob, `REGION` varchar(100) COLLATE utf8_unicode_ci NOT NULL, PRIMARY KEY (`KEY`,`ID`,`REGION`) ) ENGINE=InnoDB DEFAULT CHARSET=utf8 COLLATE=utf8_unicode_ci; The column that was failing in the insert is defined as "blob". According to quick research on this and based on the error message, the next command we used was with --binary-mode=1 mysql -uadmin -p --binary-mode=1 < binlog72.sql Again, there was an error when trying to execute the SQL file with MySQL client. The error is now showing bad SQL syntax: Enter **************** 1064 (42000) at line 66849: You have an error in your SQL syntax; check the manual that corresponds to your MariaDB server version for the right syntax to use near 'VJKF3BY7', 'solution-center', 0, NULL, 'idPrefixPersist', '44a6a325-d17d-4ce9-b7' at line 1 In another try for the same restore, we used the command where we pipe the output from mysqlbinlog to MySQL client: mysqlbinlog mysql-bin.000072 --stop-position=16208282 | mysql -uadmin -p --binary-mode=1 After some more tries on this, we were not able to make this SQL file run. We did some checks to see if the binary log was corrupted, in case there was some corruption in the blob column, but none of that was the case. Our next try was to source the file after we connect to MySQL as client. mysql -uadmin -p MariaDB [test]> source binlog72.sql The server starts processing the events from the SQL file and then it errors again: ...... Query OK, 1 row affected (0.00 sec) Rows matched: 1 Changed: 1 Warnings: 0 Query OK, 0 rows affected (0.01 sec) Query OK, 0 rows affected (0.00 sec) Query OK, 0 rows affected (0.00 sec) Query OK, 0 rows affected (0.00 sec) Query OK, 0 rows affected (0.00 sec) ERROR at line 66848 in file: 'binlog72.sql': ASCII '\0' appeared in the statement, but this is not allowed unless option --binary-mode is enabled and mysql is run in non-interactive mode. Set --binary-mode to 1 if ASCII '\0' is expected. Query: 'INSERT into pythian_msq(ID, KEY, REGION, CREATED_DATE, PRIORITY, BYTES) values ('b67d8bd1-f8f7-8ffb-d2a4-88da8cf14b21', 'd4d0a754-019b-39af-b568-2f2bf93b2845', '2.8.0', 1553862137605, NULL, _binary '??. In between each of these tests, we had to restore the latest backup and try again. Our next try was to start the MySQL client with --binary-mode=1 and then source the SQL file. The commands are: mysql -uadmin -p --binary-mode=1 MariaDB [test]> source binlog72.sql With the last command, the database does not produce any errors and we were able to restore the database up to the point of time before an erroneous transaction was run.
While most of the MySQL tools seem to be working with no major issues and are very straightforward for most of the DBAs, we may run into a use case that requires a more careful review of what is wrong and where we got the errors. In most of the cases, the error is showing some information about what is wrong and we can just follow the solution. In other cases, the error may be misleading or verbose. The only way of making the MySQL client work with Blob data in non-interactive mode was to generate the SQL file using mysqlbinlog and then source the SQL file while connected to MySQL client with --binary-mode=1. I hope this will save you some time if you are running into the same issues while doing PITR for your database.
Looking to optimize your MySQL use?