Shulou(Shulou.com)05/31 Report--

Editor to share with you how to skillfully use Event to find problems, I believe most people do not know much about it, so share this article for your reference, I hope you can learn a lot after reading this article, let's go to know it!

If the picture cannot be displayed, please see the following link:

Https://www.jianshu.com/p/d636215d767f

With the previous understanding of Event, we can use these Event to do some work. After learning these commonly used Event, I wrote a tool to parse Event in C language. I call it 'infobin',' which means to extract information from binary log. As far as I know, although this tool will appear BUG in a few cases, there are still some friends using it. I'm not here to promote my tools, but to tell you this way of thinking. I completed this tool with some problems encountered in my work, and the main functions include the following:

Analyze whether there are long-term uncommitted transactions in binary log, and long-uncommitted transactions will lead to more lock contention.

Analyze whether there are large transactions in binary log, and the commit of large transactions may block the commit of other transactions.

Analyze the number of DML Event generated by each table in binary log so that you can know which table has the most modifications.

Analyze the speed of Event generation in binary log so that you can know which time period generates more Event.

The help information for this tool is as follows:

[root@gp1 infobin] #. / infobin USAGE ERROR! [Author]: gaopeng [QQ]: 22389860 [blog]: http://blog.itpub.net/7728585/-- USAGE:./infobin binlogfile pieces bigtrxsize bigtrxtime [- t] [- force] [binlogfile]: binlogfile! [piece]: how many piece will split,is a Highly balanced histogram Find which time generate biggest binlog. (must:piece256 (bytes)) [bigtrxtime] (sec): larger than this sec trx will view. (must: > 0 (sec)) [[- t]]: if [- t] no detail is print out,the result will small [[- force]]: force analyze if unkown error checkpoints!

Next, let's take a look at how these functions are realized.

I. Analysis of long-term uncommitted transactions

As I have mentioned many times before, there are the following characteristics for a manually committed transaction, with the 'Insert' statement as the column:

GTID_LOG_EVENT and XID_EVENT are the time when the command 'COMMIT' was initiated.

QUERY_EVENT is the time when the first 'Insert' command was initiated.

MAP_EVENT/WRITE_ROWS_EVENT is the time that each 'Insert' command was initiated.

In fact, we can use (1) minus (2) to get the time between the initiation of the first 'DML' command' and the initiation of the 'COMMIT' command', and then use a user input parameter to define how long uncommitted transactions are called long-uncommitted transactions. I use bigtrxtime as this input in my tool. Let's use an example to illustrate that we make the following statement:

Statement time beginT1insert into testrr values (20); 11:25:22insert into testrr values (30); 11:25:26insert into testrr values (40); 11 purl 25 purl 28 purse Ten 11 purl 25 purl 30

Let's take a look at the order and timing of Event as follows:

| | Event | time |

| |-|-|

| | GTID_LOG_EVENT | 11:25:30 |

| | QUERY_EVENT | 11:25:22 |

| | MAP_EVENT (the first insert) | 11:25:22 |

| | WRITE_ROWS_EVENT (the first insert) | 11:25:22 |

| | MAP_EVENT (2nd insert) | 11:25:26 |

| | WRITE_ROWS_EVENT (2nd insert) | 11:25:26 |

| | MAP_EVENT (3rd insert) | 11:25:28 |

| | WRITE_ROWS_EVENT (3rd insert) | 11:25:28 |

| | XID_EVENT | 11:25:30 |

If we use the time of the last XID_EVENT minus the time of QUERY_EVENT, then the transaction's time from the beginning of the first statement to 'COMMIT' is calculated. Note that, in fact, the 'BEGIN' command is not recorded in Event, it just makes a mark so that the transaction does not automatically enter the commit process. Please refer to my brief book article on what the' BEGIN' command has done:

Https://www.jianshu.com/p/6de1e8071279

Second, analyze major affairs

This part of the implementation is relatively simple, we only need to scan all the Event between each transaction GTID_LOG_EVENT and XID_EVENT to calculate their sum, and we can get the size of each transaction generated Event (but it is best to calculate the total amount of Event between QUERY_EVENT and XID_EVENT for compatibility). Use a user input parameter to customize the size of a transaction called a large transaction, and I use bigtrxsize as this input parameter in my tool.

If the parameter binlog_row_image parameter is set to 'FULL', we can roughly calculate the size of the log generated by each row of data modification in a particular table:

Because there is only before_image or after_image in 'Insert' and' Delete':, 100 bytes of data plus some extra overhead adds about 10 bytes, or 110 bytes, to a row. If the location of the large transaction is 100m, then the modification is about 100W rows of data.

Because Update': contains before_image and after_image, the 110bytes calculated above need to be multiplied by 2. So if the location of the large transaction is 100m, then the modification is about 50W rows of data.

I think 20m is more appropriate as the definition of big transaction, of course, this is calculated according to your own needs.

Third, analyze the generation speed of Event in binary log

This implementation is very simple. We only need to fragment the binary log according to the input parameters and count the time difference between the end Event and the start Event to calculate how long it takes for each shard to be generated. Our tool uses piece as the input parameter of the shard. Through this analysis, we can roughly know when the amount of Event generated is higher, which also reflects the busy degree of the database.

4. Analyze the number of DML Event generated by each table

