mysqlbinlog Command

Today I had to help another team member debug an issue with MySQL replication. There were times that the MySQL binary logs were generating upwards of 8GB per 10 minutes.

In come the mysqlbinlog command. This command can help view the raw binary log files to see what is actually running.

An example command to run is:

mysqlbinlog -v --base64-output=DECODE-ROWS binary-log-file-name.003852 | less  

To be able to see the actual SQL commands you will need to make sure to use;

  • -v - Reconstruct row events as SQL statements
  • --base64-output - Print binary log entries using base-64 encoding

Example output:

[root@hostname mysqllogs]# mysqlbinlog -v --base64-output=DECODE-ROWS binary-log-file-name.003852 | head -100
/*!40019 SET @@session.max_insert_delayed_threads=0*/;
DELIMITER /*!*/;  
# at 4
#170110  2:06:10 server id 728848  end_log_pos 107     Start: binlog v 4, server v 5.5.49-log created 170110  2:06:10
# at 107
#170110  2:06:10 server id 728848  end_log_pos 244     Query   thread_id=107464529 exec_time=0 error_code=0
use `prod_db`/*!*/;  
SET TIMESTAMP=1484035570/*!*/;  
SET @@session.pseudo_thread_id=107464529/*!*/;  
SET @@session.foreign_key_checks=1, @@session.sql_auto_is_null=0, @@session.unique_checks=1, @@session.autocommit=1/*!*/;  
SET @@session.sql_mode=0/*!*/;  
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/*!*/;  
ALTER TABLE `magento_cataloginventory_stock_status` DISABLE KEYS  
# at 244
#170110  2:06:10 server id 728848  end_log_pos 377     Query   thread_id=107464529 exec_time=0 error_code=0
SET TIMESTAMP=1484035570/*!*/;  
ALTER TABLE `magento_catalog_product_index_eav` DISABLE KEYS  

As you can see near the bottom, the actual SQL commands are output to the screen which can be extremely helpful with debugging replication issues where a large volume of data is being written to the binary logs.

In this case it was an errant WordPress column that had a large field value. It was running every few seconds and causing a large amount of write activity.