From 67e040f76a79da9a6d551fbdbe2f50479255b198 Mon Sep 17 00:00:00 2001 From: MassimilianoPinto Date: Thu, 10 Sep 2015 14:37:49 +0200 Subject: [PATCH 1/2] Addition of maxbinlogcheck, a new utility in bin Addition of maxbinlogcheck, a new utility in bin --- Reference/MaxBinlogCheck.md | 330 ++++++++++++++++++++++++++++++++++++ 1 file changed, 330 insertions(+) create mode 100644 Reference/MaxBinlogCheck.md diff --git a/Reference/MaxBinlogCheck.md b/Reference/MaxBinlogCheck.md new file mode 100644 index 000000000..3f1fc4c57 --- /dev/null +++ b/Reference/MaxBinlogCheck.md @@ -0,0 +1,330 @@ +# Maxbinlogcheck + +# The MySQL/MariaDB binlog check utility + +Massimiliano Pinto + +Last Updated: 08th September 2015 + +# Overview + +Maxbinlogcheck is a command line utility for checking binlogfiles downloaded by MaxScale binlog router or the MySQL/MariaDB binlog files stored in a database server acting as a master in a replication environment. +It checks the binlog file against any corruption and incomplete transaction stored and reports a transaction summary after reading all the events. +It may optionally truncate binlog file. + +Maxbinlogcheck supports + +* MariaDB 5.5 and MySQL 5.6 + +* MariaDB 10.0 with a command line option + +# Running maxbinlogcheck +``` +# /usr/local/bin/maxbinlogcheck /path_to_file/bin.000002 +``` + +# Command Line Switches + +The maxbinlogcheck command accepts a number of switches + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + +
SwitchLong OptionDescription
-f--fixIf the option is set the binlog file will be truncated at last safe transaction pos in case of any error
-M--mariadb10Check the current binlog against MariaDB 10.0.x events
-d--debugSet the debug mode. If set the FD Events, Rotate events and opening/closing transactions are displayed.
-?--helpPrint usage information regarding maxbinlogcheck
-V--versionPrint the maxbinlogcheck version information
+ +## Example without debug: + +1) No transactions + +``` +[root@maxscale-02 build]# /usr/local/bin/maxbinlogcheck /servers/binlogs/new-trx/mar-bin.000002 +2015-09-08 09:38:03 maxbinlogcheck 1.0.0 +2015-09-08 09:38:03 Checking /servers/binlogs/new-trx/mar-bin.000002 (mar-bin.000002), size 290 bytes +2015-09-08 09:38:03 Check retcode: 0, Binlog Pos = 290 +``` + +2) With complete transactions + +``` +[root@maxscale-02 build]# /usr/local/bin/maxbinlogcheck /servers/binlogs/new-trx/mar-bin.000004 +2015-09-08 09:38:35 maxbinlogcheck 1.0.0 +2015-09-08 09:38:35 Checking /servers/binlogs/new-trx/mar-bin.000004 (mar-bin.000004), size 38738629 bytes +2015-09-08 09:38:36 Transaction Summary: + Description Total Average Max + No. of Transactions 21713 + No. of Events 186599 8.6 5082 + No. of Bytes 36M 1k 5M +2015-09-08 09:38:36 Check retcode: 0, Binlog Pos = 38738629 +``` + +## Example with debug: + +1) one complete transaction + +``` +[root@maxscale-02 build]# /usr/local/bin/maxbinlogcheck /servers/binlogs/new-trx/mar-bin.000001 -d +2015-09-08 09:36:49 maxbinlogcheck 1.0.0 +2015-09-08 09:36:49 Checking /servers/binlogs/new-trx/mar-bin.000001 (mar-bin.000001), size 590760698 bytes +2015-09-08 09:36:49 - Format Description event FDE @ 4, size 241 +2015-09-08 09:36:49 FDE ServerVersion [ 5.5.35-MariaDB-log] +2015-09-08 09:36:49 FDE Header EventLength 19, N. of supported MySQL/MariaDB events 160 +2015-09-08 09:36:49 FDE Checksum alg desc 1, alg type BINLOG_CHECKSUM_ALG_CRC32 +2015-09-08 09:36:49 > Transaction starts @ pos 572 +2015-09-08 09:36:49 Transaction XID @ pos 572, closing @ 590760644 +2015-09-08 09:36:49 < Transaction @ pos 572, is now closed @ 590760644. 18001 events seen +2015-09-08 09:36:49 End of binlog file [mar-bin.000001] at 590760698. +2015-09-08 09:36:49 Transaction Summary: + Description Total Average Max + No. of Transactions 1 + No. of Events 18001 18001.0 18001 + No. of Bytes 563M 563M 563M +2015-09-08 09:36:49 Check retcode: 0, Binlog Pos = 590760698 +``` + +2) some transactions + +``` +[root@maxscale-02 build]# /usr/local/bin/maxbinlogcheck /servers/binlogs/new-trx/mar-bin.000004 -d +2015-09-08 10:19:35 maxbinlogcheck 1.0.0 +2015-09-08 10:19:35 Checking /servers/binlogs/new-trx/mar-bin.000004 (mar-bin.000004), size 38738629 bytes +2015-09-08 10:19:35 - Format Description event FDE @ 4, size 241 +2015-09-08 10:19:35 FDE ServerVersion [ 5.5.35-MariaDB-log] +2015-09-08 10:19:35 FDE Header EventLength 19, N. of supported MySQL/MariaDB events 160 +2015-09-08 10:19:35 FDE Checksum alg desc 1, alg type BINLOG_CHECKSUM_ALG_CRC32 +2015-09-08 10:19:35 > Transaction starts @ pos 971 +2015-09-08 10:19:35 Transaction XID @ pos 971, closing @ 1128 +2015-09-08 10:19:35 < Transaction @ pos 971, is now closed @ 1128. 3 events seen +... +2015-09-08 10:19:51 > Transaction starts @ pos 33440561 +2015-09-08 10:19:51 Transaction XID @ pos 33440561, closing @ 33440763 +2015-09-08 10:19:51 < Transaction @ pos 33440561, is now closed @ 33440763. 3 events seen +2015-09-08 10:19:51 > Transaction starts @ pos 33440794 +2015-09-08 10:19:51 Transaction XID @ pos 33440794, closing @ 38738553 +2015-09-08 10:19:51 < Transaction @ pos 33440794, is now closed @ 38738553. 5082 events seen +2015-09-08 10:19:51 - Rotate event @ 38738584, next file is [mar-bin.000005] @ 4 +2015-09-08 10:19:51 End of binlog file [mar-bin.000004] at 38738629. +2015-09-08 10:19:51 Transaction Summary: + Description Total Average Max + No. of Transactions 21713 + No. of Events 186599 8.6 5082 + No. of Bytes 36M 1k 5M +2015-09-08 10:19:51 Check retcode: 0, Binlog Pos = 38738629 +``` + +3) No transactions + +``` +2015-09-08 09:41:02 Check retcode: 0, Binlog Pos = 290 +[root@maxscale-02 build]# /usr/local/bin/maxbinlogcheck /servers/binlogs/new-trx/mar-bin.000002 -d +2015-09-08 09:41:08 maxbinlogcheck 1.0.0 +2015-09-08 09:41:08 Checking /servers/binlogs/new-trx/mar-bin.000002 (mar-bin.000002), size 290 bytes +2015-09-08 09:41:08 - Format Description event FDE @ 4, size 241 +2015-09-08 09:41:08 FDE ServerVersion [ 5.5.35-MariaDB-log] +2015-09-08 09:41:08 FDE Header EventLength 19, N. of supported MySQL/MariaDB events 160 +2015-09-08 09:41:08 FDE Checksum alg desc 1, alg type BINLOG_CHECKSUM_ALG_CRC32 +2015-09-08 09:41:08 - Rotate event @ 245, next file is [mar-bin.000003] @ 4 +2015-09-08 09:41:08 End of binlog file [mar-bin.000002] at 290. +2015-09-08 09:41:08 Check retcode: 0, Binlog Pos = 290 +``` + +## Fixing a corrupted binlog file + +This file is corrupted, as reported by the utility: + +``` +[root@maxscale-02 build]# /usr/local/bin/maxbinlogcheck /servers/binlogs/new-trx/bin.000002 +2015-09-08 10:03:16 maxbinlogcheck 1.0.0 +2015-09-08 10:03:16 Checking /servers/binlogs/new-trx/bin.000002 (bin.000002), size 109498 bytes +2015-09-08 10:03:16 Event size error: size 0 at 290. +2015-09-08 10:03:16 warning : an error has been found. Setting safe pos to 245, current pos 290 +2015-09-08 10:03:16 Check retcode: 1, Binlog Pos = 245 +``` + +The suggested safe pos is 245 + +Use -f option for fix with debug: + +``` +[root@maxscale-02 build]# /usr/local/bin/maxbinlogcheck /servers/binlogs/new-trx/bin.000002 -d -f +2015-09-08 09:56:52 maxbinlogcheck 1.0.0 +2015-09-08 09:56:52 Checking /servers/binlogs/new-trx/bin.000002 (bin.000002), size 109498 bytes +2015-09-08 09:56:52 - Format Description event FDE @ 4, size 241 +2015-09-08 09:56:52 FDE ServerVersion [ 5.5.35-MariaDB-log] +2015-09-08 09:56:52 FDE Header EventLength 19, N. of supported MySQL/MariaDB events 160 +2015-09-08 09:56:52 FDE Checksum alg desc 1, alg type BINLOG_CHECKSUM_ALG_CRC32 +2015-09-08 09:56:52 - Rotate event @ 245, next file is [mar-bin.000003] @ 4 +2015-09-08 09:56:52 Event size error: size 0 at 290. +2015-09-08 09:56:52 warning : an error has been found. Setting safe pos to 245, current pos 290 +2015-09-09 09:56:52 Binlog file bin.000002 has been truncated at 245 +2015-09-08 09:56:52 Check retcode: 1, Binlog Pos = 245 +``` + +Check it again, last pos will be 245 and no errors will be reported: + +``` +[root@maxscale-02 build]# /usr/local/bin/maxbinlogcheck /servers/binlogs/new-trx/bin.000002 -d +2015-09-08 09:56:56 maxbinlogcheck 1.0.0 +2015-09-08 09:56:56 Checking /servers/binlogs/new-trx/bin.000002 (bin.000002), size 245 bytes +2015-09-08 09:56:56 - Format Description event FDE @ 4, size 241 +2015-09-08 09:56:56 FDE ServerVersion [ 5.5.35-MariaDB-log] +2015-09-08 09:56:56 FDE Header EventLength 19, N. of supported MySQL/MariaDB events 160 +2015-09-08 09:56:56 FDE Checksum alg desc 1, alg type BINLOG_CHECKSUM_ALG_CRC32 +2015-09-08 09:56:56 End of binlog file [bin.000002] at 245. +2015-09-08 09:56:56 Check retcode: 0, Binlog Pos = 245 +``` + +## Detection of an incomplete big transaction + +``` +[root@maxscale-02 build]# /usr/local/bin/maxbinlogcheck /servers/binlogs/new-trx/mar-bin.000003 +2015-09-08 10:10:21 maxbinlogcheck 1.0.0 +2015-09-08 10:10:21 Checking /servers/binlogs/new-trx/mar-bin.000003 (mar-bin.000003), size 16476284 bytes +2015-09-08 10:10:21 Warning : pending transaction has been found. Setting safe pos to 572, current pos 16476284 +2015-09-08 10:10:21 Check retcode: 0, Binlog Pos = 572 +``` + +with debug option: + +``` +[root@maxscale-02 build]# /usr/local/bin/maxbinlogcheck /servers/binlogs/new-trx/mar-bin.000003 -d +2015-09-08 10:11:08 maxbinlogcheck 1.0.0 +2015-09-08 10:11:08 Checking /servers/binlogs/new-trx/mar-bin.000003 (mar-bin.000003), size 16476284 bytes +2015-09-08 10:11:08 - Format Description event FDE @ 4, size 241 +2015-09-08 10:11:08 FDE ServerVersion [ 5.5.35-MariaDB-log] +2015-09-08 10:11:08 FDE Header EventLength 19, N. of supported MySQL/MariaDB events 160 +2015-09-08 10:11:08 FDE Checksum alg desc 1, alg type BINLOG_CHECKSUM_ALG_CRC32 +2015-09-08 10:11:08 > Transaction starts @ pos 572 +2015-09-08 10:11:08 Warning : pending transaction has been found. Setting safe pos to 572, current pos 16476284 +2015-09-08 10:11:08 End of binlog file [mar-bin.000003] at 16476284. +2015-09-08 10:11:08 Check retcode: 0, Binlog Pos = 572 +``` + +Retcode is 0 as the transaction may proceed over time, example: + +Another check ... + +``` +[root@maxscale-02 build]# /usr/local/bin/maxbinlogcheck /servers/binlogs/new-trx/mar-bin.000003 -d +2015-09-08 10:17:13 maxbinlogcheck 1.0.0 +2015-09-08 10:17:13 Checking /servers/binlogs/new-trx/mar-bin.000003 (mar-bin.000003), size 569296364 bytes +2015-09-08 10:17:13 - Format Description event FDE @ 4, size 241 +2015-09-08 10:17:13 FDE ServerVersion [ 5.5.35-MariaDB-log] +2015-09-08 10:17:13 FDE Header EventLength 19, N. of supported MySQL/MariaDB events 160 +2015-09-08 10:17:13 FDE Checksum alg desc 1, alg type BINLOG_CHECKSUM_ALG_CRC32 +2015-09-08 10:17:13 > Transaction starts @ pos 572 +2015-09-08 10:17:14 End of binlog file [mar-bin.000003] at 577567062. +2015-09-08 10:17:14 Check retcode: 0, Binlog Pos = 572 +``` + +And finally big transaction is now done. + +``` +[root@maxscale-02 build]# /usr/local/bin/maxbinlogcheck /servers/binlogs/new-trx/mar-bin.000003 -d +2015-09-08 10:17:15 maxbinlogcheck 1.0.0 +2015-09-08 10:17:15 Checking /servers/binlogs/new-trx/mar-bin.000003 (mar-bin.000003), size 590760698 bytes +2015-09-08 10:17:15 - Format Description event FDE @ 4, size 241 +2015-09-08 10:17:15 FDE ServerVersion [ 5.5.35-MariaDB-log] +2015-09-08 10:17:15 FDE Header EventLength 19, N. of supported MySQL/MariaDB events 160 +2015-09-08 10:17:15 FDE Checksum alg desc 1, alg type BINLOG_CHECKSUM_ALG_CRC32 +2015-09-08 10:17:15 > Transaction starts @ pos 572 +2015-09-08 10:17:16 Transaction XID @ pos 572, closing @ 590760644 +2015-09-08 10:17:16 < Transaction @ pos 572, is now closed @ 590760644. 18001 events seen +2015-09-08 10:17:16 End of binlog file [mar-bin.000003] at 590760698. +2015-09-08 10:17:16 Transaction Summary: + Description Total Average Max + No. of Transactions 1 + No. of Events 18001 18001.0 18001 + No. of Bytes 563M 563M 563M +2015-09-08 10:17:16 Check retcode: 0, Binlog Pos = 590760698 +``` + +**Note** +with current maxbinlogcheck it's not possible to fix a binlog with incomplete transaction and no other errors + +If that is really desired it will be possible with UNIX command line: + +``` +# truncate /servers/binlogs/new-trx/mar-bin.000003 --size=572 +``` + +In case of an error and incomplete transaction, the fix will work + +``` +[root@maxscale-02 build]# /usr/local/bin/maxbinlogcheck /servers/binlogs/new-trx/mar-bin.000003 -d -f +2015-09-08 10:35:57 maxbinlogcheck 1.0.0 +2015-09-08 10:35:57 Checking /servers/binlogs/new-trx/mar-bin.000003 (mar-bin.000003), size 282580902 bytes +2015-09-08 10:35:57 - Format Description event FDE @ 4, size 241 +2015-09-08 10:35:57 FDE ServerVersion [ 5.5.35-MariaDB-log] +2015-09-08 10:35:57 FDE Header EventLength 19, N. of supported MySQL/MariaDB events 160 +2015-09-08 10:35:57 FDE Checksum alg desc 1, alg type BINLOG_CHECKSUM_ALG_CRC32 +2015-09-08 10:35:57 > Transaction starts @ pos 572 +2015-09-08 10:35:57 Short read when reading the event at 304898502 in mar-bin.000003. Expected 65563 bytes got 15911 bytes. +2015-09-08 10:35:57 warning : an error has been found. Setting safe pos to 572, current pos 304898502 +2015-09-09 10:35:57 Binlog file bin.000003 has been truncated at 572 +2015-09-08 10:35:57 Check retcode: 1, Binlog Pos = 572 +``` + +Check result: + +``` +[root@maxscale-02 build]# /usr/local/bin/maxbinlogcheck /servers/binlogs/new-trx/mar-bin.000003 -d +2015-09-08 10:54:17 maxbinlogcheck 1.0.0 +2015-09-08 10:54:17 Checking /servers/binlogs/new-trx/mar-bin.000003 (mar-bin.000003), size 572 bytes +2015-09-08 10:54:17 - Format Description event FDE @ 4, size 241 +2015-09-08 10:54:17 FDE ServerVersion [ 5.5.35-MariaDB-log] +2015-09-08 10:54:17 FDE Header EventLength 19, N. of supported MySQL/MariaDB events 160 +2015-09-08 10:54:17 FDE Checksum alg desc 1, alg type BINLOG_CHECKSUM_ALG_CRC32 +2015-09-08 10:54:17 End of binlog file [mar-bin.000003] at 572. +2015-09-08 10:54:17 Check retcode: 0, Binlog Pos = 572 +``` + +### MariaDB 10 binlog check + +``` +[root@maxscale-02 build]# /usr/local/bin/maxbinlogcheck -M -d /mariadb-10.0.11/data/mysql-bin.000008 +2015-09-08 12:49:18 maxbinlogcheck 1.0.0 +2015-09-08 12:49:18 Checking /mariadb-10.0.11/data/mysql-bin.000008 (mysql-bin.000008), size 1215327 bytes +2015-09-08 12:49:18 - Format Description event FDE @ 4, size 244 +2015-09-08 12:49:18 FDE ServerVersion [ 10.0.11-MariaDB-log] +2015-09-08 12:49:18 FDE Header EventLength 19, N. of supported MySQL/MariaDB events 163 +2015-09-08 12:49:18 FDE Checksum alg desc 0, alg type NONE or UNDEF +2015-09-08 12:49:18 > MariaDB 10 Transaction (GTID 0-29-60) starts @ pos 802 +2015-09-08 12:49:18 Transaction XID @ pos 802, closing @ 1214943 +2015-09-08 12:49:18 < Transaction @ pos 802, is now closed @ 1214943. 76 events seen +2015-09-08 12:49:18 End of binlog file [mysql-bin.000008] at 1215327. +2015-09-08 12:49:18 Transaction Summary: + Description Total Average Max + No. of Transactions 1 + No. of Events 76 76.0 76 + No. of Bytes 1.2M 1.2M 1.2M +2015-09-08 12:49:18 Check retcode: 0, Binlog Pos = 1215327 +``` + From 40ae81c91b9119c8e0bd0695d624fbce4fc3bbcf Mon Sep 17 00:00:00 2001 From: Johan Wikman Date: Fri, 11 Sep 2015 15:21:31 +0300 Subject: [PATCH 2/2] MXS-362: Enable/disable log augmentation Log message augmentation (appending of function name) can now be enabled or disabled via the configuration file and command line. By default, the augmentation is disabled. --- Getting-Started/Configuration-Guide.md | 12 ++++++++++++ Tutorials/Administration-Tutorial.md | 1 + 2 files changed, 13 insertions(+) diff --git a/Getting-Started/Configuration-Guide.md b/Getting-Started/Configuration-Guide.md index 01a8c1dba..0bb10617b 100644 --- a/Getting-Started/Configuration-Guide.md +++ b/Getting-Started/Configuration-Guide.md @@ -124,6 +124,18 @@ log_debug=1 To disable the log use the value 0 and to enable it use the value 1. +#### `log_augmentation` + +Enable or disable the augmentation of messages. If this is enabled, then each logged message is appended with the name of the function where the message was logged. This is primarily for development purposes and hence is disabled by default. + +``` +# Valid options are: +# log_augmentation=<0|1> +log_augmentation=1 +``` + +To disable the augmentation use the value 0 and to enable it use the value 1. + #### `logdir` Set the directory where the logfiles are stored. The folder needs to be both readable and writable by the user running MaxScale. diff --git a/Tutorials/Administration-Tutorial.md b/Tutorials/Administration-Tutorial.md index 364ca7e41..920c60f96 100644 --- a/Tutorials/Administration-Tutorial.md +++ b/Tutorials/Administration-Tutorial.md @@ -43,6 +43,7 @@ Switch|Long Option|Description `-U USER`|`--user=USER`|run MaxScale as another user. The user ID and group ID of this user are used to run MaxScale. `-s [yes no]`|`--syslog=[yes no]`|log messages to syslog (default:yes) `-S [yes no]`|`--maxscalelog=[yes no]`|log messages to MaxScale log (default: yes) +`-G [0 1]`|`--log_augmentation=[0 1]`|augment messages with the name of the function where the message was logged (default: 0). Primarily for development purposes. `-v`|`--version`|print version info and exit `-V`|`--version-full`|print version info and the commit ID the binary was built from `-?`|`--help`|show this help