This function is also very useful, through this analysis we can know which table in the database has the largest amount of modification. The main way to achieve this is to scan the MAP_EVENT in binary log and the following DML Event, get the table name through table id, then put the size of DML Event into the table, make a linked list, and finally sort the output. But we said earlier that table id can change even in a transaction, which I didn't consider at first, so there is something wrong with the tool, but in most cases it works.

Fifth, tool display

Now I'm going to show you the features I'm talking about. I did the following:

Mysql > flush binary logs;Query OK, 0 rows affected (0.51 sec) mysql > select count (*) from tti;+-+ | count (*) | +-+ | 98304 | +-+ 1 row in set (0.06 sec) mysql > delete from tti;Query OK, 98304 rows affected (2.47 sec) mysql > begin;Query OK, 0 rows affected (0.00 sec) mysql > insert into tti values Query OK, 1 row affected (0.00 sec) mysql > select sleep (20); +-+ | sleep (20) | +-+ | 0 | +-+ 1 row in set (20.03 sec) mysql > commit;Query OK, 0 rows affected (0.22 sec) mysql > insert into tpp values (10); Query OK, 1 row affected (0.14 sec)

In the example I switched a binary log and did three transactions at the same time:

Deleted a total of 98304 rows of tti table data.

Inserts a piece of data into the tti table and waits for more than 20 seconds to commit.

A piece of data is inserted into the tpp table.

Let's use the tool to analyze it, and here's the statistical output:

. / infobin mysql-bin.000005 3 1000000 15-t > log.logmore log.log...-Total now-Trx total [counts]: 3Event total [counts]: 125Max trx event size:8207 (bytes) Pos: 420 [0X1A4] Avg binlog size (/ sec): 9265.844 (bytes) [9.049 (kb)] Avg binlog size (/ min): 555950.625 (bytes) [542.921 ( Kb)]-- Piece view: (1) Time:1561442359-1561442383 (24 (s)) piece:296507 (bytes) [289.558 (kb)] (2) Time:1561442383-1561442383 (0 (s)) piece:296507 (bytes) [289.558 (kb)] (3) Time:1561442383-1561442455 (72 (s)) piece:296507 (bytes) [289.558 (kb)]-- Large than 500000 (bytes) trx: (1) Trx_size:888703 (bytes) [867.874 (kb) ] trx_begin_p: 299 [0X12B] trx_end_p: 889002 [0XD90AA] Total large trx count size (kb): # 867.874 (kb)-- Large than 15 (secs) trx: (1) Trx_sec:31 (sec) trx_begin_time: [20190625 14:00:08 (CST)] trx_end_time: [20190625 14:00:39 (CST)] trx_begin_pos:889067trx_end_pos:889267 query_exe_time:0-- Every Table binlog size ( Bytes) and times:Note:size unit is bytes--- (1) Current Table:test.tpp:: Insert:binlog size (40 (Bytes)) times (1) Update:binlog size (0 (Bytes)) times (0) Delete:binlog size (0 (Bytes)) times (0) Total:binlog size (40 (Bytes)) times (1)-(2) Current Table:test.tti:: Insert:binlog size (48 (Bytes)) times (1) Update:binlog size ( 0 (Bytes)) times (0) Delete:binlog size (888551 (Bytes)) times (109th) Total:binlog size (888599 (Bytes)) times (11010)-Total binlog dml event size:888639 (Bytes) times

We found that all the operations we did had been counted:

Contains a large transaction log with a total amount of more than 500K and a size of about 800K, which is caused by deleting 98304 rows of data from my tti table.

-- Large than 500000 (bytes) trx: (1) Trx_size:888703 (bytes) [867.874 (kb)] trx_begin_p: 299 [0X12B] trx_end_p: 889002 [0XD90AA]

Contains a long-uncommitted transaction with a time of 31 seconds, which is caused by my deliberate waiting for more than 20 seconds to commit.

-- Large than 15 (secs) trx: (1) Trx_sec:31 (sec) trx_begin_time: [20190625 14:00:08 (CST)] trx_end_time: [20190625 14:00:39 (CST)] trx_begin_pos:889067trx_end_pos:889267 query_exe_time:0

This binary log has two table modification records tti and tpp, in which the tti table has' Delete' operation and 'Insert' operation, and the tpp table has only' Insert' operation, and contains the size of the log volume.

-Every Table binlog size (bytes) and times:Note:size unit is bytes--- (1) Current Table:test.tpp:: Insert:binlog size (40 (Bytes)) times (1) Update:binlog size (0 (Bytes)) times (0) Delete:binlog size (0 (Bytes)) times (0) Total:binlog size (40 (Bytes)) times (1)-- (2) Current Table:test.tti:: Insert:binlog size (48 (Bytes)) times (1) ) Update:binlog size (0 (Bytes)) times (0) Delete:binlog size (888551 (Bytes)) times (109) Total:binlog size (888599 (Bytes)) times (110)-Total binlog dml event size:888639 (Bytes) times

All right, what I want to tell you here is that after learning Event, you can try to parse binary log in various languages, and maybe you can write better tools to achieve more functions.

Of course, it can be parsed through mysqlbinlog and then counted through shell/python, but this tool is much faster than this way.

The above is all the contents of the article "how to find problems with Event". Thank you for reading! I believe we all have a certain understanding, hope to share the content to help you, if you want to learn more knowledge, welcome to follow the industry information channel!

Welcome to subscribe "Shulou Technology Information " to get latest news, interesting things and hot topics in the IT industry, and controls the hottest and latest Internet news, technology news and IT industry trends.